Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Make module data dir and config reading logs debug level #4566

Open
wants to merge 2 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion config/watcher.go
Original file line number Diff line number Diff line change
Expand Up @@ -73,7 +73,7 @@ func newCloudWatcher(ctx context.Context, config *Config, logger logging.Logger)
}
newConfig, err := readFromCloud(cancelCtx, config, prevCfg, false, checkForNewCert, logger)
if err != nil {
logger.Errorw("error reading cloud config", "error", err)
logger.Debugw("error reading cloud config; will try again", "error", err)
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I (and apparently SEs) have found this log to be output quite frequently on machines with a poor network connection. Particularly when we're in the firstRead case, and the timeout for reading is lowered, this path is not really an "error." I would be in favor of lowering this to the debug level.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm bought into not needing to log this every 10 seconds. I do like having something loosely track whether we're online or offline, but happy to find a way to get that into FTDC.

For robot startup, do we at least log whether we've got a cloud config or are using the cached config? I would like to keep a log line for that. But happy to have it manifest as a simple "we're using a cloud config" or "we're using the cached config". And not inferring which config is getting used based on seeing "error reading cloud config".

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

do we at least log whether we've got a cloud config or are using the cached config?

Good question; we only log when we are relying on the cache. These logs still appear with my changes:

2024-11-19T18:44:06.644Z	WARN	rdk	config/reader.go:621	failed to read config from cloud, checking cache	{"error":"context deadline exceeded"}
2024-11-19T18:44:06.646Z	WARN	rdk	config/reader.go:637	unable to get cloud config; using cached version	{"config last updated":"2024-11-19T13:43:54.075-0500","error":"context deadline exceeded"

We do not log when we are relying on a cloud config. I could add that, but I also feel that since that's the default expected behavior, maybe we don't want a log for it?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We do not log when we are relying on a cloud config. I could add that, but I also feel that since that's the default expected behavior, maybe we don't want a log for it?

I think we can live with that. Being explicit wouldn't hurt either.

The config/reader.go:621 log line -- is there any value in that one existing? My guess is that the "error, context deadline exceeded' that's logged as part of 637 is just a copy of the error reported by 621?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The config/reader.go:621 log line -- is there any value in that one existing?

Yeah I don't think so; removed because your guess below is exactly correct and nothing too critical happens between the two log lines.

My guess is that the "error, context deadline exceeded' that's logged as part of 637 is just a copy of the error reported by 621?

continue
}
if cp, err := newConfig.CopyOnlyPublicFields(); err == nil {
Expand Down
4 changes: 2 additions & 2 deletions module/modmanager/manager.go
Original file line number Diff line number Diff line change
Expand Up @@ -348,7 +348,7 @@ func (mgr *Manager) startModule(ctx context.Context, mod *module) error {

// create the module's data directory
if mod.dataDir != "" {
mgr.logger.Infof("Creating data directory %q for module %q", mod.dataDir, mod.cfg.Name)
mgr.logger.Debugf("Creating data directory %q for module %q", mod.dataDir, mod.cfg.Name)
benjirewis marked this conversation as resolved.
Show resolved Hide resolved
if err := os.MkdirAll(mod.dataDir, 0o750); err != nil {
return errors.WithMessage(err, "error while creating data directory for module "+mod.cfg.Name)
}
Expand Down Expand Up @@ -1121,7 +1121,7 @@ func (m *module) startProcess(
moduleWorkingDirectory, ok := moduleEnvironment["VIAM_MODULE_ROOT"]
if !ok {
moduleWorkingDirectory = filepath.Dir(absoluteExePath)
logger.CWarnw(ctx, "VIAM_MODULE_ROOT was not passed to module. Defaulting to module's working directory",
benjirewis marked this conversation as resolved.
Show resolved Hide resolved
logger.CDebugw(ctx, "VIAM_MODULE_ROOT was not passed to module. Defaulting to module's working directory",
"module", m.cfg.Name, "dir", moduleWorkingDirectory)
} else {
logger.CInfow(ctx, "Starting module in working directory", "module", m.cfg.Name, "dir", moduleWorkingDirectory)
Expand Down
Loading