feat: output the runtime log to the log file (#214)

Signed-off-by: chlins <[email protected]>

Author: chlins

cmd/root.go

@@ -22,8 +22,10 @@ import (
 	_ "net/http/pprof"
 	"os"
 	"os/signal"
+	"path/filepath"
 	"syscall"
 
+	"github.com/sirupsen/logrus"
 	"github.com/spf13/cobra"
 	"github.com/spf13/viper"
 
@@ -33,6 +35,7 @@ import (
 )
 
 var rootConfig *config.Root
+var logFile *os.File
 
 // rootCmd represents the modctl command.
 var rootCmd = &cobra.Command{
@@ -53,10 +56,38 @@ var rootCmd = &cobra.Command{
 			}()
 		}
 
+		// Ensure log directory exists.
+		if err := os.MkdirAll(rootConfig.LogDir, 0755); err != nil {
+			return err
+		}
+
+		// Ensure log file exists.
+		var err error
+		logFile, err = os.OpenFile(filepath.Join(rootConfig.LogDir, "modctl.log"), os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666)
+		if err != nil {
+			return err
+		}
+
+		logLevel, err := logrus.ParseLevel(rootConfig.LogLevel)
+		if err != nil {
+			return err
+		}
+
+		logrus.SetOutput(logFile)
+		logrus.SetLevel(logLevel)
+		logrus.SetFormatter(&logrus.TextFormatter{})
+
 		// TODO: need refactor as currently use a global flag to control the progress bar render.
 		internalpb.SetDisableProgress(rootConfig.DisableProgress)
 		return nil
 	},
+	PersistentPostRunE: func(cmd *cobra.Command, args []string) error {
+		if logFile != nil {
+			return logFile.Close()
+		}
+
+		return nil
+	},
 }
 
 // Execute adds all child commands to the root command and sets flags appropriately.
