12933: Log node info in node.json, similar to container.json.

Arvados-DCO-1.1-Signed-off-by: Tom Clegg <tclegg@veritasgenetics.com>

diff --git a/services/crunch-run/crunchrun.go b/services/crunch-run/crunchrun.go
index b97727f41ee06581389f17774acd2f56fe71cb22..eecd6baf5bd21f96d876de24e1b5a260c98674dd 100644 (file)
--- a/services/crunch-run/crunchrun.go
+++ b/services/crunch-run/crunchrun.go
@@ -660,30 +660,14 @@ type infoCommand struct {
        cmd   []string
 }
 
-// LogNodeInfo gathers node information and logs it for debugging and
-// accounting purposes.
-func (runner *ContainerRunner) LogNodeInfo() (err error) {
+// LogHostInfo logs info about the current host, for debugging and
+// accounting purposes. Although it's logged as "node-info", this is
+// about the environment where crunch-run is actually running, which
+// might differ from what's described in the node record (see
+// LogNodeRecord).
+func (runner *ContainerRunner) LogHostInfo() (err error) {
        w := runner.NewLogWriter("node-info")
 
-       hostname := os.Getenv("SLURMD_NODENAME")
-       if hostname == "" {
-               hostname, _ = os.Hostname()
-       }
-       var nodes arvados.NodeList
-       err = runner.ArvClient.Call("GET", "nodes", "", "", map[string]interface{}{
-               "filters": [][]string{{"hostname", "=", hostname}},
-       }, &nodes)
-       if err != nil {
-               return fmt.Errorf("Error retrieving node list: %s", err)
-       }
-       if len(nodes.Items) < 1 {
-               fmt.Fprintf(w, "Node record not available for hostname %s\n", hostname)
-       } else {
-               fmt.Fprintf(w, "Node properties for node %s with hostname %q\n", nodes.Items[0].UUID, hostname)
-               json.NewEncoder(w).Encode(nodes.Items[0].Properties)
-       }
-       fmt.Fprintln(w, "")
-
        commands := []infoCommand{
                {
                        label: "Host Information",
@@ -729,38 +713,72 @@ func (runner *ContainerRunner) LogNodeInfo() (err error) {
 }
 
 // LogContainerRecord gets and saves the raw JSON container record from the API server
-func (runner *ContainerRunner) LogContainerRecord() (err error) {
+func (runner *ContainerRunner) LogContainerRecord() error {
+       logged, err := runner.logAPIResponse("container", "containers", map[string]interface{}{"filters": [][]string{{"uuid", "=", runner.Container.UUID}}}, nil)
+       if !logged && err == nil {
+               err = fmt.Errorf("error: no container record found for %s", runner.Container.UUID)
+       }
+       return err
+}
+
+// LogNodeRecord logs arvados#node record corresponding to the current host.
+func (runner *ContainerRunner) LogNodeRecord() error {
+       hostname := os.Getenv("SLURMD_NODENAME")
+       if hostname == "" {
+               hostname, _ = os.Hostname()
+       }
+       _, err := runner.logAPIResponse("node", "nodes", map[string]interface{}{"filters": [][]string{{"hostname", "=", hostname}}}, func(resp interface{}) {
+               // The "info" field has admin-only info when obtained
+               // with a privileged token, and should not be logged.
+               node, ok := resp.(map[string]interface{})
+               if ok {
+                       delete(node, "info")
+               }
+       })
+       return err
+}
+
+func (runner *ContainerRunner) logAPIResponse(label, path string, params map[string]interface{}, munge func(interface{})) (logged bool, err error) {
        w := &ArvLogWriter{
                ArvClient:     runner.ArvClient,
                UUID:          runner.Container.UUID,
-               loggingStream: "container",
-               writeCloser:   runner.LogCollection.Open("container.json"),
+               loggingStream: label,
+               writeCloser:   runner.LogCollection.Open(label + ".json"),
        }
 
        // Get Container record JSON from the API Server
-       reader, err := runner.ArvClient.CallRaw("GET", "containers", runner.Container.UUID, "", nil)
+       reader, err := runner.ArvClient.CallRaw("GET", path, "", "", nil)
        if err != nil {
-               return fmt.Errorf("While retrieving container record from the API server: %v", err)
+               return false, fmt.Errorf("error getting %s record: %v", label, err)
        }
        defer reader.Close()
 
        dec := json.NewDecoder(reader)
        dec.UseNumber()
-       var cr map[string]interface{}
-       if err = dec.Decode(&cr); err != nil {
-               return fmt.Errorf("While decoding the container record JSON response: %v", err)
+       var resp map[string]interface{}
+       if err = dec.Decode(&resp); err != nil {
+               return false, fmt.Errorf("error decoding %s list response: %v", label, err)
+       }
+       items, ok := resp["items"].([]interface{})
+       if !ok {
+               return false, fmt.Errorf("error decoding %s list response: no \"items\" key in API list response", label)
+       } else if len(items) < 1 {
+               return false, nil
+       }
+       if munge != nil {
+               munge(items[0])
        }
        // Re-encode it using indentation to improve readability
        enc := json.NewEncoder(w)
        enc.SetIndent("", "    ")
-       if err = enc.Encode(cr); err != nil {
-               return fmt.Errorf("While logging the JSON container record: %v", err)
+       if err = enc.Encode(items[0]); err != nil {
+               return false, fmt.Errorf("error logging %s record: %v", label, err)
        }
        err = w.Close()
        if err != nil {
-               return fmt.Errorf("While closing container.json log: %v", err)
+               return false, fmt.Errorf("error closing %s.json in log collection: %v", label, err)
        }
-       return nil
+       return true, nil
 }
 
 // AttachStreams connects the docker container stdin, stdout and stderr logs
@@ -1571,13 +1589,14 @@ func (runner *ContainerRunner) Run() (err error) {
        if err != nil {
                return
        }
-
-       // Gather and record node information
-       err = runner.LogNodeInfo()
+       err = runner.LogHostInfo()
+       if err != nil {
+               return
+       }
+       err = runner.LogNodeRecord()
        if err != nil {
                return
        }
-       // Save container.json record on log collection
        err = runner.LogContainerRecord()
        if err != nil {
                return

diff --git a/services/crunch-run/crunchrun_test.go b/services/crunch-run/crunchrun_test.go
index d21b55ee7d43cbb16d2c553780425a4d43a46158..4979cf8a0c801ee5bc56e48933e97f736dc3d00d 100644 (file)
--- a/services/crunch-run/crunchrun_test.go
+++ b/services/crunch-run/crunchrun_test.go
@@ -236,14 +236,6 @@ func (client *ArvTestClient) Call(method, resourceType, uuid, action string, par
                        "uuid": "`+fakeAuthUUID+`",
                        "api_token": "`+fakeAuthToken+`"
                        }`), output)
-       case method == "GET" && resourceType == "nodes" && uuid == "" && action == "":
-               return json.Unmarshal([]byte(`{
-                       "kind": "arvados#nodeList",
-                       "items": [{
-                               "uuid": "zzzzz-7ekkf-2z3mc76g2q73aio",
-                               "hostname": "compute2",
-                               "properties": {"total_cpu_cores": 16}
-                       }]}`), output)
        default:
                return fmt.Errorf("Not found")
        }
@@ -252,8 +244,23 @@ func (client *ArvTestClient) Call(method, resourceType, uuid, action string, par
 func (client *ArvTestClient) CallRaw(method, resourceType, uuid, action string,
        parameters arvadosclient.Dict) (reader io.ReadCloser, err error) {
        var j []byte
-       if method == "GET" && resourceType == "containers" && action == "" && !client.callraw {
-               j, err = json.Marshal(client.Container)
+       if method == "GET" && resourceType == "nodes" && uuid == "" && action == "" {
+               j = []byte(`{
+                       "kind": "arvados#nodeList",
+                       "items": [{
+                               "uuid": "zzzzz-7ekkf-2z3mc76g2q73aio",
+                               "hostname": "compute2",
+                               "properties": {"total_cpu_cores": 16}
+                       }]}`)
+       } else if method == "GET" && resourceType == "containers" && action == "" && !client.callraw {
+               if uuid == "" {
+                       j, err = json.Marshal(map[string]interface{}{
+                               "items": []interface{}{client.Container},
+                               "kind":  "arvados#nodeList",
+                       })
+               } else {
+                       j, err = json.Marshal(client.Container)
+               }
        } else {
                j = []byte(`{
                        "command": ["sleep", "1"],
@@ -795,14 +802,19 @@ func (s *TestSuite) TestNodeInfoLog(c *C) {
        c.Check(api.CalledWith("container.exit_code", 0), NotNil)
        c.Check(api.CalledWith("container.state", "Complete"), NotNil)
 
+       c.Assert(api.Logs["node"], NotNil)
+       json := api.Logs["node"].String()
+       c.Check(json, Matches, `(?ms).*"uuid": *"zzzzz-7ekkf-2z3mc76g2q73aio".*`)
+       c.Check(json, Matches, `(?ms).*"total_cpu_cores": *16.*`)
+       c.Check(json, Not(Matches), `(?ms).*"info":.*`)
+
        c.Assert(api.Logs["node-info"], NotNil)
-       inf := api.Logs["node-info"].String()
-       c.Check(inf, Matches, `(?ms).*Node properties.*zzzzz-7ekkf-2z3mc76g2q73aio.*"total_cpu_cores":16.*`)
-       c.Check(inf, Matches, `(?ms).*Host Information.*`)
-       c.Check(inf, Matches, `(?ms).*CPU Information.*`)
-       c.Check(inf, Matches, `(?ms).*Memory Information.*`)
-       c.Check(inf, Matches, `(?ms).*Disk Space.*`)
-       c.Check(inf, Matches, `(?ms).*Disk INodes.*`)
+       json = api.Logs["node-info"].String()
+       c.Check(json, Matches, `(?ms).*Host Information.*`)
+       c.Check(json, Matches, `(?ms).*CPU Information.*`)
+       c.Check(json, Matches, `(?ms).*Memory Information.*`)
+       c.Check(json, Matches, `(?ms).*Disk Space.*`)
+       c.Check(json, Matches, `(?ms).*Disk INodes.*`)
 }
 
 func (s *TestSuite) TestContainerRecordLog(c *C) {