diff --git a/cmd/completion/complete.go b/cmd/completion/complete.go index a3d36659..41026142 100644 --- a/cmd/completion/complete.go +++ b/cmd/completion/complete.go @@ -9,25 +9,25 @@ import ( "github.com/wot-oss/tmc/internal/repos" ) -func CompleteRepoNames(cmd *cobra.Command, args []string, toComplete string) ([]string, cobra.ShellCompDirective) { +func CompleteRepoNames(_ *cobra.Command, _ []string, _ string) ([]string, cobra.ShellCompDirective) { config, err := repos.ReadConfig() if err != nil { return nil, cobra.ShellCompDirectiveError } var rNames []string - for k, _ := range config { + for k := range config { rNames = append(rNames, k) } return rNames, cobra.ShellCompDirectiveNoFileComp } -func CompleteRepoTypes(cmd *cobra.Command, args []string, toComplete string) ([]string, cobra.ShellCompDirective) { +func CompleteRepoTypes(_ *cobra.Command, _ []string, _ string) ([]string, cobra.ShellCompDirective) { return repos.SupportedTypes, cobra.ShellCompDirectiveNoFileComp } -func NoCompletionNoFile(cmd *cobra.Command, args []string, toComplete string) ([]string, cobra.ShellCompDirective) { +func NoCompletionNoFile(_ *cobra.Command, _ []string, _ string) ([]string, cobra.ShellCompDirective) { return nil, cobra.ShellCompDirectiveNoFileComp } @@ -65,7 +65,7 @@ func getRepo(cmd *cobra.Command) (*repos.Union, error) { } return u, nil } -func CompleteTMNames(cmd *cobra.Command, args []string, toComplete string) ([]string, cobra.ShellCompDirective) { +func CompleteTMNames(cmd *cobra.Command, _ []string, toComplete string) ([]string, cobra.ShellCompDirective) { rs, err := getRepo(cmd) if err != nil { return nil, cobra.ShellCompDirectiveError @@ -75,7 +75,7 @@ func CompleteTMNames(cmd *cobra.Command, args []string, toComplete string) ([]st return cs, cobra.ShellCompDirectiveNoFileComp | cobra.ShellCompDirectiveNoSpace } -func CompleteTMNamesOrIds(cmd *cobra.Command, args []string, toComplete string) ([]string, cobra.ShellCompDirective) { +func CompleteTMNamesOrIds(cmd *cobra.Command, _ []string, toComplete string) ([]string, cobra.ShellCompDirective) { rs, err := getRepo(cmd) if err != nil { return nil, cobra.ShellCompDirectiveError @@ -85,7 +85,7 @@ func CompleteTMNamesOrIds(cmd *cobra.Command, args []string, toComplete string) } -func CompleteAttachmentNames(cmd *cobra.Command, args []string, toComplete string) ([]string, cobra.ShellCompDirective) { +func CompleteAttachmentNames(cmd *cobra.Command, _ []string, toComplete string) ([]string, cobra.ShellCompDirective) { rs, err := getRepo(cmd) if err != nil { return nil, cobra.ShellCompDirectiveError diff --git a/cmd/import.go b/cmd/import.go index ffd7b85c..0cfccecb 100644 --- a/cmd/import.go +++ b/cmd/import.go @@ -18,7 +18,7 @@ var importCmd = &cobra.Command{ Short: "Import a TM or a directory with TMs into a catalog", Long: `Import a single Thing Model or a directory with Thing Models into a catalog. -Importing a directory will walk the directory tree recursively and import all found ThingModels. +Importing a directory will walk the directory tree recursively and attempt to import all found .json files. Specifying the target repository with --directory or --repo is optional if there's exactly one enabled named repository in the config. `, @@ -31,8 +31,8 @@ func init() { AddRepoDisambiguatorFlags(importCmd) importCmd.Flags().StringP("opt-path", "p", "", "Appends optional path parts to the target path (and id) of imported files, after the mandatory path structure") _ = importCmd.RegisterFlagCompletionFunc("repo", completion.NoCompletionNoFile) - importCmd.Flags().BoolP("opt-tree", "t", false, `Use original directory tree structure below file-or-dirname as --opt-path for each found ThingModel file. - Has no effect when file-or-dirname points to a file. + importCmd.Flags().BoolP("opt-tree", "t", false, `Use original directory tree structure below file-or-directory as --opt-path for each found ThingModel file. + Has no effect when file-or-directory points to a file. Overrides --opt-path`) importCmd.Flags().Bool("force", false, `Force import, even if there are conflicts with existing TMs.`) importCmd.Flags().Bool("ignore-existing", false, `Ignore TMs that have conflicts with existing TMs instead of returning an error code.`) diff --git a/cmd/index.go b/cmd/index.go index 72d02dda..c9f2b9a9 100644 --- a/cmd/index.go +++ b/cmd/index.go @@ -2,8 +2,6 @@ package cmd import ( "context" - "fmt" - "log/slog" "os" "github.com/spf13/cobra" @@ -24,11 +22,8 @@ func init() { AddRepoDisambiguatorFlags(indexCmd) } -func executeRefreshIndex(cmd *cobra.Command, args []string) { - var log = slog.Default() - +func executeRefreshIndex(cmd *cobra.Command, _ []string) { spec := RepoSpecFromFlags(cmd) - log.Debug(fmt.Sprintf("Refreshing index for repository %s", spec)) err := cli.Index(context.Background(), spec) if err != nil { diff --git a/cmd/repo/repo.go b/cmd/repo/repo.go index 6f568a1e..2e8c66cb 100644 --- a/cmd/repo/repo.go +++ b/cmd/repo/repo.go @@ -28,7 +28,7 @@ func init() { repoCmd.AddCommand(repoListCmd) } -func repoList(cmd *cobra.Command, args []string) { +func repoList(_ *cobra.Command, _ []string) { err := cli.RepoList() if err != nil { os.Exit(1) diff --git a/cmd/repo/repo_add.go b/cmd/repo/repo_add.go index 7fd26407..9017ab7b 100644 --- a/cmd/repo/repo_add.go +++ b/cmd/repo/repo_add.go @@ -1,6 +1,7 @@ package repo import ( + "context" "fmt" "os" "strings" @@ -40,7 +41,7 @@ the config may be a simple string, like directory path or a URL, or a json file. descr, _ := cmd.Flags().GetString("description") - err = cli.RepoAdd(name, typ, confStr, confFile, descr) + err = cli.RepoAdd(context.Background(), name, typ, confStr, confFile, descr) if err != nil { _ = cmd.Usage() os.Exit(1) diff --git a/cmd/repo/repo_set_auth.go b/cmd/repo/repo_set_auth.go index 37503171..72b78766 100644 --- a/cmd/repo/repo_set_auth.go +++ b/cmd/repo/repo_set_auth.go @@ -1,6 +1,7 @@ package repo import ( + "context" "os" "github.com/spf13/cobra" @@ -16,7 +17,7 @@ var repoSetAuthCmd = &cobra.Command{ Example: "set-auth http-repo bearer qfdhjf83cblkju", Args: cobra.ExactArgs(3), Run: func(cmd *cobra.Command, args []string) { - err := cli.RepoSetAuth(args[0], args[1], args[2]) + err := cli.RepoSetAuth(context.Background(), args[0], args[1], args[2]) if err != nil { _ = cmd.Usage() os.Exit(1) diff --git a/cmd/repo/repo_set_config.go b/cmd/repo/repo_set_config.go index 31b6f1f5..842dd5a1 100644 --- a/cmd/repo/repo_set_config.go +++ b/cmd/repo/repo_set_config.go @@ -1,6 +1,7 @@ package repo import ( + "context" "fmt" "os" @@ -38,7 +39,7 @@ the config may be a simple string, like a URL, or a json file. descr, _ := cmd.Flags().GetString("description") - err = cli.RepoSetConfig(name, typ, confStr, confFile, descr) + err = cli.RepoSetConfig(context.Background(), name, typ, confStr, confFile, descr) if err != nil { _ = cmd.Usage() os.Exit(1) diff --git a/cmd/root.go b/cmd/root.go index d47112cc..8979a75b 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -49,7 +49,7 @@ func init() { _ = viper.BindPFlag(config.KeyConfigPath, RootCmd.PersistentFlags().Lookup("config")) } -func preRunAll(cmd *cobra.Command, args []string) { +func preRunAll(cmd *cobra.Command, _ []string) { config.ReadInConfig() // set default loglevel depending on subcommand logDefault := cmd != nil && slices.Contains(logEnabledDefaultCmd, cmd.CalledAs()) diff --git a/cmd/validate.go b/cmd/validate.go index 76724861..d9cfe897 100644 --- a/cmd/validate.go +++ b/cmd/validate.go @@ -1,6 +1,7 @@ package cmd import ( + "context" "os" "github.com/spf13/cobra" @@ -13,7 +14,7 @@ var validateCmd = &cobra.Command{ Long: `Validate a ThingModel to ensure it is ready to be imported into TM catalog`, Args: cobra.ExactArgs(1), Run: func(cmd *cobra.Command, args []string) { - err := cli.ValidateFile(args[0]) + err := cli.ValidateFile(context.Background(), args[0]) if err != nil { os.Exit(1) } diff --git a/docs/_pages/60-faq.md b/docs/_pages/60-faq.md index 819000cf..80bdd4f6 100644 --- a/docs/_pages/60-faq.md +++ b/docs/_pages/60-faq.md @@ -4,6 +4,52 @@ permalink: /faq title: Frequently Asked Questions --- -## Question +## Q: How to Import Multiple TMs for the Same Device With Different Protocol Bindings? -Answer +When you have a device that supports several protocol bindings, and you want to keep them in separate TMs, you have +several options of how to import the TMs and still be able to distinguish between the protocols when looking for a TM. + +### Import With Optional Path + +The recommended way is to use the optional path (`--opt-path`) option when importing the TMs to append the protocol name +to the TM name (and thus include it in the ID). For example, + +```bash +tmc import lightall-coap.json --opt-path coap +tmc import lightall-http.json --opt-path http +tmc import lightall-modbus.json --opt-path modbus +``` + +This will result in each TM having a different TM name (e.g. "omnicorp/omnicorp/lightall/**modbus**") and thus having +independent lists of versions. You can then select the right TM for you based on the TM name, fetch the latest version +for the TM name, etc. + +Note that you can achieve the same effect when importing multiple TMs from a directory, if you prepare the folder +structure accordingly and use the `--opt-tree` flag. I.e. if you have prepared the following files: + +```bash +$ find . -type f +./coap/lightall.json +./coap/senseall.json +./http/lightall.json +./http/senseall.json +./modbus/lightall.json +./modbus/senseall.json +``` + +you can import them in one go: + +```bash +tmc import --opt-tree . +``` + +### Use Conventional Versions or Descriptions + +For completeness' sake, the option of defining and using a convention in your TMs' versions or descriptions should be +mentioned. + +You can include the protocol name in the semantic version (e.g. `v1.0.0-modbus`) or prefix the TM's description with +it (e.g. "modbus: Omnicorp Lightall..."). The TMs in this case will all have the same TM name and thus the different +versions will all be listed together. Listing the versions by `tmc versions` will allow to visually recognize which +version has which protocol. However, automatically checking for latest version of a TM for a certain protocol will +require some scripting on your part. diff --git a/docs/adr/adr003-logging-strategy.md b/docs/adr/adr003-logging-strategy.md new file mode 100644 index 00000000..9042bab9 --- /dev/null +++ b/docs/adr/adr003-logging-strategy.md @@ -0,0 +1,50 @@ +# Logging Strategy + +## Status + +accepted + +## Context + +We have not defined a logging strategy and, as a consequence, our code only contains sporadic log statements. The +produced logs give little help in way of tracking app's behaviour or finding bugs. + +When used to serve the REST API, the application needs to produce some king of access/request logs to enable app +usage analysis and find possible performance bottlenecks. + +## Decision + +We have two use-cases: CLI and API server, which differ in the requirements to logging. + +CLI doesn't need much in terms of logging, only to make sure that any errors are propagated to the user. The logs in +this case are only useful if they contain some additional data helpful for understanding the reasons for errors, but +which was deemed too noisy for including in stdout printouts. + +In the API server case, it is necessary to distinguish between log statements from different requests. We will generate +a request id for each request, extend the default logger with fields containing information about request, and pass that +logger in the request's context down the stack. + +### Logging Guidelines + +What follows, should be seen as guidelines, rather than hard and fast rules. Feel free to deviate from them if the +situation warrants. + +- Err on the side of not logging, unless you can explain the value-add of a logging statement. It's better to extend + logging later when a specific need is determined than pollute logs with noise. +- Indicate which component is logging. Use any string as a component identifier that helps to pinpoint the location + where the log is produced. This is a cheap poor man's replacement for collecting stacktrace information which is good + enough most of the time. +- Log at INFO every http request's start and end +- Log errors at those points where information may get lost, e.g. if the \[original] error is not propagated up the + stack, or if the message printed to stdout does not contain all error details. All errors returned via http will be + logged automatically. +- Log expected normal errors at DEBUG, e.g. user attempted to import a TM conflicting with existing one +- Log unexpected errors at WARN (e.g. remote tmc repo returned 5**) or ERROR (e.g. index file could not be locked) +- When logging errors, log any parameters that may have caused the error +- Log auth events with authorization=true flag + +## Consequences + +The logs should get more informative and helpful in tracing errors, while remaining relatively concise. +There will be a number of functions that include `context.Context` in their signature just for access to the logger, as +opposed to being able to get canceled by the context. diff --git a/internal/app/cli/copy.go b/internal/app/cli/copy.go index db36a5b2..9fb2560c 100644 --- a/internal/app/cli/copy.go +++ b/internal/app/cli/copy.go @@ -65,7 +65,7 @@ func Copy(ctx context.Context, repo model.RepoSpec, toRepo model.RepoSpec, searc } } else { if cErr != nil { - cErr = fmt.Errorf("error copying TM %s: %w", version.TMID, cErr) + cErr = fmt.Errorf("couldn't copy TM %s: %w", version.TMID, cErr) totalRes = append(totalRes, operationResult{opResultErr, version.TMID, fmt.Sprintf("%v", cErr)}) if err == nil { err = cErr @@ -142,22 +142,24 @@ func copyAttachments(ctx context.Context, spec model.RepoSpec, toRepo repos.Repo resName := fmt.Sprintf("%s/%s", relDir, att.Name) bytes, aErr = commands.AttachmentFetch(ctx, spec, ref, att.Name, false) if aErr != nil { - if err == nil { - err = aErr - } + aErr = fmt.Errorf("could not fetch attachment %s to %v: %w", att.Name, ref, aErr) results = append(results, operationResult{ typ: opResultErr, resourceId: resName, - text: fmt.Errorf("could not fetch attachment %s to %v: %w", att.Name, ref, err).Error(), + text: aErr.Error(), }) + if err == nil { + err = aErr + } continue } wErr := toRepo.ImportAttachment(ctx, ref, att, bytes, force) if wErr != nil { + wErr = fmt.Errorf("could not import attachment %s to %v: %w", att.Name, ref, wErr) results = append(results, operationResult{ typ: opResultErr, resourceId: resName, - text: fmt.Errorf("could not import attachment %s to %v: %w", att.Name, ref, wErr).Error(), + text: wErr.Error(), }) doIgnore := ignoreExisting && errors.Is(wErr, repos.ErrAttachmentExists) if err == nil && !doIgnore { @@ -180,8 +182,8 @@ func copyThingModel(ctx context.Context, version model.FoundVersion, target repo err = errs[0] } if err != nil { - Stderrf("Error fetching %s: %v", version.TMID, err) e := fmt.Errorf("cannot fetch %s from repo %s: %w", version.TMID, version.FoundIn, err) + Stderrf("Error fetching %s: %v", version.TMID, err) return repos.ImportResultFromError(e) } diff --git a/internal/app/cli/export.go b/internal/app/cli/export.go index 623b0d98..b5dbc5c6 100644 --- a/internal/app/cli/export.go +++ b/internal/app/cli/export.go @@ -110,26 +110,28 @@ func exportAttachments(ctx context.Context, spec model.RepoSpec, outputPath stri finalOutput := filepath.Join(attDir, att.Name) bytes, aErr = commands.AttachmentFetch(ctx, spec, ref, att.Name, false) if aErr != nil { - if err == nil { - err = aErr - } + aErr = fmt.Errorf("could not fetch attachment %s to %v: %w", att.Name, ref, aErr) results = append(results, operationResult{ typ: opResultErr, resourceId: resName, - text: fmt.Errorf("could not fetch attachment %s to %v: %w", att.Name, ref, err).Error(), + text: aErr.Error(), }) + if err == nil { + err = aErr + } continue } wErr := os.WriteFile(finalOutput, bytes, 0660) if wErr != nil { - if err == nil { - err = wErr - } + wErr = fmt.Errorf("could not write attachment %s to %v: %w", att.Name, ref, wErr) results = append(results, operationResult{ typ: opResultErr, resourceId: resName, - text: fmt.Errorf("could not write attachment %s to %v: %w", att.Name, ref, err).Error(), + text: wErr.Error(), }) + if err == nil { + err = wErr + } continue } results = append(results, operationResult{ diff --git a/internal/app/cli/import.go b/internal/app/cli/import.go index 3a6e1806..cba501bd 100644 --- a/internal/app/cli/import.go +++ b/internal/app/cli/import.go @@ -113,8 +113,9 @@ func (p *ImportExecutor) importDirectory(ctx context.Context, absDirname string, func (p *ImportExecutor) importFile(ctx context.Context, filename string, repo repos.Repo, opts repos.ImportOptions) (repos.ImportResult, error) { _, raw, err := utils.ReadRequiredFile(filename) if err != nil { - Stderrf("Couldn't read file %s: %v", filename, err) - return repos.ImportResultFromError(fmt.Errorf("error importing file %s: %w", filename, err)) + err := fmt.Errorf("error reading file %s for import: %w", filename, err) + Stderrf("%v", err.Error()) + return repos.ImportResultFromError(err) } res, err := commands.NewImportCommand(p.now).ImportFile(ctx, raw, repo, opts) if err != nil { @@ -127,6 +128,7 @@ func (p *ImportExecutor) importFile(ctx context.Context, filename string, repo r return res, err } err := fmt.Errorf("error importing file %s: %w", filename, err) + Stderrf("%v", err.Error()) return repos.ImportResultFromError(err) } switch res.Type { @@ -141,7 +143,9 @@ func (p *ImportExecutor) importFile(ctx context.Context, filename string, repo r case repos.ImportResultOK: res.Message = fmt.Sprintf("file %s imported as %s", filename, res.TmID) default: - return repos.ImportResultFromError(fmt.Errorf("unexpected ImportResult type %v when importing file %s", res.Type, filename)) + err := fmt.Errorf("unexpected ImportResult type %v when importing file %s", res.Type, filename) + Stderrf("%v", err.Error()) + return repos.ImportResultFromError(err) } return res, err } diff --git a/internal/app/cli/repo.go b/internal/app/cli/repo.go index 77679680..a17670bb 100644 --- a/internal/app/cli/repo.go +++ b/internal/app/cli/repo.go @@ -1,6 +1,7 @@ package cli import ( + "context" "encoding/json" "errors" "fmt" @@ -42,14 +43,14 @@ func RepoList() error { return nil } -func RepoAdd(name, typ, confStr, confFile, descr string) error { - return repoSaveConfig(name, typ, confStr, confFile, descr, repos.Add) +func RepoAdd(ctx context.Context, name, typ, confStr, confFile, descr string) error { + return repoSaveConfig(ctx, name, typ, confStr, confFile, descr, repos.Add) } -func RepoSetConfig(name, typ, confStr, confFile string, descr string) error { - return repoSaveConfig(name, typ, confStr, confFile, descr, repos.SetConfig) +func RepoSetConfig(ctx context.Context, name, typ, confStr, confFile string, descr string) error { + return repoSaveConfig(ctx, name, typ, confStr, confFile, descr, repos.SetConfig) } -func repoSaveConfig(name, typ, confStr, confFile, descr string, saver func(name string, typ string, confStr string, confFile []byte, descr string) error) error { +func repoSaveConfig(ctx context.Context, name, typ, confStr, confFile, descr string, saver func(name string, typ string, confStr string, confFile []byte, descr string) error) error { if !repos.ValidRepoNameRegex.MatchString(name) { Stderrf("invalid name: %v", name) return ErrInvalidArgs @@ -155,7 +156,7 @@ func RepoRename(oldName, newName string) (err error) { return } -func RepoSetAuth(name, kind, data string) error { +func RepoSetAuth(ctx context.Context, name, kind, data string) error { conf, err := repos.ReadConfig() if err != nil { Stderrf("error setting auth: %v", err) diff --git a/internal/app/cli/serve.go b/internal/app/cli/serve.go index 245002f8..818de37b 100644 --- a/internal/app/cli/serve.go +++ b/internal/app/cli/serve.go @@ -1,6 +1,7 @@ package cli import ( + "context" _ "embed" "fmt" "net" @@ -9,6 +10,7 @@ import ( "github.com/wot-oss/tmc/internal/app/http/cors" "github.com/wot-oss/tmc/internal/model" + "github.com/wot-oss/tmc/internal/utils" "github.com/wot-oss/tmc/internal/app/http/jwt" "github.com/wot-oss/tmc/internal/app/http/server" @@ -27,22 +29,27 @@ type ServeOptions struct { } func Serve(host, port string, opts ServeOptions, repo model.RepoSpec) error { + log := utils.GetLogger(context.Background(), "cli.Serve") defer func() { if r := recover(); r != nil { - Stderrf("could not start server:") - Stderrf(fmt.Sprint(r)) + e := fmt.Errorf("panic: could not start tmc server: %v", r).Error() + log.Error(e) + Stderrf(e) } }() err := validateContextRoot(opts.UrlCtxRoot) if err != nil { Stderrf(err.Error()) + log.Error(err.Error()) return err } // create an instance of our handler (server interface) handlerService, err := http.NewDefaultHandlerService(repo) if err != nil { - Stderrf("Could not start tm-catalog server on %s:%s, %v\n", host, port, err) + err = fmt.Errorf("Could not start tm catalog server on %s:%s, %v\n", host, port, err) + Stderrf(err.Error()) + log.Error(err.Error()) return err } @@ -66,13 +73,20 @@ func Serve(host, port string, opts ServeOptions, repo model.RepoSpec) error { // valid configuration, we can print the banner and start the server fmt.Println(banner) - fmt.Printf("Version of tmc: %s\n", TmcVersion) - fmt.Printf("Starting tm-catalog server on %s:%s\n", host, port) + verMsg := fmt.Sprintf("Version of tmc: %s", TmcVersion) + startMsg := fmt.Sprintf("Starting tmc server on %s:%s", host, port) + fmt.Println(verMsg) + fmt.Println(startMsg) + fmt.Println() + log.Info(verMsg) + log.Info(startMsg) // start server err = s.ListenAndServe() if err != nil { - Stderrf("Could not start tm-catalog server on %s:%s, %v\n", host, port, err) + err = fmt.Errorf("Could not start tm catalog server on %s:%s, %v\n", host, port, err) + Stderrf(err.Error()) + log.Error(err.Error()) return err } @@ -90,6 +104,8 @@ func validateContextRoot(ctxRoot string) error { func getMiddlewares(opts ServeOptions) []server.MiddlewareFunc { var mws []server.MiddlewareFunc + mws = append(mws, http.WithLogAfterRequestProcessing) + mws = append(mws, http.WithRequestLogger) if opts.JWTValidation == true { mws = append(mws, jwt.GetMiddleware(opts.JWTValidationOpts)) } diff --git a/internal/app/cli/validate.go b/internal/app/cli/validate.go index 89055528..553b464d 100644 --- a/internal/app/cli/validate.go +++ b/internal/app/cli/validate.go @@ -1,14 +1,14 @@ package cli import ( + "context" "fmt" "github.com/wot-oss/tmc/internal/commands/validate" "github.com/wot-oss/tmc/internal/utils" ) -func ValidateFile(filename string) error { - +func ValidateFile(ctx context.Context, filename string) error { _, raw, err := utils.ReadRequiredFile(filename) if err != nil { Stderrf("could not read file: %v\n", err) diff --git a/internal/app/http/common.go b/internal/app/http/common.go index 65a855be..f7277b89 100644 --- a/internal/app/http/common.go +++ b/internal/app/http/common.go @@ -5,13 +5,16 @@ import ( "encoding/json" "errors" "fmt" + "log/slog" "net/http" + "github.com/google/uuid" "github.com/santhosh-tekuri/jsonschema/v5" "github.com/wot-oss/tmc/internal/app/http/server" "github.com/wot-oss/tmc/internal/commands" "github.com/wot-oss/tmc/internal/model" "github.com/wot-oss/tmc/internal/repos" + "github.com/wot-oss/tmc/internal/utils" ) const ( @@ -69,12 +72,6 @@ func HandleHealthyResponse(w http.ResponseWriter, r *http.Request) { } func HandleErrorResponse(w http.ResponseWriter, r *http.Request, err error) { - - if err != nil { - //todo: log - fmt.Println(err) - } - errTitle := Error500Title errDetail := Error500Detail errStatus := http.StatusInternalServerError @@ -142,6 +139,16 @@ func HandleErrorResponse(w http.ResponseWriter, r *http.Request, err error) { default: } + if err != nil { + log := utils.GetLogger(r.Context(), "http.HandleErrorResponse") + log = log.With("title", errTitle, "status", errStatus) + if errStatus < http.StatusInternalServerError { + log.Info(errDetail) + } else { + log.Error(errDetail) + } + } + problem := server.ErrorResponse{ Title: errTitle, Detail: &errDetail, @@ -355,3 +362,39 @@ func toImportThingModelResponse(res repos.ImportResult) server.ImportThingModelR Data: data, } } + +func WithRequestLogger(handler http.Handler) http.Handler { + return http.HandlerFunc( + func(w http.ResponseWriter, r *http.Request) { + log := loggerForRequest(r) + ctx := context.WithValue(r.Context(), utils.CtxKeyLogger, log) + utils.GetLogger(ctx, "http.serve").Info("received request") + r = r.WithContext(ctx) + handler.ServeHTTP(w, r) + }) +} + +func WithLogAfterRequestProcessing(handler http.Handler) http.Handler { + return http.HandlerFunc( + func(w http.ResponseWriter, r *http.Request) { + defer func() { + utils.GetLogger(r.Context(), "http.serve").Info("processed request") + }() + handler.ServeHTTP(w, r) + }) +} + +func loggerForRequest(r *http.Request) *slog.Logger { + requestID := r.Header.Get("X-Request-Id") + if requestID == "" { + requestID = newRequestID() + r.Header.Set("X-Request-Id", requestID) + } + log := slog.Default().With("request-id", requestID, "method", r.Method, "path", r.URL.Path) + return log +} + +func newRequestID() string { + rId, _ := uuid.NewRandom() + return rId.String() +} diff --git a/internal/app/http/handler.go b/internal/app/http/handler.go index 68750920..16533fbc 100644 --- a/internal/app/http/handler.go +++ b/internal/app/http/handler.go @@ -29,7 +29,7 @@ func NewTmcHandler(handlerService HandlerService, options TmcHandlerOptions) *Tm } } -// Get the inventory of the catalog +// GetInventory returns the inventory of the catalog // (GET /inventory) func (h *TmcHandler) GetInventory(w http.ResponseWriter, r *http.Request, params server.GetInventoryParams) { @@ -96,7 +96,7 @@ func (h *TmcHandler) GetThingModelByFetchName(w http.ResponseWriter, r *http.Req HandleByteResponse(w, r, http.StatusOK, MimeJSON, data) } -// GetInventoryById Get the metadata of a single TM by ID +// GetInventoryByID returns the metadata of a single TM by ID // (GET /inventory/{tmID}) func (h *TmcHandler) GetInventoryByID(w http.ResponseWriter, r *http.Request, tmID server.TMID, params server.GetInventoryByIDParams) { repo := convertRepoName(params.Repo) @@ -232,14 +232,14 @@ func (h *TmcHandler) GetMpns(w http.ResponseWriter, r *http.Request, params serv } func (h *TmcHandler) GetRepos(w http.ResponseWriter, r *http.Request) { - repos, err := h.Service.ListRepos(r.Context()) + rs, err := h.Service.ListRepos(r.Context()) if err != nil { HandleErrorResponse(w, r, err) return } - resp := toReposResponse(repos) + resp := toReposResponse(rs) HandleJsonResponse(w, r, http.StatusOK, resp) } diff --git a/internal/app/http/jwt/jwtvalidation.go b/internal/app/http/jwt/jwtvalidation.go index ff417759..9651d6b5 100644 --- a/internal/app/http/jwt/jwtvalidation.go +++ b/internal/app/http/jwt/jwtvalidation.go @@ -2,13 +2,13 @@ package jwt import ( "errors" - "log/slog" "net/http" "strings" "github.com/golang-jwt/jwt/v5" httptmc "github.com/wot-oss/tmc/internal/app/http" "github.com/wot-oss/tmc/internal/app/http/server" + "github.com/wot-oss/tmc/internal/utils" ) var jwksKeyFunc jwt.Keyfunc @@ -28,22 +28,26 @@ func jwtValidationMiddleware(h http.Handler) http.Handler { // existing scopes in ctx is the only hint for a protected endpoint scopes := extractAuthScopes(r) if scopes != nil { - slog.Default().Debug("jwt: protected endpoint:", "path", r.URL) + log := utils.GetLogger(r.Context(), "jwt.validation.middleware").With("authentication", true) + log.Debug("jwt: protected endpoint:", "path", r.URL) // protected endpoint, check for bearer tokenString in header tokenString, err := extractBearerToken(r) if err != nil { + log.Warn("failed to extract token", "error", err) httptmc.HandleErrorResponse(w, r, httptmc.NewUnauthorizedError(nil, err.Error())) return } // got token, validate it var token *jwt.Token if token, err = jwt.Parse(tokenString, jwksKeyFunc); err != nil { + log.Warn("token validation failed", "error", err) httptmc.HandleErrorResponse(w, r, httptmc.NewUnauthorizedError(nil, err.Error())) return } // valid token, identify our service in the "aud" claim // https://datatracker.ietf.org/doc/html/rfc7519#section-4.1.3 if err := validateAudClaim(token); err != nil { + log.Warn("failed to validate 'aud' claim", "error", err) httptmc.HandleErrorResponse(w, r, httptmc.NewUnauthorizedError(nil, err.Error())) return } @@ -56,7 +60,7 @@ var extractAuthScopes = func(r *http.Request) any { return r.Context().Value(server.BearerAuthScopes) } -var TokenNotFoundError = errors.New("Authorization header does not contain a bearer token") +var TokenNotFoundError = errors.New("'Authorization' header does not contain a bearer token") var extractBearerToken = func(r *http.Request) (string, error) { // get header and extract token string @@ -71,7 +75,7 @@ var extractBearerToken = func(r *http.Request) (string, error) { return token, nil } -var InvalidAudClaimError = errors.New("Claim 'aud' did not contain valid service id") +var InvalidAudClaimError = errors.New("claim 'aud' did not contain valid service id") func validateAudClaim(token *jwt.Token) error { audClaims, err := token.Claims.GetAudience() diff --git a/internal/app/http/mocks/HandlerService.go b/internal/app/http/mocks/HandlerService.go index b711a508..e8ec9ece 100644 --- a/internal/app/http/mocks/HandlerService.go +++ b/internal/app/http/mocks/HandlerService.go @@ -1,4 +1,4 @@ -// Code generated by mockery v2.42.1. DO NOT EDIT. +// Code generated by mockery v2.46.3. DO NOT EDIT. package mocks diff --git a/internal/app/http/server.go b/internal/app/http/server.go index 41d15970..a9680890 100644 --- a/internal/app/http/server.go +++ b/internal/app/http/server.go @@ -20,7 +20,7 @@ import ( func NewHttpHandler(si server.ServerInterface, mws []server.MiddlewareFunc) http.Handler { r := mux.NewRouter() - r.NotFoundHandler = http.HandlerFunc(handleNoRoute) + r.NotFoundHandler = WithRequestLogger(http.HandlerFunc(handleNoRoute)) options := server.GorillaServerOptions{ BaseRouter: r, ErrorHandlerFunc: HandleErrorResponse, diff --git a/internal/app/http/server/models.gen.go b/internal/app/http/server/models.gen.go index 59eea7de..aea72d16 100644 --- a/internal/app/http/server/models.gen.go +++ b/internal/app/http/server/models.gen.go @@ -339,7 +339,7 @@ type GetTMNameAttachmentParams struct { // Repo Source/target repository name. The parameter is required when repository is ambiguous. See '/repos' Repo *RepoDisambiguator `form:"repo,omitempty" json:"repo,omitempty"` - // Concat Fetch a concatenation of the attachment to a TM name and homonymous attachments to all versions of the same + // Concat Fetch a concatenation of the attachment to a TM name and homonymous attachments to all of its versions Concat *bool `form:"concat,omitempty" json:"concat,omitempty"` } diff --git a/internal/app/http/service.go b/internal/app/http/service.go index 27c7c11a..85d45b66 100644 --- a/internal/app/http/service.go +++ b/internal/app/http/service.go @@ -310,7 +310,7 @@ func (dhs *defaultHandlerService) CheckHealthReady(ctx context.Context) error { _, err := repos.GetUnion(dhs.serveRepo) if err != nil { - return errors.New("invalid repo configuration or ") + return errors.New("invalid repo configuration or named repo not found") } return nil } diff --git a/internal/app/http/service_test.go b/internal/app/http/service_test.go index f6c64de8..479748ce 100644 --- a/internal/app/http/service_test.go +++ b/internal/app/http/service_test.go @@ -23,7 +23,7 @@ func Test_CheckHealthLive(t *testing.T) { // given: a service under test underTest, _ := NewDefaultHandlerService(model.EmptySpec) // when: check health live - err := underTest.CheckHealthLive(nil) + err := underTest.CheckHealthLive(context.Background()) // then: there is no error assert.NoError(t, err) } @@ -38,7 +38,7 @@ func Test_CheckHealthReady(t *testing.T) { rMocks.MockReposAll(t, rMocks.CreateMockAllFunction(nil, r)) // when check health ready - err := underTest.CheckHealthReady(nil) + err := underTest.CheckHealthReady(context.Background()) // then: no error is thrown assert.NoError(t, err) }) @@ -47,7 +47,7 @@ func Test_CheckHealthReady(t *testing.T) { // given: the repo cannot be found rMocks.MockReposGet(t, rMocks.CreateMockGetFunction(t, repo, nil, errors.New("invalid repo name"))) // when check health ready - err := underTest.CheckHealthReady(nil) + err := underTest.CheckHealthReady(context.Background()) // then: an error is thrown assert.Error(t, err) }) @@ -62,7 +62,7 @@ func Test_CheckHealthStartup(t *testing.T) { // given: the repo can be found rMocks.MockReposGet(t, rMocks.CreateMockGetFunction(t, repo, r, nil)) // when check health startup - err := underTest.CheckHealthStartup(nil) + err := underTest.CheckHealthStartup(context.Background()) // then: no error is thrown assert.NoError(t, err) }) @@ -71,7 +71,7 @@ func Test_CheckHealthStartup(t *testing.T) { // given: the repo cannot be found rMocks.MockReposGet(t, rMocks.CreateMockGetFunction(t, repo, nil, errors.New("invalid repo name"))) // when check health startup - err := underTest.CheckHealthStartup(nil) + err := underTest.CheckHealthStartup(context.Background()) // then: an error is thrown assert.Error(t, err) }) @@ -87,7 +87,7 @@ func Test_CheckHealth(t *testing.T) { rMocks.MockReposGet(t, rMocks.CreateMockGetFunction(t, repo, r, nil)) // when check health - err := underTest.CheckHealth(nil) + err := underTest.CheckHealth(context.Background()) // then: no error is thrown assert.NoError(t, err) }) @@ -96,7 +96,7 @@ func Test_CheckHealth(t *testing.T) { // given: the repo cannot be found rMocks.MockReposGet(t, rMocks.CreateMockGetFunction(t, repo, nil, errors.New("invalid repo name"))) // when check health - err := underTest.CheckHealth(nil) + err := underTest.CheckHealth(context.Background()) // then: an error is thrown assert.Error(t, err) }) @@ -409,7 +409,7 @@ func TestService_FetchLatestThingModel(t *testing.T) { t.Run("with invalid fetch name", func(t *testing.T) { // when: fetching ThingModel - res, err := underTest.FetchLatestThingModel(nil, "", "b-corp\\eagle/PM20", false) + res, err := underTest.FetchLatestThingModel(context.Background(), "", "b-corp\\eagle/PM20", false) // then: it returns nil result assert.Nil(t, res) // and then: error is ErrInvalidFetchName @@ -418,7 +418,7 @@ func TestService_FetchLatestThingModel(t *testing.T) { t.Run("with invalid semantic version", func(t *testing.T) { // when: fetching ThingModel - res, err := underTest.FetchLatestThingModel(nil, "", "b-corp/eagle/PM20:v1.", false) + res, err := underTest.FetchLatestThingModel(context.Background(), "", "b-corp/eagle/PM20:v1.", false) // then: it returns nil result assert.Nil(t, res) // and then: error is ErrInvalidIdOrName @@ -461,7 +461,7 @@ func TestService_GetLatestTMMetadata(t *testing.T) { t.Run("with invalid fetch name", func(t *testing.T) { // when: fetching ThingModel - res, err := underTest.GetLatestTMMetadata(nil, "", "b-corp\\eagle/PM20") + res, err := underTest.GetLatestTMMetadata(context.Background(), "", "b-corp\\eagle/PM20") // then: it returns nil result assert.Equal(t, model.FoundVersion{}, res) // and then: error is ErrInvalidFetchName @@ -470,7 +470,7 @@ func TestService_GetLatestTMMetadata(t *testing.T) { t.Run("with invalid semantic version", func(t *testing.T) { // when: fetching ThingModel - res, err := underTest.GetLatestTMMetadata(nil, "", "b-corp/eagle/PM20:v1.") + res, err := underTest.GetLatestTMMetadata(context.Background(), "", "b-corp/eagle/PM20:v1.") // then: it returns empty result assert.Equal(t, model.FoundVersion{}, res) // and then: error is ErrInvalidFetchName @@ -541,7 +541,7 @@ func TestService_ImportThingModel(t *testing.T) { invalidContent := []byte("invalid content") rMocks.MockReposGet(t, rMocks.CreateMockGetFunction(t, repo, r, nil)) // when: importing ThingModel - res, err := underTest.ImportThingModel(nil, "someRepo", invalidContent, repos.ImportOptions{}) + res, err := underTest.ImportThingModel(context.Background(), "someRepo", invalidContent, repos.ImportOptions{}) // then: it returns an error ImportResult assert.Equal(t, repos.ImportResultError, res.Type) assert.Equal(t, err, res.Err) @@ -553,7 +553,7 @@ func TestService_ImportThingModel(t *testing.T) { // given: invalid importTarget rMocks.MockReposGet(t, rMocks.CreateMockGetFunction(t, repo, nil, repos.ErrRepoNotFound)) // when: importing ThingModel - res, err := underTest.ImportThingModel(nil, "someRepo", []byte("some TM content"), repos.ImportOptions{}) + res, err := underTest.ImportThingModel(context.Background(), "someRepo", []byte("some TM content"), repos.ImportOptions{}) // then: it returns an error import result assert.Equal(t, repos.ImportResultError, res.Type) assert.Equal(t, err, res.Err) @@ -576,7 +576,7 @@ func TestService_ImportThingModel(t *testing.T) { } r.On("Import", mock.Anything, mock.Anything, mock.Anything, repos.ImportOptions{}).Return(expRes, nil).Once() // when: importing ThingModel - res, err := underTest.ImportThingModel(nil, "", tmContent, repos.ImportOptions{}) + res, err := underTest.ImportThingModel(context.Background(), "", tmContent, repos.ImportOptions{}) // then: it returns empty tmID assert.Equal(t, expRes, res) // and then: there is no error @@ -600,7 +600,7 @@ func TestService_ImportThingModel(t *testing.T) { r.On("Import", mock.Anything, mock.Anything, mock.Anything, repos.ImportOptions{}).Return(expRes, nil).Once() r.On("Index", mock.Anything, "new-id").Return(nil) // when: importing ThingModel - res, err := underTest.ImportThingModel(nil, "", tmContent, repos.ImportOptions{}) + res, err := underTest.ImportThingModel(context.Background(), "", tmContent, repos.ImportOptions{}) // then: it returns expected warning result assert.Equal(t, expRes, res) // and then: there is no error diff --git a/internal/commands/attachment.go b/internal/commands/attachment.go index 11da46cd..a3a58072 100644 --- a/internal/commands/attachment.go +++ b/internal/commands/attachment.go @@ -3,7 +3,6 @@ package commands import ( "context" "errors" - "fmt" "path/filepath" "strings" @@ -14,7 +13,7 @@ import ( func ImportAttachment(ctx context.Context, spec model.RepoSpec, ref model.AttachmentContainerRef, att model.Attachment, content []byte, force bool) error { repo, err := repos.Get(spec) if err != nil { - return fmt.Errorf("Could not initialize a repo instance for %s: %w\ncheck config", spec, err) + return err } sanitizedAttachmentName := strings.ReplaceAll(filepath.ToSlash(filepath.Clean(att.Name)), "/", "-") @@ -26,7 +25,7 @@ func ImportAttachment(ctx context.Context, spec model.RepoSpec, ref model.Attach func DeleteAttachment(ctx context.Context, spec model.RepoSpec, ref model.AttachmentContainerRef, attachmentName string) error { repo, err := repos.Get(spec) if err != nil { - return fmt.Errorf("Could not initialize a repo instance for %s: %w\ncheck config", spec, err) + return err } err = repo.DeleteAttachment(ctx, ref, attachmentName) @@ -35,7 +34,7 @@ func DeleteAttachment(ctx context.Context, spec model.RepoSpec, ref model.Attach func AttachmentFetch(ctx context.Context, spec model.RepoSpec, ref model.AttachmentContainerRef, attachmentName string, concat bool) ([]byte, error) { repo, err := repos.Get(spec) if err != nil { - return nil, fmt.Errorf("Could not initialize a repo instance for %s: %w\ncheck config", spec, err) + return nil, err } attFound := false diff --git a/internal/commands/fetch.go b/internal/commands/fetch.go index 397ff502..fdbf89d0 100644 --- a/internal/commands/fetch.go +++ b/internal/commands/fetch.go @@ -4,7 +4,6 @@ import ( "context" "encoding/json" "fmt" - "log/slog" "slices" "strings" @@ -34,12 +33,12 @@ func FetchByTMID(ctx context.Context, spec model.RepoSpec, tmid string, restoreI fetch, bytes, err, accessErrors := u.Fetch(ctx, tmid) if err == nil && restoreId { - bytes = restoreExternalId(bytes) + bytes = restoreExternalId(ctx, bytes) } return fetch, bytes, err, accessErrors } -func restoreExternalId(raw []byte) []byte { +func restoreExternalId(ctx context.Context, raw []byte) []byte { linksValue, dataType, _, err := jsonparser.Get(raw, "links") if err != nil && dataType != jsonparser.NotExist { return raw @@ -54,7 +53,7 @@ func restoreExternalId(raw []byte) []byte { err = json.Unmarshal(linksValue, &linksArray) if err != nil { - slog.Default().Error("error unmarshalling links", "error", err) + utils.GetLogger(ctx, "commands.restoreExternalId").Error("error unmarshalling links", "error", err) return raw } var newLinks []map[string]any @@ -72,12 +71,12 @@ func restoreExternalId(raw []byte) []byte { if len(newLinks) > 0 { linksBytes, err := json.Marshal(newLinks) if err != nil { - slog.Default().Error("unexpected marshal error", "error", err) + utils.GetLogger(ctx, "commands.restoreExternalId").Error("unexpected marshal error", "error", err) return raw } withLinks, err = jsonparser.Set(raw, linksBytes, "links") if err != nil { - slog.Default().Error("unexpected json set value error", "error", err) + utils.GetLogger(ctx, "commands.restoreExternalId").Error("unexpected json set value error", "error", err) return raw } } else { @@ -87,7 +86,7 @@ func restoreExternalId(raw []byte) []byte { withId, err := jsonparser.Set(withLinks, idBytes, "id") if err != nil { - slog.Default().Error("unexpected json set value error", "error", err) + utils.GetLogger(ctx, "commands.restoreExternalId").Error("unexpected json set value error", "error", err) return raw } return withId @@ -98,13 +97,12 @@ func restoreExternalId(raw []byte) []byte { } func FetchByName(ctx context.Context, spec model.RepoSpec, fn model.FetchName, restoreId bool) (string, []byte, error, []*repos.RepoAccessError) { - log := slog.Default() id, foundIn, err, errs := ResolveFetchName(ctx, spec, fn) if err != nil { return "", nil, err, errs } - log.Debug(fmt.Sprintf("fetching %v from %s", id, foundIn)) + utils.GetLogger(ctx, "commands.FetchByName").Debug(fmt.Sprintf("fetching %v from %s", id, foundIn)) tmid, bytes, err, _ := FetchByTMID(ctx, foundIn, id, restoreId) return tmid, bytes, err, errs } @@ -127,7 +125,7 @@ func ResolveFetchName(ctx context.Context, spec model.RepoSpec, fn model.FetchNa } } else { if _, err := semver.NewVersion(fn.Semver); err == nil { - id, foundIn, err = findMostRecentMatchingVersion(versions, fn.Semver) + id, foundIn, err = findMostRecentMatchingVersion(ctx, versions, fn.Semver) if err != nil { return id, foundIn, err, errs } @@ -139,19 +137,15 @@ func ResolveFetchName(ctx context.Context, spec model.RepoSpec, fn model.FetchNa } func findMostRecentVersion(versions []model.FoundVersion) (string, model.RepoSpec, error) { - log := slog.Default() if len(versions) == 0 { - err := fmt.Errorf("%w: no versions found", model.ErrTMNameNotFound) - log.Error(err.Error()) - return "", model.EmptySpec, err + return "", model.EmptySpec, fmt.Errorf("%w: no versions found", model.ErrTMNameNotFound) } v := versions[0] return v.TMID, model.NewSpecFromFoundSource(v.FoundIn), nil } -func findMostRecentMatchingVersion(versions []model.FoundVersion, ver string) (id string, source model.RepoSpec, err error) { - log := slog.Default() +func findMostRecentMatchingVersion(ctx context.Context, versions []model.FoundVersion, ver string) (id string, source model.RepoSpec, err error) { ver, _ = strings.CutPrefix(ver, "v") // figure out how to match versions with ver @@ -163,8 +157,7 @@ func findMostRecentMatchingVersion(versions []model.FoundVersion, ver string) (i } else { // at least one semver part is missing in ver c, err := semver.NewConstraint(fmt.Sprintf("~%s", ver)) if err != nil { - log.Error("couldn't parse semver constraint", "error", err) - return "", model.EmptySpec, err + return "", model.EmptySpec, fmt.Errorf("couldn't parse semver constraint: %w", err) } matcher = c.Check } @@ -173,7 +166,8 @@ func findMostRecentMatchingVersion(versions []model.FoundVersion, ver string) (i versions = slices.DeleteFunc(versions, func(version model.FoundVersion) bool { semVersion, err := semver.NewVersion(version.Version.Model) if err != nil { - log.Error(err.Error()) + log := utils.GetLogger(ctx, "commands.findMostRecentMatchingVersion") + log.Warn(err.Error()) return false } matches := matcher(semVersion) @@ -182,9 +176,7 @@ func findMostRecentMatchingVersion(versions []model.FoundVersion, ver string) (i // see if anything remained if len(versions) == 0 { - err := fmt.Errorf("%w: no version %s found", model.ErrTMNotFound, ver) - log.Error(err.Error()) - return "", model.EmptySpec, err + return "", model.EmptySpec, fmt.Errorf("%w: no version %s found", model.ErrTMNotFound, ver) } // and here's our winner diff --git a/internal/commands/import.go b/internal/commands/import.go index 84497692..43c42b49 100644 --- a/internal/commands/import.go +++ b/internal/commands/import.go @@ -5,7 +5,6 @@ import ( "encoding/json" "errors" "fmt" - "log/slog" "path" "strings" "time" @@ -38,25 +37,20 @@ func NewImportCommand(now Now) *ImportCommand { // Returns ImportResult which includes the ID that the TM has been stored under, and error. // If the repo already contains the same TM, the error will be an instance of repos.ErrTMIDConflict func (c *ImportCommand) ImportFile(ctx context.Context, raw []byte, repo repos.Repo, opts repos.ImportOptions) (repos.ImportResult, error) { - log := slog.Default() tm, err := validate.ValidateThingModel(raw) if err != nil { - log.Error("validation failed", "error", err) return repos.ImportResultFromError(err) } - prepared, id, err := prepareToImport(c.now, tm, raw, opts.OptPath) + prepared, id, err := prepareToImport(ctx, c.now, tm, raw, opts.OptPath) if err != nil { return repos.ImportResultFromError(err) } res, err := repo.Import(ctx, id, prepared, opts) - if err == nil { - log.Info("import executed without error") - } return res, err } -func prepareToImport(now Now, tm *model.ThingModel, raw []byte, optPath string) ([]byte, model.TMID, error) { +func prepareToImport(ctx context.Context, now Now, tm *model.ThingModel, raw []byte, optPath string) ([]byte, model.TMID, error) { var intermediate = make([]byte, len(raw)) copy(intermediate, raw) @@ -74,7 +68,7 @@ func prepareToImport(now Now, tm *model.ThingModel, raw []byte, optPath string) if err != nil { if errors.Is(err, model.ErrInvalidId) { // move the existing id to original link if it's external - intermediate = moveIdToOriginalLink(intermediate, origId) + intermediate = moveIdToOriginalLink(ctx, intermediate, origId) } else { // ParseTMID returned unexpected error. better stop here return nil, model.TMID{}, err @@ -90,7 +84,8 @@ func prepareToImport(now Now, tm *model.ThingModel, raw []byte, optPath string) finalId = generatedId } if len(finalId.Name) > maxNameLength { - return nil, model.TMID{}, fmt.Errorf("%w: %s", ErrTMNameTooLong, finalId.Name) + err := fmt.Errorf("%w: %s", ErrTMNameTooLong, finalId.Name) + return nil, model.TMID{}, err } idString, _ := json.Marshal(finalId.String()) final, err := jsonparser.Set(normalized, idString, "id") @@ -100,7 +95,7 @@ func prepareToImport(now Now, tm *model.ThingModel, raw []byte, optPath string) return final, finalId, nil } -func moveIdToOriginalLink(raw []byte, id string) []byte { +func moveIdToOriginalLink(ctx context.Context, raw []byte, id string) []byte { linksValue, dataType, _, err := jsonparser.Get(raw, "links") if err != nil && dataType != jsonparser.NotExist { return raw @@ -116,7 +111,7 @@ func moveIdToOriginalLink(raw []byte, id string) []byte { case jsonparser.Array: err := json.Unmarshal(linksValue, &linksArray) if err != nil { - slog.Default().Error("error unmarshalling links", "error", err) + utils.GetLogger(ctx, "ImportCommand").Debug("error unmarshalling links", "error", err) return raw } for _, eLink := range linksArray { @@ -129,16 +124,20 @@ func moveIdToOriginalLink(raw []byte, id string) []byte { default: // unexpected type of "links" - slog.Default().Warn(fmt.Sprintf("unexpected type of links %v", dataType)) + utils.GetLogger(ctx, "ImportCommand").Debug(fmt.Sprintf("unexpected type of links %v", dataType)) return raw } linksBytes, err := json.Marshal(linksArray) if err != nil { - slog.Default().Error("unexpected marshal error", "error", err) + utils.GetLogger(ctx, "ImportCommand").Error("unexpected marshal error", "error", err) return raw } raw, err = jsonparser.Set(raw, linksBytes, "links") + if err != nil { + utils.GetLogger(ctx, "ImportCommand").Error("failed to set links", "error", err) + return raw + } return raw } diff --git a/internal/commands/import_test.go b/internal/commands/import_test.go index 21aa377b..281733ed 100644 --- a/internal/commands/import_test.go +++ b/internal/commands/import_test.go @@ -74,7 +74,7 @@ func TestMoveIdToOriginalLink(t *testing.T) { } for i, test := range tests { - res := moveIdToOriginalLink([]byte(test.json), test.id) + res := moveIdToOriginalLink(context.Background(), []byte(test.json), test.id) var js map[string]any err := json.Unmarshal(res, &js) assert.NoError(t, err) @@ -118,7 +118,7 @@ func TestPrepareToImport(t *testing.T) { return time.Date(2023, time.November, 10, 12, 32, 43, 0, time.UTC) } t.Run("no id in original", func(t *testing.T) { - b, _, err := prepareToImport(now, &model.ThingModel{ + b, _, err := prepareToImport(context.Background(), now, &model.ThingModel{ Manufacturer: model.SchemaManufacturer{Name: "omnicorp"}, Mpn: "senseall", Author: model.SchemaAuthor{Name: "author"}, @@ -129,7 +129,7 @@ func TestPrepareToImport(t *testing.T) { assert.True(t, bytes.Contains(b, []byte("author/omnicorp/senseall/opt/dir/v3.2.1-20231110123243-7ae21a619c71.tm.json"))) }) t.Run("too long name", func(t *testing.T) { - _, _, err := prepareToImport(now, &model.ThingModel{ + _, _, err := prepareToImport(context.Background(), now, &model.ThingModel{ Manufacturer: model.SchemaManufacturer{Name: strings.Repeat("omnicorpus", 10)}, // 100 chars Mpn: strings.Repeat("senseall", 10), // 80 chars Author: model.SchemaAuthor{Name: strings.Repeat("author", 10)}, // 60 chars @@ -138,7 +138,7 @@ func TestPrepareToImport(t *testing.T) { assert.ErrorIs(t, err, ErrTMNameTooLong) // 100 + 80 + 60 + 13 + 3 slashes in between = 256 chars }) t.Run("foreign string id in original", func(t *testing.T) { - b, _, err := prepareToImport(now, &model.ThingModel{ + b, _, err := prepareToImport(context.Background(), now, &model.ThingModel{ Manufacturer: model.SchemaManufacturer{Name: "omnicorp"}, Mpn: "senseall", Author: model.SchemaAuthor{Name: "author"}, @@ -149,7 +149,7 @@ func TestPrepareToImport(t *testing.T) { assert.True(t, bytes.Contains(b, []byte("author/omnicorp/senseall/opt/dir/v3.2.1-20231110123243-e7dac5728be6.tm.json"))) }) t.Run("our string id in original/correct hash", func(t *testing.T) { - b, _, err := prepareToImport(now, &model.ThingModel{ + b, _, err := prepareToImport(context.Background(), now, &model.ThingModel{ Manufacturer: model.SchemaManufacturer{Name: "omnicorp"}, Mpn: "senseall", Author: model.SchemaAuthor{Name: "author"}, @@ -160,7 +160,7 @@ func TestPrepareToImport(t *testing.T) { assert.True(t, bytes.Contains(b, []byte("author/omnicorp/senseall/opt/dir/v3.2.1-20221010123243-7ae21a619c71.tm.json"))) }) t.Run("our string id in original/incorrect author", func(t *testing.T) { - b, _, err := prepareToImport(now, &model.ThingModel{ + b, _, err := prepareToImport(context.Background(), now, &model.ThingModel{ Manufacturer: model.SchemaManufacturer{Name: "omnicorp"}, Mpn: "senseall", Author: model.SchemaAuthor{Name: "author"}, @@ -171,7 +171,7 @@ func TestPrepareToImport(t *testing.T) { assert.True(t, bytes.Contains(b, []byte("author/omnicorp/senseall/opt/dir/v3.2.1-20231110123243-7ae21a619c71.tm.json"))) }) t.Run("our string id in original/incorrect hash", func(t *testing.T) { - b, _, err := prepareToImport(now, &model.ThingModel{ + b, _, err := prepareToImport(context.Background(), now, &model.ThingModel{ Manufacturer: model.SchemaManufacturer{Name: "omnicorp"}, Mpn: "senseall", Author: model.SchemaAuthor{Name: "author"}, diff --git a/internal/commands/validate/validate.go b/internal/commands/validate/validate.go index 7c2b617d..2a56d9a4 100644 --- a/internal/commands/validate/validate.go +++ b/internal/commands/validate/validate.go @@ -4,7 +4,6 @@ import ( "bytes" _ "embed" "encoding/json" - "log/slog" "strings" "github.com/santhosh-tekuri/jsonschema/v5" @@ -84,8 +83,6 @@ func ValidateAsTmcImportable(raw []byte, parsed any) (*model.ThingModel, error) // ValidateThingModel validates the presence of the mandatory fields in the TM to be imported. // Returns parsed *model.ThingModel, where the author name, manufacturer name, and mpn have been sanitized for use in filenames func ValidateThingModel(raw []byte) (*model.ThingModel, error) { - log := slog.Default() - var parsed any err := json.Unmarshal(raw, &parsed) if err != nil { @@ -96,20 +93,16 @@ func ValidateThingModel(raw []byte) (*model.ThingModel, error) { if err != nil { return nil, err } - log.Info("required Thing Model metadata is present") err = ValidateAsTM(raw, parsed) if err != nil { return tm, err } - log.Info("passed validation against JSON schema for Thing Models") validated, err := ValidateAsModbus(raw, parsed) if validated { if err != nil { return tm, err - } else { - log.Info("passed validation against JSON schema for Modbus protocol binding") } } diff --git a/internal/model/id.go b/internal/model/id.go index a3ea712e..103710f9 100644 --- a/internal/model/id.go +++ b/internal/model/id.go @@ -15,7 +15,6 @@ var ( ErrInvalidPseudoVersion = errors.New("no valid pseudo-version found") ErrInvalidId = errors.New("TM id invalid") ErrInvalidIdOrName = errors.New("id or name invalid") - ErrVersionDiffers = errors.New("id has a differing version from given ThingModel") ) type TMID struct { diff --git a/internal/model/link.go b/internal/model/link.go index 53ea1382..40a47935 100644 --- a/internal/model/link.go +++ b/internal/model/link.go @@ -2,10 +2,6 @@ package model type RelType string -const ( - RelContent RelType = "content" -) - type Link struct { Rel RelType `json:"rel"` HRef string `json:"href"` diff --git a/internal/model/model.go b/internal/model/model.go index 27c72b27..60e6484e 100644 --- a/internal/model/model.go +++ b/internal/model/model.go @@ -3,7 +3,6 @@ package model import ( "errors" "fmt" - "log/slog" "regexp" "github.com/Masterminds/semver/v3" @@ -49,7 +48,6 @@ func ParseFetchName(fetchName string) (FetchName, error) { // Check if there are enough submatches if len(matches) < 2 { err := fmt.Errorf("%w: %s - must be NAME[:SEMVER]", ErrInvalidFetchName, fetchName) - slog.Default().Error(err.Error()) return FetchName{}, err } @@ -78,8 +76,7 @@ func ParseAsTMIDOrFetchName(idOrName string) (*TMID, *FetchName, error) { return nil, &fn, nil } - slog.Default().Info("could not parse as either TMID or fetch name", "idOrName", idOrName) - return nil, nil, fmt.Errorf("%w: %w, %w", ErrInvalidIdOrName, err1, err2) + return nil, nil, fmt.Errorf("could not parse %s as either TMID or fetch name: %w: %w, %w", idOrName, ErrInvalidIdOrName, err1, err2) } type RepoSpec struct { diff --git a/internal/model/toc.go b/internal/model/toc.go index 7b45d907..67dfbfbe 100644 --- a/internal/model/toc.go +++ b/internal/model/toc.go @@ -2,7 +2,6 @@ package model import ( "fmt" - "log/slog" "path/filepath" "slices" "strings" @@ -102,37 +101,6 @@ func (r AttachmentContainerRef) Kind() AttachmentContainerKind { return AttachmentContainerKindTMID } -func (e *IndexEntry) MatchesSearchText(searchQuery string) bool { - if e == nil { - return false - } - searchQuery = utils.ToTrimmedLower(searchQuery) - if strings.Contains(utils.ToTrimmedLower(e.Name), searchQuery) { - return true - } - if strings.Contains(utils.ToTrimmedLower(e.Author.Name), searchQuery) { - return true - } - if strings.Contains(utils.ToTrimmedLower(e.Manufacturer.Name), searchQuery) { - return true - } - if strings.Contains(utils.ToTrimmedLower(e.Mpn), searchQuery) { - return true - } - for _, version := range e.Versions { - if strings.Contains(utils.ToTrimmedLower(version.Description), searchQuery) { - return true - } - if strings.Contains(utils.ToTrimmedLower(version.ExternalID), searchQuery) { - return true - } - } - return false - -} - -const TMLinkRel = "content" - type IndexVersion struct { Description string `json:"description"` Version Version `json:"version"` @@ -166,16 +134,12 @@ func (idx *Index) Sort() { }) } -func (idx *Index) Filter(search *SearchParams) { +func (idx *Index) Filter(search *SearchParams) error { if search == nil { - return + return nil } search.Sanitize() exclude := func(entry *IndexEntry) bool { - if !entry.MatchesSearchText(search.Query) { - return true - } - if !matchesNameFilter(search.Name, entry.Name, search.Options) { return true } @@ -201,7 +165,20 @@ func (idx *Index) Filter(search *SearchParams) { } return e }) + if len(idx.Data) == 0 { + return nil + } + if len(search.Query) > 0 { + del, err := excludeBySimpleContentSearch(search.Query) + if err != nil { + return err + } + if del != nil { + idx.Data = slices.DeleteFunc(idx.Data, del) + } + } + return nil } func matchesNameFilter(acceptedValue string, value string, options SearchOptions) bool { @@ -232,6 +209,36 @@ func matchesFilter(acceptedValues []string, value string) bool { return slices.Contains(acceptedValues, utils.SanitizeName(value)) } +func excludeBySimpleContentSearch(searchQuery string) (func(e *IndexEntry) bool, error) { + return func(e *IndexEntry) bool { + if e == nil { + return true + } + searchQuery = utils.ToTrimmedLower(searchQuery) + if strings.Contains(utils.ToTrimmedLower(e.Name), searchQuery) { + return false + } + if strings.Contains(utils.ToTrimmedLower(e.Author.Name), searchQuery) { + return false + } + if strings.Contains(utils.ToTrimmedLower(e.Manufacturer.Name), searchQuery) { + return false + } + if strings.Contains(utils.ToTrimmedLower(e.Mpn), searchQuery) { + return false + } + for _, version := range e.Versions { + if strings.Contains(utils.ToTrimmedLower(version.Description), searchQuery) { + return false + } + if strings.Contains(utils.ToTrimmedLower(version.ExternalID), searchQuery) { + return false + } + } + return true + }, nil +} + // FindByName searches by TM name and returns a pointer to the IndexEntry if found func (idx *Index) FindByName(name string) *IndexEntry { if idx.dataByName == nil { @@ -406,17 +413,15 @@ func RelAttachmentsDir(ref AttachmentContainerRef) (string, error) { var attDir string switch ref.Kind() { case AttachmentContainerKindInvalid: - return "", fmt.Errorf("%w: %v", ErrInvalidIdOrName, ref) + return "", fmt.Errorf("invalid attachment container reference: %w: %v", ErrInvalidIdOrName, ref) case AttachmentContainerKindTMID: id, err := ParseTMID(ref.TMID) if err != nil { - return "", err + return "", fmt.Errorf("invalid attachment container reference: %w: %v", err, ref) } attDir = fmt.Sprintf("%s/%s/%s", id.Name, AttachmentsDir, id.Version.String()) case AttachmentContainerKindTMName: attDir = fmt.Sprintf("%s/%s", ref.TMName, AttachmentsDir) } - slog.Default().Debug("attachments dir for ref calculated", "container", ref, "attDir", attDir) return attDir, nil - } diff --git a/internal/model/toc_test.go b/internal/model/toc_test.go index c2f56ff6..608a835c 100644 --- a/internal/model/toc_test.go +++ b/internal/model/toc_test.go @@ -10,56 +10,56 @@ import ( func TestIndex_Filter(t *testing.T) { t.Run("filter by name", func(t *testing.T) { idx := prepareIndex() - idx.Filter(&SearchParams{Name: "man/mpn"}) + _ = idx.Filter(&SearchParams{Name: "man/mpn"}) assert.Len(t, idx.Data, 1) assert.NotNil(t, idx.FindByName("man/mpn")) assert.Nil(t, idx.FindByName("aut/man/mpn")) idx = prepareIndex() - idx.Filter(&SearchParams{Name: "aut/man/mpn"}) + _ = idx.Filter(&SearchParams{Name: "aut/man/mpn"}) assert.Len(t, idx.Data, 1) assert.NotNil(t, idx.FindByName("aut/man/mpn")) assert.Nil(t, idx.FindByName("man/mpn")) }) t.Run("filter by name with prefix match", func(t *testing.T) { idx := prepareIndex() - idx.Filter(&SearchParams{Name: "man", Options: SearchOptions{NameFilterType: PrefixMatch}}) + _ = idx.Filter(&SearchParams{Name: "man", Options: SearchOptions{NameFilterType: PrefixMatch}}) assert.Len(t, idx.Data, 1) assert.NotNil(t, idx.FindByName("man/mpn")) assert.Nil(t, idx.FindByName("aut/man/mpn")) idx = prepareIndex() - idx.Filter(&SearchParams{Name: "aut/man/mpn", Options: SearchOptions{NameFilterType: PrefixMatch}}) + _ = idx.Filter(&SearchParams{Name: "aut/man/mpn", Options: SearchOptions{NameFilterType: PrefixMatch}}) assert.Len(t, idx.Data, 1) assert.NotNil(t, idx.FindByName("aut/man/mpn")) assert.Nil(t, idx.FindByName("aut/man/mpn2")) assert.Nil(t, idx.FindByName("man/mpn")) idx = prepareIndex() - idx.Filter(&SearchParams{Name: "aut/man", Options: SearchOptions{NameFilterType: PrefixMatch}}) + _ = idx.Filter(&SearchParams{Name: "aut/man", Options: SearchOptions{NameFilterType: PrefixMatch}}) assert.Len(t, idx.Data, 2) assert.NotNil(t, idx.FindByName("aut/man/mpn")) assert.NotNil(t, idx.FindByName("aut/man/mpn2")) idx = prepareIndex() - idx.Filter(&SearchParams{Name: "aut/man/", Options: SearchOptions{NameFilterType: PrefixMatch}}) + _ = idx.Filter(&SearchParams{Name: "aut/man/", Options: SearchOptions{NameFilterType: PrefixMatch}}) assert.Len(t, idx.Data, 2) assert.NotNil(t, idx.FindByName("aut/man/mpn")) assert.NotNil(t, idx.FindByName("aut/man/mpn2")) idx = prepareIndex() - idx.Filter(&SearchParams{Name: "aut/man/mpn/sub", Options: SearchOptions{NameFilterType: PrefixMatch}}) + _ = idx.Filter(&SearchParams{Name: "aut/man/mpn/sub", Options: SearchOptions{NameFilterType: PrefixMatch}}) assert.Len(t, idx.Data, 0) }) t.Run("filter by mpn", func(t *testing.T) { idx := prepareIndex() - idx.Filter(&SearchParams{Mpn: []string{"mpn2"}}) + _ = idx.Filter(&SearchParams{Mpn: []string{"mpn2"}}) assert.Len(t, idx.Data, 1) assert.NotNil(t, idx.FindByName("aut/man/mpn2")) assert.Nil(t, idx.FindByName("aut/man/mpn")) idx = prepareIndex() - idx.Filter(&SearchParams{Mpn: []string{"mpn", "mpn2", "mpn45"}}) + _ = idx.Filter(&SearchParams{Mpn: []string{"mpn", "mpn2", "mpn45"}}) assert.Len(t, idx.Data, 4) assert.NotNil(t, idx.FindByName("aut/man/mpn")) assert.NotNil(t, idx.FindByName("aut/man/mpn2")) @@ -67,14 +67,14 @@ func TestIndex_Filter(t *testing.T) { }) t.Run("filter by manufacturer", func(t *testing.T) { idx := prepareIndex() - idx.Filter(&SearchParams{Manufacturer: []string{"man"}}) + _ = idx.Filter(&SearchParams{Manufacturer: []string{"man"}}) assert.Len(t, idx.Data, 3) assert.NotNil(t, idx.FindByName("aut/man/mpn2")) assert.NotNil(t, idx.FindByName("aut/man/mpn")) assert.Nil(t, idx.FindByName("aut/man2/mpn")) idx = prepareIndex() - idx.Filter(&SearchParams{Manufacturer: []string{"man", "man2", "mpn45"}}) + _ = idx.Filter(&SearchParams{Manufacturer: []string{"man", "man2", "mpn45"}}) assert.Len(t, idx.Data, 4) assert.NotNil(t, idx.FindByName("aut/man/mpn")) assert.NotNil(t, idx.FindByName("aut/man/mpn2")) @@ -83,7 +83,7 @@ func TestIndex_Filter(t *testing.T) { }) t.Run("filter by author", func(t *testing.T) { idx := prepareIndex() - idx.Filter(&SearchParams{Author: []string{"man"}}) + _ = idx.Filter(&SearchParams{Author: []string{"man"}}) assert.Len(t, idx.Data, 1) assert.NotNil(t, idx.FindByName("man/mpn")) assert.Nil(t, idx.FindByName("aut/man/mpn2")) @@ -91,7 +91,7 @@ func TestIndex_Filter(t *testing.T) { assert.Nil(t, idx.FindByName("aut/man2/mpn")) idx = prepareIndex() - idx.Filter(&SearchParams{Author: []string{"aut"}}) + _ = idx.Filter(&SearchParams{Author: []string{"aut"}}) assert.Len(t, idx.Data, 3) assert.Nil(t, idx.FindByName("man/mpn")) assert.NotNil(t, idx.FindByName("aut/man/mpn2")) @@ -99,7 +99,7 @@ func TestIndex_Filter(t *testing.T) { assert.NotNil(t, idx.FindByName("aut/man2/mpn")) idx = prepareIndex() - idx.Filter(&SearchParams{Author: []string{"man", "aut"}}) + _ = idx.Filter(&SearchParams{Author: []string{"man", "aut"}}) assert.Len(t, idx.Data, 4) assert.NotNil(t, idx.FindByName("man/mpn")) assert.NotNil(t, idx.FindByName("aut/man/mpn2")) @@ -108,38 +108,38 @@ func TestIndex_Filter(t *testing.T) { }) t.Run("filter by query", func(t *testing.T) { idx := prepareIndex() - idx.Filter(&SearchParams{Query: ""}) + _ = idx.Filter(&SearchParams{Query: ""}) assert.Len(t, idx.Data, 4) idx = prepareIndex() - idx.Filter(&SearchParams{Query: "z"}) + _ = idx.Filter(&SearchParams{Query: "z"}) assert.Len(t, idx.Data, 0) idx = prepareIndex() - idx.Filter(&SearchParams{Query: "a"}) + _ = idx.Filter(&SearchParams{Query: "a"}) assert.Len(t, idx.Data, 4) idx = prepareIndex() - idx.Filter(&SearchParams{Query: "d1"}) + _ = idx.Filter(&SearchParams{Query: "d1"}) assert.Len(t, idx.Data, 1) assert.Len(t, idx.Data[0].Versions, 2) idx = prepareIndex() - idx.Filter(&SearchParams{Query: "d5"}) + _ = idx.Filter(&SearchParams{Query: "d5"}) assert.Len(t, idx.Data, 2) assert.NotNil(t, idx.FindByName("aut/man/mpn2")) assert.NotNil(t, idx.FindByName("aut/man2/mpn")) }) t.Run("filter by author and manufacturer", func(t *testing.T) { idx := prepareIndex() - idx.Filter(&SearchParams{Manufacturer: []string{"man"}, Author: []string{"aut"}}) + _ = idx.Filter(&SearchParams{Manufacturer: []string{"man"}, Author: []string{"aut"}}) assert.Len(t, idx.Data, 2) assert.NotNil(t, idx.FindByName("aut/man/mpn2")) assert.NotNil(t, idx.FindByName("aut/man/mpn")) assert.Nil(t, idx.FindByName("aut/man2/mpn")) idx = prepareIndex() - idx.Filter(&SearchParams{Manufacturer: []string{"man"}, Author: []string{"man", "aut"}}) + _ = idx.Filter(&SearchParams{Manufacturer: []string{"man"}, Author: []string{"man", "aut"}}) assert.Len(t, idx.Data, 3) assert.NotNil(t, idx.FindByName("aut/man/mpn")) assert.NotNil(t, idx.FindByName("aut/man/mpn2")) @@ -169,13 +169,13 @@ func TestIndex_Filter(t *testing.T) { author := "aut^hor" manuf := "Man&ufacturer" mpn := "M/PN" - idx.Filter(ToSearchParams(&author, &manuf, &mpn, nil, nil, nil)) + _ = idx.Filter(ToSearchParams(&author, &manuf, &mpn, nil, nil, nil)) assert.Len(t, idx.Data, 1) author = "Aut%hor" manuf = "Man-ufacturer" mpn = "M&pN" - idx.Filter(ToSearchParams(&author, &manuf, &mpn, nil, nil, nil)) + _ = idx.Filter(ToSearchParams(&author, &manuf, &mpn, nil, nil, nil)) assert.Len(t, idx.Data, 1) }) } diff --git a/internal/repos/errors.go b/internal/repos/errors.go index 6f12030d..1f2daa96 100644 --- a/internal/repos/errors.go +++ b/internal/repos/errors.go @@ -16,7 +16,6 @@ var ( ErrInvalidErrorCode = errors.New("invalid error code") ErrInvalidCompletionParams = errors.New("invalid completion parameters") ErrNotSupported = errors.New("method not supported") - ErrIndexMismatch = errors.New("index does not reflect repository content, maybe needs rebuild") ErrNoIndex = errors.New("no table of contents found. Run `index` for this repo") ) diff --git a/internal/repos/fs.go b/internal/repos/fs.go index c1bb0e22..1471e09d 100644 --- a/internal/repos/fs.go +++ b/internal/repos/fs.go @@ -5,7 +5,6 @@ import ( "encoding/json" "errors" "fmt" - "log/slog" "os" "path" "path/filepath" @@ -24,12 +23,10 @@ const ( defaultFilePermissions = 0664 indexLockTimeout = 5 * time.Second indexLocRetryDelay = 13 * time.Millisecond - errTmExistsPrefix = "Thing Model already exists under id: " TMExt = ".tm.json" ) var ErrRootInvalid = errors.New("root is not a directory") -var ErrIndexLocked = errors.New("could not acquire lock on index file") var osStat = os.Stat // mockable for testing var osReadFile = os.ReadFile // mockable for testing @@ -45,7 +42,7 @@ type FileRepo struct { func NewFileRepo(config map[string]any, spec model.RepoSpec) (*FileRepo, error) { loc := utils.JsGetString(config, KeyRepoLoc) if loc == nil { - return nil, fmt.Errorf("invalid file repo config. loc is either not found or not a string") + return nil, fmt.Errorf("cannot create a file repo from spec %v. Invalid config. loc is either not found or not a string", spec) } rootPath, err := utils.ExpandHome(*loc) if err != nil { @@ -59,7 +56,7 @@ func NewFileRepo(config map[string]any, spec model.RepoSpec) (*FileRepo, error) func (f *FileRepo) Import(ctx context.Context, id model.TMID, raw []byte, opts ImportOptions) (ImportResult, error) { if len(raw) == 0 { - err := errors.New("nothing to write") + err := fmt.Errorf("nothing to write for id %v", id) return ImportResultFromError(err) } idS := id.String() @@ -70,11 +67,8 @@ func (f *FileRepo) Import(ctx context.Context, id model.TMID, raw []byte, opts I return ImportResultFromError(err) } - match, existingId := f.getExistingID(idS) - log := slog.Default() - log.Debug(fmt.Sprintf("match: %v, existingId: %v", match, existingId)) + match, existingId := f.getExistingID(ctx, idS) if (match == idMatchDigest || match == idMatchFull) && !opts.Force { - log.Info(fmt.Sprintf("Same TM content already exists under ID %v", existingId)) err := &ErrTMIDConflict{Type: IdConflictSameContent, ExistingId: existingId} return ImportResult{Type: ImportResultError, Message: err.Error(), Err: err}, err } @@ -84,11 +78,8 @@ func (f *FileRepo) Import(ctx context.Context, id model.TMID, raw []byte, opts I err := fmt.Errorf("could not write TM to catalog: %v", err) return ImportResultFromError(err) } - log.Info("saved Thing Model file", "filename", fullPath) if match == idMatchTimestamp && !opts.Force { - msg := fmt.Sprintf("Version and timestamp clash with existing %v", existingId) - log.Info(msg) err := &ErrTMIDConflict{Type: IdConflictSameTimestamp, ExistingId: existingId} return ImportResult{Type: ImportResultWarning, TmID: idS, Message: err.Error(), Err: err}, nil } @@ -119,7 +110,7 @@ func (f *FileRepo) Delete(ctx context.Context, id string) error { fullFilename, dir, _ := f.filenames(id) err = os.Remove(fullFilename) if os.IsNotExist(err) { - return model.ErrTMNotFound + return fmt.Errorf("couldn't delete TM file %s: %w", id, model.ErrTMNotFound) } attDir, _ := f.getAttachmentsDir(model.NewTMIDAttachmentContainerRef(id)) h, err := f.listAttachments(model.NewTMIDAttachmentContainerRef(id)) @@ -134,7 +125,7 @@ func (f *FileRepo) Delete(ctx context.Context, id string) error { _attDir := filepath.Dir(attDir) // make sure there's no mistake, and we're about to delete the correct dir with attachments if filepath.Base(_attDir) != model.AttachmentsDir { - return fmt.Errorf("internal error: not in .attachments directory: %s", attDir) + return fmt.Errorf("internal error while deleting %s: not in .attachments directory: %s", id, attDir) } err = os.RemoveAll(_attDir) if err != nil { @@ -143,7 +134,7 @@ func (f *FileRepo) Delete(ctx context.Context, id string) error { } _ = rmEmptyDirs(dir, f.root) - _, err = f.updateIndex(ctx, f.indexUpdaterForIds(ctx, id)) + _, err = f.updateIndex(ctx, f.indexUpdaterForIds(id)) return err } @@ -151,14 +142,13 @@ func rmEmptyDirs(from string, upTo string) error { from, errF := filepath.Abs(from) upTo, errU := filepath.Abs(upTo) if errF != nil { - slog.Default().Error("from path cannot be converted to absolute path", "error", errF) + errF = fmt.Errorf("from path %s cannot be converted to absolute path: %w", from, errF) return errF } else if errU != nil { - slog.Default().Error("upTo path cannot be converted to absolute path", "error", errU) + errU = fmt.Errorf("upTo path %s cannot be converted to absolute path: %w", upTo, errU) return errU } else if !strings.HasPrefix(from, upTo) { - err := errors.New("from path is not below upTo") - slog.Default().Error("error removing empty dirs", "error", err) + err := fmt.Errorf("cannot remove empty dirs: from path %s is not below upTo %s", from, upTo) return err } @@ -194,7 +184,7 @@ const ( idMatchTimestamp // semver and timestamp match ) -func (f *FileRepo) getExistingID(ids string) (idMatch, string) { +func (f *FileRepo) getExistingID(ctx context.Context, ids string) (idMatch, string) { fullName, dir, base := f.filenames(ids) // try full repoName as given if _, err := os.Stat(fullName); err == nil { @@ -207,7 +197,7 @@ func (f *FileRepo) getExistingID(ids string) (idMatch, string) { } version, err := model.ParseTMVersion(strings.TrimSuffix(base, TMExt)) if err != nil { - slog.Default().Error("invalid TM version in TM id", "id", ids, "error", err) + utils.GetLogger(ctx, "FileRepo").Warn("invalid TM version in TM id", "id", ids, "error", err) return idMatchNone, "" } idPrefix := strings.TrimSuffix(ids, base) @@ -261,7 +251,7 @@ func (f *FileRepo) Fetch(ctx context.Context, id string) (string, []byte, error) if err != nil { return "", nil, err } - match, actualId := f.getExistingID(id) + match, actualId := f.getExistingID(ctx, id) if match != idMatchFull && match != idMatchDigest { return "", nil, model.ErrTMNotFound } @@ -285,7 +275,7 @@ func (f *FileRepo) Index(ctx context.Context, ids ...string) error { _, err = f.updateIndex(ctx, f.fullIndexRebuild) return err } - _, err = f.updateIndex(ctx, f.indexUpdaterForIds(ctx, ids...)) + _, err = f.updateIndex(ctx, f.indexUpdaterForIds(ids...)) return err } @@ -318,9 +308,6 @@ func (f *FileRepo) Spec() model.RepoSpec { } func (f *FileRepo) List(ctx context.Context, search *model.SearchParams) (model.SearchResult, error) { - log := slog.Default() - log.Debug(fmt.Sprintf("Creating list with filter '%v'", search)) - err := f.checkRootValid() if err != nil { return model.SearchResult{}, err @@ -336,7 +323,10 @@ func (f *FileRepo) List(ctx context.Context, search *model.SearchParams) (model. if err != nil { return model.SearchResult{}, err } - idx.Filter(search) + err = idx.Filter(search) + if err != nil { + return model.SearchResult{}, err + } idx.Sort() // the index is supposed to be sorted on disk, but we don't trust external storage, hence we'll sort here one more time to be extra sure return model.NewIndexToFoundMapper(f.Spec().ToFoundSource()).ToSearchResult(*idx), nil } @@ -367,7 +357,6 @@ func (f *FileRepo) indexFilename() string { } func (f *FileRepo) Versions(ctx context.Context, name string) ([]model.FoundVersion, error) { - log := slog.Default() name = strings.TrimSpace(name) res, err := f.List(ctx, &model.SearchParams{Name: name}) if err != nil { @@ -376,7 +365,6 @@ func (f *FileRepo) Versions(ctx context.Context, name string) ([]model.FoundVers if len(res.Entries) != 1 { err := fmt.Errorf("%w: %s", model.ErrTMNameNotFound, name) - log.Error(err.Error()) return nil, err } @@ -401,21 +389,16 @@ func (f *FileRepo) GetTMMetadata(ctx context.Context, tmID string) ([]model.Foun } func (f *FileRepo) ImportAttachment(ctx context.Context, container model.AttachmentContainerRef, attachment model.Attachment, content []byte, force bool) error { - log := slog.Default() - log.Debug(fmt.Sprintf("Importing attachment %s for '%v'", attachment, container)) - err := f.checkRootValid() if err != nil { return err } - log.Debug("root dir validated") unlock, err := f.lockIndex(ctx) defer unlock() if err != nil { return err } - log.Debug("index locked") attDir, err := f.prepareAttachmentOperation(container) if err != nil { @@ -439,7 +422,7 @@ func (f *FileRepo) ImportAttachment(ctx context.Context, container model.Attachm return err } - _, err = f.updateIndex(ctx, f.indexUpdaterForImportAttachment(ctx, container, attachment, content)) + _, err = f.updateIndex(ctx, f.indexUpdaterForImportAttachment(container, attachment, content)) if err != nil { return err } @@ -463,9 +446,6 @@ func (f *FileRepo) prepareAttachmentOperation(ref model.AttachmentContainerRef) } func (f *FileRepo) FetchAttachment(ctx context.Context, ref model.AttachmentContainerRef, attachmentName string) ([]byte, error) { - log := slog.Default() - log.Debug(fmt.Sprintf("Fetching attachment %s for '%v'", attachmentName, ref)) - err := f.checkRootValid() if err != nil { return nil, err @@ -508,9 +488,6 @@ func (f *FileRepo) verifyAttachmentExistsInIndex(ref model.AttachmentContainerRe return nil } func (f *FileRepo) DeleteAttachment(ctx context.Context, ref model.AttachmentContainerRef, attachmentName string) error { - log := slog.Default() - log.Debug(fmt.Sprintf("Deleting attachment %s for '%v'", attachmentName, ref)) - err := f.checkRootValid() if err != nil { return err @@ -537,7 +514,7 @@ func (f *FileRepo) DeleteAttachment(ctx context.Context, ref model.AttachmentCon return err } - _, err = f.updateIndex(ctx, f.indexUpdaterForDeleteAttachment(ctx, ref, attachmentName)) + _, err = f.updateIndex(ctx, f.indexUpdaterForDeleteAttachment(ref, attachmentName)) if err != nil { return err } @@ -619,7 +596,6 @@ func getFileNames(dir string) ([]string, error) { func (f *FileRepo) getAttachmentsDir(ref model.AttachmentContainerRef) (string, error) { relDir, err := model.RelAttachmentsDir(ref) attDir := filepath.Join(f.root, relDir) - slog.Default().Debug("attachments dir calculated", "container", ref, "attDir", attDir) return attDir, err } @@ -627,10 +603,8 @@ func (f *FileRepo) checkRootValid() error { stat, err := os.Stat(f.root) if err != nil || !stat.IsDir() { err := fmt.Errorf("%s: %w", f.Spec(), ErrRootInvalid) - slog.Default().Debug(err.Error()) return err } - slog.Default().Debug(fmt.Sprintf("%s: root dir check ok", f.Spec())) return nil } @@ -686,7 +660,6 @@ func makeAbs(dir string) (string, error) { func (f *FileRepo) updateIndex(ctx context.Context, updater indexUpdater) (*model.Index, error) { // Prepare data collection for logging stats - var log = slog.Default() start := time.Now() oldNames := f.readNamesFile() @@ -718,15 +691,15 @@ func (f *FileRepo) updateIndex(ctx context.Context, updater indexUpdater) (*mode return nil, err } - msg := "Updated index with %d records in %s " - msg = fmt.Sprintf(msg, fileCount, duration.String()) - log.Info(msg) + msg := fmt.Sprintf("Updated index with %d records in %s ", fileCount, duration.String()) + utils.GetLogger(ctx, "FileRepo").Debug(msg) + return newIndex, nil } type indexUpdater func(ctx context.Context, oldIndex *model.Index, oldNames []string) (newIndex *model.Index, newNames []string, updatedFileCount int, err error) -func (f *FileRepo) indexUpdaterForIds(ctx context.Context, ids ...string) indexUpdater { +func (f *FileRepo) indexUpdaterForIds(ids ...string) indexUpdater { return func(ctx context.Context, oldIndex *model.Index, oldNames []string) (*model.Index, []string, int, error) { fileCount := 0 newNames := oldNames @@ -738,9 +711,9 @@ func (f *FileRepo) indexUpdaterForIds(ctx context.Context, ids ...string) indexU return nil, nil, 0, ctx.Err() default: } - path := filepath.Join(f.root, id) - info, statErr := osStat(path) - upd, id, nameDeleted, err := f.updateIndexWithFile(newIndex, path, info, statErr) + pth := filepath.Join(f.root, id) + info, statErr := osStat(pth) + upd, id, nameDeleted, err := f.updateIndexWithFile(ctx, newIndex, pth, info, statErr) if err != nil { return nil, nil, 0, err } @@ -766,7 +739,7 @@ func (f *FileRepo) indexUpdaterForIds(ctx context.Context, ids ...string) indexU } } -func (f *FileRepo) indexUpdaterForDeleteAttachment(ctx context.Context, ref model.AttachmentContainerRef, attName string) indexUpdater { +func (f *FileRepo) indexUpdaterForDeleteAttachment(ref model.AttachmentContainerRef, attName string) indexUpdater { return func(ctx context.Context, oldIndex *model.Index, oldNames []string) (*model.Index, []string, int, error) { select { case <-ctx.Done(): @@ -788,7 +761,7 @@ func (f *FileRepo) indexUpdaterForDeleteAttachment(ctx context.Context, ref mode } } -func (f *FileRepo) indexUpdaterForImportAttachment(ctx context.Context, ref model.AttachmentContainerRef, att model.Attachment, content []byte) indexUpdater { +func (f *FileRepo) indexUpdaterForImportAttachment(ref model.AttachmentContainerRef, att model.Attachment, content []byte) indexUpdater { return func(ctx context.Context, oldIndex *model.Index, oldNames []string) (*model.Index, []string, int, error) { select { case <-ctx.Done(): @@ -824,7 +797,7 @@ func (f *FileRepo) fullIndexRebuild(ctx context.Context, oldIndex *model.Index, return ctx.Err() default: } - upd, id, _, err := f.updateIndexWithFile(newIndex, path, info, err) + upd, id, _, err := f.updateIndexWithFile(ctx, newIndex, path, info, err) if err != nil { return err } @@ -848,7 +821,7 @@ func (f *FileRepo) fullIndexRebuild(ctx context.Context, oldIndex *model.Index, } func (f *FileRepo) reindexAttachments(containers map[model.AttachmentContainerRef]struct{}, oldIndex *model.Index, newIndex *model.Index) error { - for ref, _ := range containers { + for ref := range containers { dir, _ := f.getAttachmentsDir(ref) // ref is sure to be valid nameAttachments, err := getFileNames(dir) if err != nil { @@ -871,8 +844,8 @@ func (f *FileRepo) reindexAttachments(containers map[model.AttachmentContainerRe return nil } -func (f *FileRepo) updateIndexWithFile(idx *model.Index, path string, info os.FileInfo, err error) (updated bool, indexedId model.TMID, deletedName string, errr error) { - log := slog.Default() +func (f *FileRepo) updateIndexWithFile(ctx context.Context, idx *model.Index, path string, info os.FileInfo, err error) (updated bool, indexedId model.TMID, deletedName string, errr error) { + log := utils.GetLogger(ctx, "FileRepo") idS, _ := strings.CutPrefix(filepath.ToSlash(filepath.Clean(path)), filepath.ToSlash(filepath.Clean(f.root))) idS, _ = strings.CutPrefix(idS, "/") if os.IsNotExist(err) { @@ -893,16 +866,12 @@ func (f *FileRepo) updateIndexWithFile(idx *model.Index, path string, info os.Fi } thingMeta, err := f.getThingMetadata(path) if err != nil { - err = fmt.Errorf("failed to extract metadata from file %s with error: %w", path, err) - log.Error(err.Error()) - log.Error("The file will be excluded from the table of contents.") + log.Warn(fmt.Sprintf("failed to extract metadata from file %s: %v. The file will be excluded from index", path, err)) return false, model.TMID{}, "", nil } err = idx.Insert(&thingMeta.tm) if err != nil { - log.Error(fmt.Sprintf("Failed to insert %s into index:", path)) - log.Error(err.Error()) - log.Error("The file will be excluded from index") + log.Warn(fmt.Sprintf("failed to insert %s into index: %v. The file will be excluded from index", path, err)) return false, model.TMID{}, "", nil } return true, thingMeta.id, "", nil @@ -911,13 +880,12 @@ func (f *FileRepo) updateIndexWithFile(idx *model.Index, path string, info os.Fi type unlockFunc func() func (f *FileRepo) lockIndex(ctx context.Context) (unlockFunc, error) { - log := slog.Default() - log.Debug(fmt.Sprintf("%s: attempting to lock index", f.Spec())) rd := filepath.Join(f.root, RepoConfDir) stat, err := os.Stat(rd) if err != nil || !stat.IsDir() { err := os.MkdirAll(rd, defaultDirPermissions) if err != nil { + err := fmt.Errorf("couldn't create repo config dir %s: %w", rd, err) return func() {}, err } } @@ -929,21 +897,15 @@ func (f *FileRepo) lockIndex(ctx context.Context) (unlockFunc, error) { cancel() _ = fl.Unlock() f.idx = nil - log.Debug(fmt.Sprintf("unlocked index file: %s", idxFile)) } locked, err := fl.TryLockContext(ctx, indexLocRetryDelay) - if err != nil { - //log.Debug("failed to lock index file: %s", idxFile) + if err != nil || !locked { + err = fmt.Errorf("failed to lock index file %s: %w", idxFile, err) return unlock, err } - if !locked { - //log.Debug("failed to lock index file: %s", idxFile) - return unlock, ErrIndexLocked - } f.moveOldIndex(idxFile) - log.Debug(fmt.Sprintf("locked index file: %s", idxFile)) return unlock, nil } @@ -1038,7 +1000,8 @@ func (f *FileRepo) ListCompletions(ctx context.Context, kind string, args []stri return names, nil case CompletionKindFetchNames: if strings.Contains(toComplete, "..") { - return nil, fmt.Errorf("%w :no completions for name containing '..'", ErrInvalidCompletionParams) + err := fmt.Errorf("%w :no completions for name containing '..': %s", ErrInvalidCompletionParams, toComplete) + return nil, err } name, _, _ := strings.Cut(toComplete, ":") @@ -1053,13 +1016,14 @@ func (f *FileRepo) ListCompletions(ctx context.Context, kind string, args []stri if !e.IsDir() && strings.HasSuffix(e.Name(), TMExt) { ver, err := model.ParseTMVersion(strings.TrimSuffix(e.Name(), TMExt)) if err != nil { + utils.GetLogger(ctx, "FileRepo.ListCompletions").Debug(err.Error()) continue } vm[ver.BaseString()] = struct{}{} } } var vs []string - for v, _ := range vm { + for v := range vm { vs = append(vs, fmt.Sprintf("%s:%s", name, v)) } slices.Sort(vs) diff --git a/internal/repos/fs_test.go b/internal/repos/fs_test.go index 8fb05992..b9847afe 100644 --- a/internal/repos/fs_test.go +++ b/internal/repos/fs_test.go @@ -525,7 +525,7 @@ func TestFileRepo_UpdateIndex_RemoveId(t *testing.T) { index, err := r.readIndex() assert.NoError(t, err) // then: nothing changes - index.Filter(&model.SearchParams{Name: "omnicorp-tm-department/omnicorp/omnilamp"}) + _ = index.Filter(&model.SearchParams{Name: "omnicorp-tm-department/omnicorp/omnilamp"}) if assert.Equal(t, 1, len(index.Data)) { assert.Equal(t, 3, len(index.Data[0].Versions)) } @@ -542,7 +542,7 @@ func TestFileRepo_UpdateIndex_RemoveId(t *testing.T) { index, err := r.readIndex() assert.NoError(t, err) // then: nothing changes - index.Filter(&model.SearchParams{Name: "omnicorp-tm-department/omnicorp/omnilamp"}) + _ = index.Filter(&model.SearchParams{Name: "omnicorp-tm-department/omnicorp/omnilamp"}) if assert.Equal(t, 1, len(index.Data)) { assert.Equal(t, 3, len(index.Data[0].Versions)) } @@ -561,7 +561,7 @@ func TestFileRepo_UpdateIndex_RemoveId(t *testing.T) { index, err := r.readIndex() assert.NoError(t, err) // then: version is removed from index - index.Filter(&model.SearchParams{Name: "omnicorp-tm-department/omnicorp/omnilamp"}) + _ = index.Filter(&model.SearchParams{Name: "omnicorp-tm-department/omnicorp/omnilamp"}) if assert.Equal(t, 1, len(index.Data)) { assert.Equal(t, 2, len(index.Data[0].Versions)) } @@ -581,7 +581,7 @@ func TestFileRepo_UpdateIndex_RemoveId(t *testing.T) { index, err := r.readIndex() assert.NoError(t, err) // then: name is removed from index - index.Filter(&model.SearchParams{Name: "omnicorp-tm-department/omnicorp/omnilamp/subfolder"}) + _ = index.Filter(&model.SearchParams{Name: "omnicorp-tm-department/omnicorp/omnilamp/subfolder"}) assert.Equal(t, 0, len(index.Data)) names := r.readNamesFile() // then: name is removed from names file diff --git a/internal/repos/http.go b/internal/repos/http.go index 7ee9355e..063189b1 100644 --- a/internal/repos/http.go +++ b/internal/repos/http.go @@ -6,7 +6,6 @@ import ( "errors" "fmt" "io" - "log/slog" "net/http" "net/url" "os" @@ -30,6 +29,10 @@ var once sync.Once func getHttpClient() *http.Client { once.Do(func() { + if config.ConfigDir == "" { // this is probably a test run, but even if it isn't, we don't want to write the cache in the working directory + httpClient = http.DefaultClient + return + } cacheDir := filepath.Join(config.ConfigDir, ".http-cache") err := os.MkdirAll(cacheDir, 0770) if err != nil { @@ -170,7 +173,10 @@ func (h *HttpRepo) List(ctx context.Context, search *model.SearchParams) (model. if err != nil { return model.SearchResult{}, err } - idx.Filter(search) + err = idx.Filter(search) + if err != nil { + return model.SearchResult{}, err + } return model.NewIndexToFoundMapper(h.Spec().ToFoundSource()).ToSearchResult(*idx), nil } @@ -189,7 +195,7 @@ func (h *HttpRepo) getIndex(ctx context.Context) (*model.Index, error) { case http.StatusOK: var idx model.Index err = json.Unmarshal(data, &idx) - return &idx, nil + return &idx, err default: return nil, errors.New(fmt.Sprintf("received unexpected HTTP response from remote server: %s", resp.Status)) } @@ -211,24 +217,24 @@ func doHttp(req *http.Request, auth map[string]any) (*http.Response, error) { } } resp, err := getHttpClient().Do(req) + if err != nil { + utils.GetLogger(req.Context(), "HttpRepo").Error(err.Error()) + } return resp, err } func (h *HttpRepo) Versions(ctx context.Context, name string) ([]model.FoundVersion, error) { - log := slog.Default() if len(name) == 0 { - log.Error("Please specify a name to show the TM.") - return nil, errors.New("please specify a name to show the TM") + return nil, errors.New("cannot list versions for empty TM name") } name = strings.TrimSpace(name) idx, err := h.List(ctx, &model.SearchParams{Name: name}) if err != nil { - return nil, err + return nil, fmt.Errorf("%s: %w", name, model.ErrTMNameNotFound) } if len(idx.Entries) != 1 { - log.Error(fmt.Sprintf("No TM found with name: %s", name)) - return nil, model.ErrTMNameNotFound + return nil, fmt.Errorf("%s: %w", name, model.ErrTMNameNotFound) } return idx.Entries[0].Versions, nil diff --git a/internal/repos/mocks/Repo.go b/internal/repos/mocks/Repo.go index c3e3493c..6fc451bf 100644 --- a/internal/repos/mocks/Repo.go +++ b/internal/repos/mocks/Repo.go @@ -1,4 +1,4 @@ -// Code generated by mockery v2.42.1. DO NOT EDIT. +// Code generated by mockery v2.46.3. DO NOT EDIT. package mocks diff --git a/internal/repos/repo.go b/internal/repos/repo.go index a4dcd52c..b817a71b 100644 --- a/internal/repos/repo.go +++ b/internal/repos/repo.go @@ -129,13 +129,13 @@ type ImportOptions struct { var Get = func(spec model.RepoSpec) (Repo, error) { if spec.Dir() != "" { if spec.RepoName() != "" { - return nil, model.ErrInvalidSpec + return nil, fmt.Errorf("could not initialize a repo instance for %s: %w\ncheck config", spec, model.ErrInvalidSpec) } return NewFileRepo(map[string]any{KeyRepoType: "file", KeyRepoLoc: spec.Dir()}, spec) } repos, err := ReadConfig() if err != nil { - return nil, err + return nil, fmt.Errorf("could not initialize a repo instance for %s: could not read config: %w", spec, err) } repos = filterEnabled(repos) parent, child := splitRepoName(spec.RepoName()) @@ -144,24 +144,28 @@ var Get = func(spec model.RepoSpec) (Repo, error) { if parent == "" { switch len(repos) { case 0: - return nil, ErrRepoNotFound + return nil, fmt.Errorf("could not initialize a repo instance for %s: %w\ncheck config", spec, ErrRepoNotFound) case 1: for n, v := range repos { rc = v spec = model.NewRepoSpec(n) } default: - return nil, ErrAmbiguous + return nil, fmt.Errorf("could not initialize a repo instance for %s: %w\ncheck config", spec, ErrAmbiguous) } } else { if !ok { - return nil, ErrRepoNotFound + return nil, fmt.Errorf("could not initialize a repo instance for %s: %w\ncheck config", spec, ErrRepoNotFound) } } if child != "" { rc[keySubRepo] = child } - return createRepo(rc, spec) + repo, err := createRepo(rc, spec) + if err != nil { + return nil, fmt.Errorf("could not initialize a repo instance for %s: %w\ncheck config", spec, err) + } + return repo, err } func splitRepoName(name string) (string, string) { diff --git a/internal/repos/tmc.go b/internal/repos/tmc.go index ee9e720d..817ba74b 100644 --- a/internal/repos/tmc.go +++ b/internal/repos/tmc.go @@ -8,7 +8,6 @@ import ( "errors" "fmt" "io" - "log/slog" "net/http" "net/url" "strings" @@ -249,6 +248,8 @@ func (t *TmcRepo) Import(ctx context.Context, id model.TMID, raw []byte, opts Im } b, err := io.ReadAll(resp.Body) if err != nil { + err := fmt.Errorf("could not read response body: %w", err) + utils.GetLogger(ctx, "TmcRepo.Import").Warn(err.Error()) return ImportResultFromError(err) } @@ -257,6 +258,8 @@ func (t *TmcRepo) Import(ctx context.Context, id model.TMID, raw []byte, opts Im var res server.ImportThingModelResponse err = json.Unmarshal(b, &res) if err != nil { + err := fmt.Errorf("could not unmarshal response from remote tmc: %w", err) + utils.GetLogger(ctx, "TmcRepo.Import").Warn(err.Error()) return ImportResultFromError(err) } msg := "" @@ -266,6 +269,8 @@ func (t *TmcRepo) Import(ctx context.Context, id model.TMID, raw []byte, opts Im if res.Data.Code != nil && *res.Data.Code != "" { cErr, err := ParseErrTMIDConflict(*res.Data.Code) if err != nil { + err := fmt.Errorf("failed to parse returned conflict error code %s: %w", *res.Data.Code, err) + utils.GetLogger(ctx, "TmcRepo.Import").Warn(err.Error()) return ImportResultFromError(err) } return ImportResult{Type: ImportResultWarning, TmID: res.Data.TmID, Message: msg, Err: cErr}, nil @@ -275,6 +280,8 @@ func (t *TmcRepo) Import(ctx context.Context, id model.TMID, raw []byte, opts Im var e server.ErrorResponse err = json.Unmarshal(b, &e) if err != nil { + err := fmt.Errorf("could not unmarshal error response from remote tmc: %w", err) + utils.GetLogger(ctx, "TmcRepo.Import").Warn(err.Error()) return ImportResultFromError(err) } detail := e.Title @@ -289,18 +296,21 @@ func (t *TmcRepo) Import(ctx context.Context, id model.TMID, raw []byte, opts Im } cErr, err := ParseErrTMIDConflict(eCode) if err != nil { + err := fmt.Errorf("failed to parse returned conflict error code %s: %w", eCode, err) + utils.GetLogger(ctx, "TmcRepo.Import").Warn(err.Error()) return ImportResultFromError(err) } return ImportResultFromError(cErr) case http.StatusInternalServerError, http.StatusUnauthorized, http.StatusBadRequest: - err := errors.New(detail) + err := fmt.Errorf("received error response from remote tmc server: %v, %s", resp.Status, detail) + utils.GetLogger(ctx, "TmcRepo.Import").Debug(err.Error()) return ImportResultFromError(err) default: - err := errors.New("unexpected status not handled correctly") - return ImportResultFromError(err) + panic(fmt.Errorf("unhandled response status code: %v", resp.StatusCode)) } default: - err := errors.New(fmt.Sprintf("received unexpected HTTP response from remote TM catalog: %s", resp.Status)) + err := fmt.Errorf("received unexpected HTTP response from remote tmc server: %v", resp.Status) + utils.GetLogger(ctx, "TmcRepo.Import").Error(err.Error()) return ImportResultFromError(err) } } @@ -335,9 +345,13 @@ func (t *TmcRepo) Delete(ctx context.Context, id string) error { case http.StatusNotFound: return model.ErrTMNotFound case http.StatusInternalServerError, http.StatusUnauthorized: - return newErrorFromResponse(b) + err := newErrorFromResponse(b) + utils.GetLogger(ctx, "TmcRepo.Delete").Error(err.Error()) + return err default: - return errors.New(fmt.Sprintf("received unexpected HTTP response from remote TM catalog: %s", resp.Status)) + err := fmt.Errorf("received unexpected HTTP response from remote TM catalog: %s", resp.Status) + utils.GetLogger(ctx, "TmcRepo.Delete").Error(err.Error()) + return err } } @@ -452,7 +466,7 @@ func appendQueryArray(u *url.URL, key string, values []string) { } func (t *TmcRepo) Versions(ctx context.Context, name string) ([]model.FoundVersion, error) { - log := slog.Default() + log := utils.GetLogger(ctx, "TmcRepo") name = strings.TrimSpace(name) if len(name) == 0 { log.Error("cannot show versions for empty TM name.") diff --git a/internal/repos/tmc_test.go b/internal/repos/tmc_test.go index cfb52772..dc4bd305 100644 --- a/internal/repos/tmc_test.go +++ b/internal/repos/tmc_test.go @@ -755,21 +755,21 @@ func TestTmcRepo_Push(t *testing.T) { reqBody: importBody, respBody: []byte(`{"detail":"bad request"}`), status: http.StatusBadRequest, - expErr: errors.New("bad request"), + expErr: errors.New("received error response from remote tmc server: 400 Bad Request, bad request"), }, { name: "internal server error", reqBody: importBody, respBody: []byte(`{"detail":"something bad happened"}`), status: http.StatusInternalServerError, - expErr: errors.New("something bad happened"), + expErr: errors.New("received error response from remote tmc server: 500 Internal Server Error, something bad happened"), }, { name: "unexpected status", reqBody: importBody, respBody: []byte(`{"detail":"no coffee for you"}`), status: http.StatusTeapot, - expErr: errors.New("received unexpected HTTP response from remote TM catalog: 418 I'm a teapot"), + expErr: errors.New("received unexpected HTTP response from remote tmc server: 418 I'm a teapot"), }, } diff --git a/internal/utils/util.go b/internal/utils/util.go index 4aa643ec..a2a87447 100644 --- a/internal/utils/util.go +++ b/internal/utils/util.go @@ -3,6 +3,7 @@ package utils import ( "bufio" "bytes" + "context" "errors" "fmt" "io" @@ -18,31 +19,23 @@ import ( // ReadRequiredFile reads the file. Returns expanded absolute representation of the filename and file contents. // Removes Byte-Order-Mark from the content func ReadRequiredFile(name string) (string, []byte, error) { - var log = slog.Default() - abs, err := filepath.Abs(name) if err != nil { - log.Error("error expanding file name", "filename", name, "error", err) - return "", nil, err + return "", nil, fmt.Errorf("error expanding file name %s: %w", name, err) } - log.Debug("reading file", "filename", abs) stat, err := os.Stat(abs) if err != nil { - log.Error("error reading file", "filename", abs, "error", err) - return "", nil, err + return "", nil, fmt.Errorf("error reading file %s: %w", abs, err) } if stat.IsDir() { - err = errors.New("not a file") - return "", nil, err + return "", nil, fmt.Errorf("%s is not a file", abs) } raw, err := os.ReadFile(abs) if err != nil { - log.Error("error reading file", "filename", abs, "error", err) - return "", nil, err + return "", nil, fmt.Errorf("error reading file %s: %w", abs, err) } raw = removeBOM(raw) - log.Debug(fmt.Sprintf("read %d bytes from %s beginning with %s", len(raw), abs, string(raw[:100]))) return abs, raw, nil } @@ -61,7 +54,6 @@ func ExpandHome(path string) (string, error) { } home, err := os.UserHomeDir() if err != nil { - slog.Default().Error("cannot expand user home directory", "error", err) return "", fmt.Errorf("cannot expand user home directory: %w", err) } _, rest, found := strings.Cut(path, "~") @@ -297,3 +289,19 @@ func DetectMediaType(userGivenType string, filename string, getReader ReadCloser } return mediaOctetStream } + +const CtxKeyLogger = "logger" + +// GetLogger returns the logger that is valid in the context +// If component is not empty, the logger is extended with the field "where" having that value. +func GetLogger(ctx context.Context, component string) *slog.Logger { + cv := ctx.Value(CtxKeyLogger) + l, ok := cv.(*slog.Logger) + if !ok || l == nil { + l = slog.Default() + } + if component != "" { + l = l.With("where", component) + } + return l +}