@@ -88,6 +119,8 @@ func init() {
 	flags.BoolVar(&rootConfig.Pprof, "pprof", rootConfig.Pprof, "enable pprof")
 	flags.StringVar(&rootConfig.PprofAddr, "pprof-addr", rootConfig.PprofAddr, "specify the address for pprof")
 	flags.BoolVar(&rootConfig.DisableProgress, "no-progress", rootConfig.DisableProgress, "disable progress bar")
+	flags.StringVar(&rootConfig.LogDir, "log-dir", rootConfig.LogDir, "specify the log directory for modctl")
+	flags.StringVar(&rootConfig.LogLevel, "log-level", rootConfig.LogLevel, "specify the log level for modctl")
 
 	// Bind common flags.
 	if err := viper.BindPFlags(flags); err != nil {

pkg/backend/attach.go

@@ -28,6 +28,7 @@ import (
 	modelspec "github.com/CloudNativeAI/model-spec/specs-go/v1"
 	godigest "github.com/opencontainers/go-digest"
 	ocispec "github.com/opencontainers/image-spec/specs-go/v1"
+	"github.com/sirupsen/logrus"
 
 	internalpb "github.com/CloudNativeAI/modctl/internal/pb"
 	"github.com/CloudNativeAI/modctl/pkg/backend/build"
@@ -59,6 +60,7 @@ var (
 
 // Attach attaches user materials into the model artifact which follows the Model Spec.
 func (b *backend) Attach(ctx context.Context, filepath string, cfg *config.Attach) error {
+	logrus.Infof("attaching file %s, cfg: %+v", filepath, cfg)
 	srcManifest, err := b.getManifest(ctx, cfg.Source, cfg.OutputRemote, cfg.PlainHTTP, cfg.Insecure)
 	if err != nil {
 		return fmt.Errorf("failed to get source manifest: %w", err)
@@ -69,6 +71,8 @@ func (b *backend) Attach(ctx context.Context, filepath string, cfg *config.Attac
 		return fmt.Errorf("failed to get source model config: %w", err)
 	}
 
+	logrus.Infof("source model config: %+v", srcModelConfig)
+
 	var foundLayer *ocispec.Descriptor
 	for _, layer := range srcManifest.Layers {
 		if anno := layer.Annotations; anno != nil {
@@ -83,6 +87,8 @@ func (b *backend) Attach(ctx context.Context, filepath string, cfg *config.Attac
 		}
 	}
 
+	logrus.Infof("found original layer: %+v", foundLayer)
+
 	layers := srcManifest.Layers
 	if foundLayer != nil {
 		// Remove the found layer from the layers slice as we need to replace it with the new layer.
@@ -117,6 +123,8 @@ func (b *backend) Attach(ctx context.Context, filepath string, cfg *config.Attac
 	layers = append(layers, newLayers...)
 	sortLayers(layers)
 
+	logrus.Infof("new sorted layers: %+v", layers)
+
 	diffIDs := []godigest.Digest{}
 	for _, layer := range layers {
 		diffIDs = append(diffIDs, layer.Digest)
@@ -136,6 +144,9 @@ func (b *backend) Attach(ctx context.Context, filepath string, cfg *config.Attac
 		Family:       srcModelConfig.Descriptor.Family,
 		Name:         srcModelConfig.Descriptor.Name,
 	}
+
+	logrus.Infof("new model config: %+v", modelConfig)
+
 	configDesc, err := builder.BuildConfig(ctx, layers, modelConfig, hooks.NewHooks(
 		hooks.WithOnStart(func(name string, size int64, reader io.Reader) io.Reader {
 			return pb.Add(internalpb.NormalizePrompt("Building config"), name, size, reader)

pkg/backend/build.go

@@ -26,6 +26,7 @@ import (
 	modelspec "github.com/CloudNativeAI/model-spec/specs-go/v1"
 	retry "github.com/avast/retry-go/v4"
 	ocispec "github.com/opencontainers/image-spec/specs-go/v1"
+	"github.com/sirupsen/logrus"
 
 	internalpb "github.com/CloudNativeAI/modctl/internal/pb"
 	"github.com/CloudNativeAI/modctl/pkg/backend/build"
@@ -45,6 +46,7 @@ const (
 
 // Build builds the user materials into the model artifact which follows the Model Spec.
 func (b *backend) Build(ctx context.Context, modelfilePath, workDir, target string, cfg *config.Build) error {
+	logrus.Infof("building model artifact: %s, cfg: %+v", target, cfg)
 	// parse the repo name and tag name from target.
 	ref, err := ParseReference(target)
 	if err != nil {
@@ -97,6 +99,8 @@ func (b *backend) Build(ctx context.Context, modelfilePath, workDir, target stri
 
 	layers = append(layers, layerDescs...)
 
+	logrus.Infof("model artifact layers: %+v", layers)
+
 	revision := sourceInfo.Commit
 	if revision != "" && sourceInfo.Dirty {
 		revision += "-dirty"
@@ -114,6 +118,8 @@ func (b *backend) Build(ctx context.Context, modelfilePath, workDir, target stri
 		SourceRevision: revision,
 	}
 
+	logrus.Infof("model artifact config: %+v", modelConfig)
+
 	var configDesc ocispec.Descriptor
 	// Build the model config.
 	if err := retry.Do(func() error {

pkg/backend/build/builder.go

@@ -34,6 +34,7 @@ import (
 	godigest "github.com/opencontainers/go-digest"
 	spec "github.com/opencontainers/image-spec/specs-go"
 	ocispec "github.com/opencontainers/image-spec/specs-go/v1"
+	"github.com/sirupsen/logrus"
 
 	buildconfig "github.com/CloudNativeAI/modctl/pkg/backend/build/config"
 	"github.com/CloudNativeAI/modctl/pkg/backend/build/hooks"
@@ -146,12 +147,15 @@ func (ab *abstractBuilder) BuildLayer(ctx context.Context, mediaType, workDir, p
 		return ocispec.Descriptor{}, fmt.Errorf("failed to create codec: %w", err)
 	}
 
+	logrus.Infof("building file %s...", relPath)
+
 	// Encode the content by codec depends on the media type.
 	reader, err := codec.Encode(path, workDirPath)
 	if err != nil {
 		return ocispec.Descriptor{}, fmt.Errorf("failed to encode file: %w", err)
 	}
 
+	logrus.Infof("calculating digest for %s...", relPath)
 	// Calculate the digest of the encoded content.
 	hash := sha256.New()
 	size, err := io.Copy(hash, reader)
@@ -160,14 +164,17 @@ func (ab *abstractBuilder) BuildLayer(ctx context.Context, mediaType, workDir, p
 	}
 
 	digest := fmt.Sprintf("sha256:%x", hash.Sum(nil))
+	logrus.Infof("calculated digest for %s: %s", relPath, digest)
 
 	// Seek the reader to the beginning if supported,
 	// otherwise we needs to re-encode the content again.
 	if seeker, ok := reader.(io.ReadSeeker); ok {
+		logrus.Infof("seeking %s reader to beginning...", relPath)
 		if _, err := seeker.Seek(0, io.SeekStart); err != nil {
 			return ocispec.Descriptor{}, fmt.Errorf("failed to seek reader: %w", err)
 		}
 	} else {
+		logrus.Infof("%s reader is not seekable, re-encoding...", relPath)
 		reader, err = codec.Encode(path, workDirPath)
 		if err != nil {
 			return ocispec.Descriptor{}, fmt.Errorf("failed to encode file: %w", err)
@@ -217,6 +224,8 @@ func (ab *abstractBuilder) BuildLayer(ctx context.Context, mediaType, workDir, p
 		return desc, fmt.Errorf("failed to marshal metadata: %w", err)
 	}
 
+	logrus.Infof("retrieved file %s metadata: %s", relPath, string(metadataStr))
+
 	// Apply the metadata to the descriptor annotation.
 	if desc.Annotations == nil {
 		desc.Annotations = make(map[string]string)

pkg/backend/extract.go

@@ -27,6 +27,7 @@ import (
 	"github.com/CloudNativeAI/modctl/pkg/config"
 	"github.com/CloudNativeAI/modctl/pkg/storage"
 	modelspec "github.com/CloudNativeAI/model-spec/specs-go/v1"
+	"github.com/sirupsen/logrus"
 	"golang.org/x/sync/errgroup"
 
 	ocispec "github.com/opencontainers/image-spec/specs-go/v1"
@@ -39,6 +40,7 @@ const (
 
 // Extract extracts the model artifact.
 func (b *backend) Extract(ctx context.Context, target string, cfg *config.Extract) error {
+	logrus.Infof("extracting model artifact: %s, cfg: %+v", target, cfg)
 	// parse the repository and tag from the target.
 	ref, err := ParseReference(target)
 	if err != nil {
@@ -57,6 +59,8 @@ func (b *backend) Extract(ctx context.Context, target string, cfg *config.Extrac
 		return fmt.Errorf("failed to unmarshal the manifest: %w", err)
 	}
 
+	logrus.Infof("manifest: %s", string(manifestRaw))
+
 	return exportModelArtifact(ctx, b.store, manifest, repo, cfg)
 }
 
@@ -65,13 +69,16 @@ func exportModelArtifact(ctx context.Context, store storage.Storage, manifest oc
 	g, ctx := errgroup.WithContext(ctx)
 	g.SetLimit(cfg.Concurrency)
 
+	logrus.Infof("extracting %d layers in total...", len(manifest.Layers))
 	for _, layer := range manifest.Layers {
 		g.Go(func() error {
 			select {
 			case <-ctx.Done():
 				return ctx.Err()
 			default:
 			}
+
+			logrus.Infof("extracting layer %s...", layer.Digest.String())
 			// pull the blob from the storage.
 			reader, err := store.PullBlob(ctx, repo, layer.Digest.String())
 			if err != nil {
@@ -84,6 +91,8 @@ func exportModelArtifact(ctx context.Context, store storage.Storage, manifest oc
 				return fmt.Errorf("failed to extract layer %s: %w", layer.Digest.String(), err)
 			}
 
+			logrus.Infof("extracted layer %s successfully", layer.Digest.String())
+
 			return nil
 		})
 	}

pkg/backend/fetch.go

@@ -24,6 +24,7 @@ import (
 
 	modelspec "github.com/CloudNativeAI/model-spec/specs-go/v1"
 	ocispec "github.com/opencontainers/image-spec/specs-go/v1"
+	"github.com/sirupsen/logrus"
 	"golang.org/x/sync/errgroup"
 
 	internalpb "github.com/CloudNativeAI/modctl/internal/pb"
@@ -33,6 +34,7 @@ import (
 
 // Fetch fetches partial files to the output.
 func (b *backend) Fetch(ctx context.Context, target string, cfg *config.Fetch) error {
+	logrus.Infof("fetching partial files, target: %s, cfg: %+v", target, cfg)
 	// parse the repository and tag from the target.
 	ref, err := ParseReference(target)
 	if err != nil {
@@ -57,6 +59,8 @@ func (b *backend) Fetch(ctx context.Context, target string, cfg *config.Fetch) e
 		return fmt.Errorf("failed to decode the manifest: %w", err)
 	}
 
+	logrus.Infof("manifest: %+v", manifest)
+
 	layers := []ocispec.Descriptor{}
 	// filter the layers by patterns.
 	for _, layer := range manifest.Layers {
@@ -85,6 +89,7 @@ func (b *backend) Fetch(ctx context.Context, target string, cfg *config.Fetch) e
 	g, ctx := errgroup.WithContext(ctx)
 	g.SetLimit(cfg.Concurrency)
 
+	logrus.Infof("fetching %d layers in total...", len(layers))
 	for _, layer := range layers {
 		g.Go(func() error {
 			select {
@@ -93,9 +98,16 @@ func (b *backend) Fetch(ctx context.Context, target string, cfg *config.Fetch) e
 			default:
 			}
 
-			return pullAndExtractFromRemote(ctx, pb, internalpb.NormalizePrompt("Fetching blob"), client, cfg.Output, layer)
+			logrus.Infof("fetching layer %s...", layer.Digest)
+			if err := pullAndExtractFromRemote(ctx, pb, internalpb.NormalizePrompt("Fetching blob"), client, cfg.Output, layer); err != nil {
+				return err
+			}
+
+			logrus.Infof("layer %s fetched successfully", layer.Digest)
+			return nil
 		})
 	}
 
+	logrus.Infof("fetched %d layers in total successfully", len(layers))
 	return g.Wait()
 }

pkg/backend/inspect.go

@@ -23,6 +23,7 @@ import (
 	"time"
 
 	godigest "github.com/opencontainers/go-digest"
+	"github.com/sirupsen/logrus"
 
 	"github.com/CloudNativeAI/modctl/pkg/config"
 	modelspec "github.com/CloudNativeAI/model-spec/specs-go/v1"
@@ -66,6 +67,7 @@ type InspectedModelArtifactLayer struct {
 
 // Inspect inspects the target from the storage.
 func (b *backend) Inspect(ctx context.Context, target string, cfg *config.Inspect) (*InspectedModelArtifact, error) {
+	logrus.Infof("inspecting target: %s, cfg: %+v", target, cfg)
 	_, err := ParseReference(target)
 	if err != nil {
 		return nil, fmt.Errorf("failed to parse target: %w", err)
@@ -81,11 +83,15 @@ func (b *backend) Inspect(ctx context.Context, target string, cfg *config.Inspec
 		return nil, fmt.Errorf("failed to marshal manifest: %w", err)
 	}
 
+	logrus.Infof("manifest: %s", string(manifestRaw))
+
 	config, err := b.getModelConfig(ctx, target, manifest.Config, cfg.Remote, cfg.PlainHTTP, cfg.Insecure)
 	if err != nil {
 		return nil, fmt.Errorf("failed to get config: %w", err)
 	}
 
+	logrus.Infof("model config: %+v", config)
+
 	inspectedModelArtifact := &InspectedModelArtifact{
 		ID:           manifest.Config.Digest.String(),
 		Digest:       godigest.FromBytes(manifestRaw).String(),

pkg/backend/list.go

@@ -24,8 +24,8 @@ import (
 	"time"
 
 	modelspec "github.com/CloudNativeAI/model-spec/specs-go/v1"
-
 	ocispec "github.com/opencontainers/image-spec/specs-go/v1"
+	"github.com/sirupsen/logrus"
 )
 
 // ModelArtifact is the data model to represent the model artifact.
@@ -44,6 +44,7 @@ type ModelArtifact struct {
 
 // List lists all the model artifacts.
 func (b *backend) List(ctx context.Context) ([]*ModelArtifact, error) {
+	logrus.Info("listing model artifacts")
 	modelArtifacts := []*ModelArtifact{}
 
 	// list all the repositories.
@@ -52,13 +53,17 @@ func (b *backend) List(ctx context.Context) ([]*ModelArtifact, error) {
 		return nil, fmt.Errorf("failed to list repositories: %w", err)
 	}
 
+	logrus.Infof("listed %d repositories: %+v", len(repos), repos)
+
 	// list all the tags in the repository.
 	for _, repo := range repos {
 		tags, err := b.store.ListTags(ctx, repo)
 		if err != nil {
 			return nil, fmt.Errorf("failed to list tags in repository %s: %w", repo, err)
 		}
 
+		logrus.Infof("listed %d tags in repository %s: %+v", len(tags), repo, tags)
+
 		// assemble the model artifact.
 		for _, tag := range tags {
 			modelArtifact, err := b.assembleModelArtifact(ctx, repo, tag)