Additional logging & local reader cleanup (#5238)

Author: cheukt

cli/module_build.go

@@ -3,7 +3,6 @@ package cli
 import (
 	"archive/tar"
 	"compress/gzip"
-	"context"
 	"fmt"
 	"io"
 	"net/url"
@@ -661,7 +660,7 @@ func ReloadModuleAction(c *cli.Context, args reloadModuleArgs) error {
 // reloadModuleAction is the testable inner reload logic.
 func reloadModuleAction(c *cli.Context, vc *viamClient, args reloadModuleArgs, logger logging.Logger) error {
 	// TODO(RSDK-9727) it'd be nice for this to be a method on a viam client rather than taking one as an arg
-	partID, err := resolvePartID(c.Context, args.PartID, args.CloudConfig)
+	partID, err := resolvePartID(args.PartID, args.CloudConfig)
 	if err != nil {
 		return err
 	}
@@ -831,14 +830,14 @@ func validateReloadableArchive(c *cli.Context, build *manifestBuildInfo) error {
 }
 
 // resolvePartID takes an optional provided part ID (from partFlag), and an optional default viam.json, and returns a part ID to use.
-func resolvePartID(ctx context.Context, partIDFromFlag, cloudJSON string) (string, error) {
+func resolvePartID(partIDFromFlag, cloudJSON string) (string, error) {
 	if len(partIDFromFlag) > 0 {
 		return partIDFromFlag, nil
 	}
 	if len(cloudJSON) == 0 {
 		return "", errors.New("no --part and no default json")
 	}
-	conf, err := config.ReadLocalConfig(ctx, cloudJSON, logging.NewLogger("config"))
+	conf, err := config.ReadLocalConfig(cloudJSON, logging.NewLogger("config"))
 	if err != nil {
 		return "", err
 	}

cli/module_reload_test.go

@@ -93,13 +93,13 @@ func TestRestartModule(t *testing.T) {
 func TestResolvePartId(t *testing.T) {
 	c := newTestContext(t, map[string]any{})
 	// empty flag, no path
-	partID, err := resolvePartID(c.Context, c.String(generalFlagPartID), "")
+	partID, err := resolvePartID(c.String(generalFlagPartID), "")
 	test.That(t, err, test.ShouldNotBeNil)
 	test.That(t, partID, test.ShouldBeEmpty)
 
 	// empty flag, fake path
 	missingPath := filepath.Join(t.TempDir(), "MISSING.json")
-	_, err = resolvePartID(c.Context, c.String(generalFlagPartID), missingPath)
+	_, err = resolvePartID(c.String(generalFlagPartID), missingPath)
 	test.That(t, err, test.ShouldNotBeNil)
 
 	// empty flag, valid path
@@ -108,13 +108,13 @@ func TestResolvePartId(t *testing.T) {
 	test.That(t, err, test.ShouldBeNil)
 	_, err = fi.WriteString(`{"cloud":{"app_address":"https://app.viam.com:443","id":"JSON-PART","secret":"SECRET"}}`)
 	test.That(t, err, test.ShouldBeNil)
-	partID, err = resolvePartID(c.Context, c.String(generalFlagPartID), path)
+	partID, err = resolvePartID(c.String(generalFlagPartID), path)
 	test.That(t, err, test.ShouldBeNil)
 	test.That(t, partID, test.ShouldEqual, "JSON-PART")
 
 	// given flag, valid path
 	c = newTestContext(t, map[string]any{generalFlagPartID: "FLAG-PART"})
-	partID, err = resolvePartID(c.Context, c.String(generalFlagPartID), path)
+	partID, err = resolvePartID(c.String(generalFlagPartID), path)
 	test.That(t, err, test.ShouldBeNil)
 	test.That(t, partID, test.ShouldEqual, "FLAG-PART")
 }

config/reader.go

@@ -329,7 +329,6 @@ func Read(
 
 // ReadLocalConfig reads a config from the given file but does not fetch any config from the remote servers.
 func ReadLocalConfig(
-	ctx context.Context,
 	filePath string,
 	logger logging.Logger,
 ) (*Config, error) {
@@ -338,7 +337,7 @@ func ReadLocalConfig(
 		return nil, err
 	}
 
-	return fromReader(ctx, filePath, bytes.NewReader(buf), logger, nil)
+	return fromReaderLocal(filePath, bytes.NewReader(buf), logger)
 }
 
 // FromReader reads a config from the given reader and specifies
@@ -353,14 +352,12 @@ func FromReader(
 	return fromReader(ctx, originalPath, r, logger, conn)
 }
 
-// fromReader reads a config from the given reader and specifies
+// fromReaderLocal reads a config from the given reader and specifies
 // where, if applicable, the file the reader originated from.
-func fromReader(
-	ctx context.Context,
+func fromReaderLocal(
 	originalPath string,
 	r io.Reader,
 	logger logging.Logger,
-	conn rpc.ClientConn,
 ) (*Config, error) {
 	// First read and process config from disk
 	unprocessedConfig := Config{
@@ -374,6 +371,23 @@ func fromReader(
 	if err != nil {
 		return nil, errors.Wrapf(err, "failed to process Config")
 	}
+	return cfgFromDisk, err
+}
+
+// fromReader reads a config from the given reader and specifies
+// where, if applicable, the file the reader originated from.
+func fromReader(
+	ctx context.Context,
+	originalPath string,
+	r io.Reader,
+	logger logging.Logger,
+	conn rpc.ClientConn,
+) (*Config, error) {
+	// First read and process config from disk
+	cfgFromDisk, err := fromReaderLocal(originalPath, r, logger)
+	if err != nil {
+		return nil, err
+	}
 
 	if conn != nil && cfgFromDisk.Cloud != nil {
 		cfg, err := readFromCloud(ctx, cfgFromDisk, nil, true, true, logger, conn)

web/server/entrypoint.go

@@ -187,13 +187,10 @@ func RunServer(ctx context.Context, args []string, _ logging.Logger) (err error)
 	var appConn rpc.ClientConn
 
 	// Read the config from disk and use it to initialize the remote logger.
-	initialReadCtx, cancel := context.WithTimeout(ctx, time.Second*5)
-	cfgFromDisk, err := config.ReadLocalConfig(initialReadCtx, argsParsed.ConfigFile, logger.Sublogger("config"))
+	cfgFromDisk, err := config.ReadLocalConfig(argsParsed.ConfigFile, logger.Sublogger("config"))
 	if err != nil {
-		cancel()
 		return err
 	}
-	cancel()
 
 	if argsParsed.OutputTelemetry {
 		exporter := perf.NewDevelopmentExporter()
@@ -261,13 +258,14 @@ func RunServer(ctx context.Context, args []string, _ logging.Logger) (err error)
 // runServer is an entry point to starting the web server after the local config is read. Once the local config
 // is read the logger may be initialized to remote log. This ensure we capture errors starting up the server and report to the cloud.
 func (s *robotServer) runServer(ctx context.Context) error {
-	initialReadCtx, cancel := context.WithTimeout(ctx, time.Second*5)
-	cfg, err := config.Read(initialReadCtx, s.args.ConfigFile, s.logger, s.conn)
+	if s.conn != nil {
+		s.logger.CInfo(ctx, "Getting up-to-date config from cloud...")
+	}
+	// config.Read will add a timeout using contextutils.GetTimeoutCtx, so no need to add a separate timeout.
+	cfg, err := config.Read(ctx, s.args.ConfigFile, s.logger, s.conn)
 	if err != nil {
-		cancel()
 		return err
 	}
-	cancel()
 	config.UpdateFileConfigDebug(cfg.Debug)
 
 	err = s.serveWeb(ctx, cfg)
@@ -503,7 +501,7 @@ func (s *robotServer) serveWeb(ctx context.Context, cfg *config.Config) (err err
 		slowWatcherCancel()
 		<-slowWatcher
 	}()
-
+	s.logger.CInfo(ctx, "Processing initial robot config...")
 	fullProcessedConfig, err := s.processConfig(cfg)
 	if err != nil {
 		return err