Started logging memory reserved in addition to memory used.

Started using GetOrCreateMap() in loggerutil
Updated comments, cleaned up typos.

diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index f63b95f0f59a90ff0f68b78aaf2083bcd349b259..e0929b77575fc7e8eb66e016d4d68ecef08aa131 100644 (file)
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -13,7 +13,6 @@ import (
        "git.curoverse.com/arvados.git/services/datamanager/loggerutil"
        "log"
        "os"
-       "runtime"
        "runtime/pprof"
        "time"
 )
@@ -123,7 +122,6 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
        fieldsWanted := []string{"manifest_text",
                "owner_uuid",
                "uuid",
-               // TODO(misha): Start using the redundancy field.
                "redundancy",
                "modified_at"}
 
@@ -203,9 +201,6 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
                }
        }
 
-       // Just in case this lowers the numbers reported in the heap profile.
-       runtime.GC()
-
        // Write the heap profile for examining memory usage
        WriteHeapProfile()
 
@@ -232,7 +227,7 @@ func ProcessCollections(arvLogger *logger.Logger,
                        loggerutil.FatalWithMessage(arvLogger,
                                fmt.Sprintf(
                                        "Arvados SDK collection returned with unexpected zero "+
-                                               "modifcation date. This probably means that either we failed to "+
+                                               "modification date. This probably means that either we failed to "+
                                                "parse the modification date or the API server has changed how "+
                                                "it returns modification dates: %+v",
                                        collection))

diff --git a/services/datamanager/loggerutil/loggerutil.go b/services/datamanager/loggerutil/loggerutil.go
index 58abb119ac128a7ba94920ad6e3a29101df8e8cc..8c655cd5ff68a981146493bfa21fd71693ba12c0 100644 (file)
--- a/services/datamanager/loggerutil/loggerutil.go
+++ b/services/datamanager/loggerutil/loggerutil.go
@@ -16,7 +16,7 @@ func LogRunInfo(arvLogger *logger.Logger) {
        if arvLogger != nil {
                now := time.Now()
                arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
-                       runInfo := make(map[string]interface{})
+                       runInfo := logger.GetOrCreateMap(p, "run_info")
                        runInfo["started_at"] = now
                        runInfo["args"] = os.Args
                        hostname, err := os.Hostname()
@@ -26,26 +26,25 @@ func LogRunInfo(arvLogger *logger.Logger) {
                                runInfo["hostname"] = hostname
                        }
                        runInfo["pid"] = os.Getpid()
-                       p["run_info"] = runInfo
                })
        }
 }
 
 // A LogMutator that records the current memory usage. This is most useful as a logger write hook.
-//
-// Assumes we already have a map named "run_info" in properties. LogRunInfo() can create such a map for you if you call it.
 func LogMemoryAlloc(p map[string]interface{}, e map[string]interface{}) {
-       runInfo := p["run_info"].(map[string]interface{})
+       runInfo := logger.GetOrCreateMap(p, "run_info")
        var memStats runtime.MemStats
        runtime.ReadMemStats(&memStats)
-       runInfo["alloc_bytes_in_use"] = memStats.Alloc
+       runInfo["memory_bytes_in_use"] = memStats.Alloc
+       runInfo["memory_bytes_reserved"] = memStats.Sys
 }
 
 func FatalWithMessage(arvLogger *logger.Logger, message string) {
        if arvLogger != nil {
                arvLogger.FinalUpdate(func(p map[string]interface{}, e map[string]interface{}) {
                        p["FATAL"] = message
-                       p["run_info"].(map[string]interface{})["finished_at"] = time.Now()
+                       runInfo := logger.GetOrCreateMap(p, "run_info")
+                       runInfo["finished_at"] = time.Now()
                })
        }