15954: Logging and env var fixes.

Arvados-DCO-1.1-Signed-off-by: Tom Clegg <tom@tomclegg.ca>

diff --git a/lib/boot/cmd.go b/lib/boot/cmd.go
index 5f5bb1ee77b8c5fc8c209f447d6e44acddaab3a0..2c3103202427237e94863d5393d1d1bee698a360 100644 (file)
--- a/lib/boot/cmd.go
+++ b/lib/boot/cmd.go
@@ -26,6 +26,7 @@ import (
 
        "git.arvados.org/arvados.git/lib/cmd"
        "git.arvados.org/arvados.git/lib/config"
+       "git.arvados.org/arvados.git/lib/service"
        "git.arvados.org/arvados.git/sdk/go/arvados"
        "git.arvados.org/arvados.git/sdk/go/ctxlog"
        "git.arvados.org/arvados.git/sdk/go/health"
@@ -391,6 +392,23 @@ func (boot *Booter) setEnv(key, val string) {
        boot.environ = append(boot.environ, key+"="+val)
 }
 
+// Remove all but the first occurrence of each env var.
+func dedupEnv(in []string) []string {
+       saw := map[string]bool{}
+       var out []string
+       for _, kv := range in {
+               if split := strings.Index(kv, "="); split < 1 {
+                       panic("invalid environment var: " + kv)
+               } else if saw[kv[:split]] {
+                       continue
+               } else {
+                       saw[kv[:split]] = true
+                       out = append(out, kv)
+               }
+       }
+       return out
+}
+
 func (boot *Booter) installGoProgram(ctx context.Context, srcpath string) error {
        boot.goMutex.Lock()
        defer boot.goMutex.Unlock()
@@ -441,11 +459,13 @@ func (boot *Booter) lookPath(prog string) string {
 // boot command's stderr.
 func (boot *Booter) RunProgram(ctx context.Context, dir string, output io.Writer, env []string, prog string, args ...string) error {
        cmdline := fmt.Sprintf("%s", append([]string{prog}, args...))
-       fmt.Fprintf(boot.Stderr, "%s executing in %s\n", cmdline, dir)
+       boot.logger.WithField("command", cmdline).WithField("dir", dir).Info("executing")
 
        logprefix := prog
        if prog == "bundle" && len(args) > 2 && args[0] == "exec" {
                logprefix = args[1]
+       } else if prog == "arvados-server" && len(args) > 1 {
+               logprefix = args[0]
        }
        if !strings.HasPrefix(dir, "/") {
                logprefix = dir + ": " + logprefix
@@ -460,7 +480,7 @@ func (boot *Booter) RunProgram(ctx context.Context, dir string, output io.Writer
        if err != nil {
                return err
        }
-       logwriter := &logPrefixer{Writer: boot.Stderr, Prefix: []byte("[" + logprefix + "] ")}
+       logwriter := &service.LogPrefixer{Writer: boot.Stderr, Prefix: []byte("[" + logprefix + "] ")}
        go io.Copy(logwriter, stderr)
        if output == nil {
                go io.Copy(logwriter, stdout)
@@ -473,7 +493,9 @@ func (boot *Booter) RunProgram(ctx context.Context, dir string, output io.Writer
        } else {
                cmd.Dir = filepath.Join(boot.SourcePath, dir)
        }
-       cmd.Env = append(env, boot.environ...)
+       env = append([]string(nil), env...)
+       env = append(env, boot.environ...)
+       cmd.Env = dedupEnv(env)
 
        exited := false
        defer func() { exited = true }()

diff --git a/lib/controller/integration_test.go b/lib/controller/integration_test.go
index 157998aa7f85ed9702e286f8a12cfb8a3e05010c..c78686ac8f062961c465f8b853007def02ff92ae 100644 (file)
--- a/lib/controller/integration_test.go
+++ b/lib/controller/integration_test.go
@@ -15,6 +15,7 @@ import (
        "git.arvados.org/arvados.git/lib/boot"
        "git.arvados.org/arvados.git/lib/config"
        "git.arvados.org/arvados.git/lib/controller/rpc"
+       "git.arvados.org/arvados.git/lib/service"
        "git.arvados.org/arvados.git/sdk/go/arvados"
        "git.arvados.org/arvados.git/sdk/go/arvadosclient"
        "git.arvados.org/arvados.git/sdk/go/auth"
@@ -68,6 +69,8 @@ func (s *IntegrationSuite) SetUpSuite(c *check.C) {
       Insecure: true
     Login:
       LoginCluster: z1111
+    SystemLogs:
+      Format: text
     RemoteClusters:
       z1111:
         Host: localhost:` + port["z1111"] + `
@@ -96,7 +99,7 @@ func (s *IntegrationSuite) SetUpSuite(c *check.C) {
                                ListenHost:           "localhost",
                                ControllerAddr:       ":0",
                                OwnTemporaryDatabase: true,
-                               Stderr:               ctxlog.LogWriter(c.Log),
+                               Stderr:               &service.LogPrefixer{Writer: ctxlog.LogWriter(c.Log), Prefix: []byte("[" + id + "] ")},
                        },
                        config: *cfg,
                }

diff --git a/lib/boot/log.go b/lib/service/log.go
similarity index 84%
rename from lib/boot/log.go
rename to lib/service/log.go
index eaaca85672d777a7b78a075b0c2485f9211a41c4..76278030b4046e45fec2ec7227ec5169fb348d9c 100644 (file)
--- a/lib/boot/log.go
+++ b/lib/service/log.go
@@ -2,20 +2,20 @@
 //
 // SPDX-License-Identifier: AGPL-3.0
 
-package boot
+package service
 
 import (
        "bytes"
        "io"
 )
 
-type logPrefixer struct {
+type LogPrefixer struct {
        io.Writer
        Prefix []byte
        did    bool
 }
 
-func (lp *logPrefixer) Write(p []byte) (int, error) {
+func (lp *LogPrefixer) Write(p []byte) (int, error) {
        if len(p) == 0 {
                return 0, nil
        }