18691: Fix wrong column name in clear_permissions.
[arvados.git] / lib / costanalyzer / costanalyzer.go
index b828c5ce0a1b1ce40d10ffc0e418b20a4564ba1e..a3673c9794d42d9db2da9b3cded67faaf3be67c4 100644 (file)
@@ -9,10 +9,6 @@ import (
        "errors"
        "flag"
        "fmt"
        "errors"
        "flag"
        "fmt"
-       "git.arvados.org/arvados.git/lib/config"
-       "git.arvados.org/arvados.git/sdk/go/arvados"
-       "git.arvados.org/arvados.git/sdk/go/arvadosclient"
-       "git.arvados.org/arvados.git/sdk/go/keepclient"
        "io"
        "io/ioutil"
        "net/http"
        "io"
        "io/ioutil"
        "net/http"
@@ -21,9 +17,15 @@ import (
        "strings"
        "time"
 
        "strings"
        "time"
 
+       "git.arvados.org/arvados.git/lib/cmd"
+       "git.arvados.org/arvados.git/sdk/go/arvados"
+       "git.arvados.org/arvados.git/sdk/go/arvadosclient"
+       "git.arvados.org/arvados.git/sdk/go/keepclient"
        "github.com/sirupsen/logrus"
 )
 
        "github.com/sirupsen/logrus"
 )
 
+const timestampFormat = "2006-01-02T15:04:05"
+
 type nodeInfo struct {
        // Legacy (records created by Arvados Node Manager with Arvados <= 1.4.3)
        Properties struct {
 type nodeInfo struct {
        // Legacy (records created by Arvados Node Manager with Arvados <= 1.4.3)
        Properties struct {
@@ -38,6 +40,16 @@ type nodeInfo struct {
        Preemptible  bool
 }
 
        Preemptible  bool
 }
 
+type consumption struct {
+       cost     float64
+       duration float64
+}
+
+func (c *consumption) Add(n consumption) {
+       c.cost += n.cost
+       c.duration += n.duration
+}
+
 type arrayFlags []string
 
 func (i *arrayFlags) String() string {
 type arrayFlags []string
 
 func (i *arrayFlags) String() string {
@@ -51,17 +63,16 @@ func (i *arrayFlags) Set(value string) error {
        return nil
 }
 
        return nil
 }
 
-func parseFlags(prog string, args []string, loader *config.Loader, logger *logrus.Logger, stderr io.Writer) (exitCode int, uuids arrayFlags, resultsDir string, cache bool, begin time.Time, end time.Time, err error) {
+func (c *command) parseFlags(prog string, args []string, logger *logrus.Logger, stderr io.Writer) (ok bool, exitCode int) {
        var beginStr, endStr string
        flags := flag.NewFlagSet("", flag.ContinueOnError)
        var beginStr, endStr string
        flags := flag.NewFlagSet("", flag.ContinueOnError)
-       flags.SetOutput(stderr)
        flags.Usage = func() {
                fmt.Fprintf(flags.Output(), `
 Usage:
        flags.Usage = func() {
                fmt.Fprintf(flags.Output(), `
 Usage:
-  %s [options ...] [uuid ...]
+  %s [options ...] [UUID ...]
 
        This program analyzes the cost of Arvados container requests and calculates
 
        This program analyzes the cost of Arvados container requests and calculates
-       the total cost across all requests. At least one uuid or a timestamp range
+       the total cost across all requests. At least one UUID or a timestamp range
        must be specified.
 
        When the '-output' option is specified, a set of CSV files with cost details
        must be specified.
 
        When the '-output' option is specified, a set of CSV files with cost details
@@ -69,22 +80,20 @@ Usage:
        all the containers used to fulfill the container request, together with the
        machine type and cost of each container.
 
        all the containers used to fulfill the container request, together with the
        machine type and cost of each container.
 
-       When supplied with the uuid of a container request, it will calculate the
+       When supplied with the UUID of a container request, it will calculate the
        cost of that container request and all its children.
 
        cost of that container request and all its children.
 
-       When supplied with the uuid of a collection, it will see if there is a
-       container_request uuid in the properties of the collection, and if so, it
+       When supplied with the UUID of a collection, it will see if there is a
+       container_request UUID in the properties of the collection, and if so, it
        will calculate the cost of that container request and all its children.
 
        will calculate the cost of that container request and all its children.
 
-       When supplied with a project uuid or when supplied with multiple container
-       request or collection uuids, it will calculate the total cost for all
-       supplied uuid.
+       When supplied with a project UUID or when supplied with multiple container
+       request or collection UUIDs, it will calculate the total cost for all
+       supplied UUIDs.
 
        When supplied with a 'begin' and 'end' timestamp (format:
 
        When supplied with a 'begin' and 'end' timestamp (format:
-       2006-01-02T15:04:05), it will calculate the cost for the UUIDs of all the
-       container requests with an associated container whose "Finished at" timestamp
-       is greater than or equal to the "begin" timestamp and smaller than the "end"
-       timestamp.
+       %s), it will calculate the cost for all top-level container
+       requests whose containers finished during the specified interval.
 
        The total cost calculation takes container reuse into account: if a container
        was reused between several container requests, its cost will only be counted
 
        The total cost calculation takes container reuse into account: if a container
        was reused between several container requests, its cost will only be counted
@@ -109,70 +118,58 @@ Usage:
        permanent cloud nodes that provide the Arvados services, the cost of data
        stored in Arvados, etc.
 
        permanent cloud nodes that provide the Arvados services, the cost of data
        stored in Arvados, etc.
 
-       - When provided with a project uuid, subprojects will not be considered.
+       - When provided with a project UUID, subprojects will not be considered.
 
 
-       In order to get the data for the uuids supplied, the ARVADOS_API_HOST and
+       In order to get the data for the UUIDs supplied, the ARVADOS_API_HOST and
        ARVADOS_API_TOKEN environment variables must be set.
 
        This program prints the total dollar amount from the aggregate cost
        ARVADOS_API_TOKEN environment variables must be set.
 
        This program prints the total dollar amount from the aggregate cost
-       accounting across all provided uuids on stdout.
+       accounting across all provided UUIDs on stdout.
 
 Options:
 
 Options:
-`, prog)
+`, prog, timestampFormat)
                flags.PrintDefaults()
        }
        loglevel := flags.String("log-level", "info", "logging `level` (debug, info, ...)")
                flags.PrintDefaults()
        }
        loglevel := flags.String("log-level", "info", "logging `level` (debug, info, ...)")
-       flags.StringVar(&resultsDir, "output", "", "output `directory` for the CSV reports")
-       flags.StringVar(&beginStr, "begin", "", "timestamp `begin` for date range operation (format: 2006-01-02T15:04:05)")
-       flags.StringVar(&endStr, "end", "", "timestamp `end` for date range operation (format: 2006-01-02T15:04:05)")
-       flags.BoolVar(&cache, "cache", true, "create and use a local disk cache of Arvados objects")
-       err = flags.Parse(args)
-       if err == flag.ErrHelp {
-               err = nil
-               exitCode = 1
-               return
-       } else if err != nil {
-               exitCode = 2
-               return
+       flags.StringVar(&c.resultsDir, "output", "", "output `directory` for the CSV reports")
+       flags.StringVar(&beginStr, "begin", "", fmt.Sprintf("timestamp `begin` for date range operation (format: %s)", timestampFormat))
+       flags.StringVar(&endStr, "end", "", fmt.Sprintf("timestamp `end` for date range operation (format: %s)", timestampFormat))
+       flags.BoolVar(&c.cache, "cache", true, "create and use a local disk cache of Arvados objects")
+       if ok, code := cmd.ParseFlags(flags, prog, args, "[uuid ...]", stderr); !ok {
+               return false, code
        }
        }
-       uuids = flags.Args()
+       c.uuids = flags.Args()
 
        if (len(beginStr) != 0 && len(endStr) == 0) || (len(beginStr) == 0 && len(endStr) != 0) {
 
        if (len(beginStr) != 0 && len(endStr) == 0) || (len(beginStr) == 0 && len(endStr) != 0) {
-               flags.Usage()
-               err = fmt.Errorf("When specifying a date range, both begin and end must be specified")
-               exitCode = 2
-               return
+               fmt.Fprintf(stderr, "When specifying a date range, both begin and end must be specified (try -help)\n")
+               return false, 2
        }
 
        if len(beginStr) != 0 {
                var errB, errE error
        }
 
        if len(beginStr) != 0 {
                var errB, errE error
-               begin, errB = time.Parse("2006-01-02T15:04:05", beginStr)
-               end, errE = time.Parse("2006-01-02T15:04:05", endStr)
+               c.begin, errB = time.Parse(timestampFormat, beginStr)
+               c.end, errE = time.Parse(timestampFormat, endStr)
                if (errB != nil) || (errE != nil) {
                if (errB != nil) || (errE != nil) {
-                       flags.Usage()
-                       err = fmt.Errorf("When specifying a date range, both begin and end must be of the format 2006-01-02T15:04:05 %+v, %+v", errB, errE)
-                       exitCode = 2
-                       return
+                       fmt.Fprintf(stderr, "When specifying a date range, both begin and end must be of the format %s %+v, %+v\n", timestampFormat, errB, errE)
+                       return false, 2
                }
        }
 
                }
        }
 
-       if (len(uuids) < 1) && (len(beginStr) == 0) {
-               flags.Usage()
-               err = fmt.Errorf("error: no uuid(s) provided")
-               exitCode = 2
-               return
+       if (len(c.uuids) < 1) && (len(beginStr) == 0) {
+               fmt.Fprintf(stderr, "error: no uuid(s) provided (try -help)\n")
+               return false, 2
        }
 
        lvl, err := logrus.ParseLevel(*loglevel)
        if err != nil {
        }
 
        lvl, err := logrus.ParseLevel(*loglevel)
        if err != nil {
-               exitCode = 2
-               return
+               fmt.Fprintf(stderr, "invalid argument to -log-level: %s\n", err)
+               return false, 2
        }
        logger.SetLevel(lvl)
        }
        logger.SetLevel(lvl)
-       if !cache {
-               logger.Debug("Caching disabled\n")
+       if !c.cache {
+               logger.Debug("Caching disabled")
        }
        }
-       return
+       return true, 0
 }
 
 func ensureDirectory(logger *logrus.Logger, dir string) (err error) {
 }
 
 func ensureDirectory(logger *logrus.Logger, dir string) (err error) {
@@ -190,7 +187,9 @@ func ensureDirectory(logger *logrus.Logger, dir string) (err error) {
        return
 }
 
        return
 }
 
-func addContainerLine(logger *logrus.Logger, node nodeInfo, cr arvados.ContainerRequest, container arvados.Container) (csv string, cost float64) {
+func addContainerLine(logger *logrus.Logger, node nodeInfo, cr arvados.ContainerRequest, container arvados.Container) (string, consumption) {
+       var csv string
+       var containerConsumption consumption
        csv = cr.UUID + ","
        csv += cr.Name + ","
        csv += container.UUID + ","
        csv = cr.UUID + ","
        csv += cr.Name + ","
        csv += container.UUID + ","
@@ -205,7 +204,7 @@ func addContainerLine(logger *logrus.Logger, node nodeInfo, cr arvados.Container
        if container.FinishedAt != nil {
                csv += container.FinishedAt.String() + ","
                delta = container.FinishedAt.Sub(*container.StartedAt)
        if container.FinishedAt != nil {
                csv += container.FinishedAt.String() + ","
                delta = container.FinishedAt.Sub(*container.StartedAt)
-               csv += strconv.FormatFloat(delta.Seconds(), 'f', 0, 64) + ","
+               csv += strconv.FormatFloat(delta.Seconds(), 'f', 3, 64) + ","
        } else {
                csv += ",,"
        }
        } else {
                csv += ",,"
        }
@@ -218,9 +217,10 @@ func addContainerLine(logger *logrus.Logger, node nodeInfo, cr arvados.Container
                price = node.Price
                size = node.ProviderType
        }
                price = node.Price
                size = node.ProviderType
        }
-       cost = delta.Seconds() / 3600 * price
-       csv += size + "," + fmt.Sprintf("%+v", node.Preemptible) + "," + strconv.FormatFloat(price, 'f', 8, 64) + "," + strconv.FormatFloat(cost, 'f', 8, 64) + "\n"
-       return
+       containerConsumption.cost = delta.Seconds() / 3600 * price
+       containerConsumption.duration = delta.Seconds()
+       csv += size + "," + fmt.Sprintf("%+v", node.Preemptible) + "," + strconv.FormatFloat(price, 'f', 8, 64) + "," + strconv.FormatFloat(containerConsumption.cost, 'f', 8, 64) + "\n"
+       return csv, containerConsumption
 }
 
 func loadCachedObject(logger *logrus.Logger, file string, uuid string, object interface{}) (reload bool) {
 }
 
 func loadCachedObject(logger *logrus.Logger, file string, uuid string, object interface{}) (reload bool) {
@@ -250,12 +250,12 @@ func loadCachedObject(logger *logrus.Logger, file string, uuid string, object in
        case *arvados.ContainerRequest:
                if v.State == arvados.ContainerRequestStateFinal {
                        reload = false
        case *arvados.ContainerRequest:
                if v.State == arvados.ContainerRequestStateFinal {
                        reload = false
-                       logger.Debugf("Loaded object %s from local cache (%s)\n", uuid, file)
+                       logger.Debugf("Loaded object %s from local cache (%s)", uuid, file)
                }
        case *arvados.Container:
                if v.State == arvados.ContainerStateComplete || v.State == arvados.ContainerStateCancelled {
                        reload = false
                }
        case *arvados.Container:
                if v.State == arvados.ContainerStateComplete || v.State == arvados.ContainerStateCancelled {
                        reload = false
-                       logger.Debugf("Loaded object %s from local cache (%s)\n", uuid, file)
+                       logger.Debugf("Loaded object %s from local cache (%s)", uuid, file)
                }
        }
        return
                }
        }
        return
@@ -355,8 +355,8 @@ func getNode(arv *arvadosclient.ArvadosClient, ac *arvados.Client, kc *keepclien
        return
 }
 
        return
 }
 
-func handleProject(logger *logrus.Logger, uuid string, arv *arvadosclient.ArvadosClient, ac *arvados.Client, kc *keepclient.KeepClient, resultsDir string, cache bool) (cost map[string]float64, err error) {
-       cost = make(map[string]float64)
+func handleProject(logger *logrus.Logger, uuid string, arv *arvadosclient.ArvadosClient, ac *arvados.Client, kc *keepclient.KeepClient, resultsDir string, cache bool) (cost map[string]consumption, err error) {
+       cost = make(map[string]consumption)
 
        var project arvados.Group
        err = loadObject(logger, ac, uuid, uuid, cache, &project)
 
        var project arvados.Group
        err = loadObject(logger, ac, uuid, uuid, cache, &project)
@@ -385,33 +385,32 @@ func handleProject(logger *logrus.Logger, uuid string, arv *arvadosclient.Arvado
                return nil, fmt.Errorf("error querying container_requests: %s", err.Error())
        }
        if value, ok := childCrs["items"]; ok {
                return nil, fmt.Errorf("error querying container_requests: %s", err.Error())
        }
        if value, ok := childCrs["items"]; ok {
-               logger.Infof("Collecting top level container requests in project %s\n", uuid)
+               logger.Infof("Collecting top level container requests in project %s", uuid)
                items := value.([]interface{})
                for _, item := range items {
                        itemMap := item.(map[string]interface{})
                items := value.([]interface{})
                for _, item := range items {
                        itemMap := item.(map[string]interface{})
-                       crCsv, err := generateCrCsv(logger, itemMap["uuid"].(string), arv, ac, kc, resultsDir, cache)
+                       crInfo, err := generateCrInfo(logger, itemMap["uuid"].(string), arv, ac, kc, resultsDir, cache)
                        if err != nil {
                                return nil, fmt.Errorf("error generating container_request CSV: %s", err.Error())
                        }
                        if err != nil {
                                return nil, fmt.Errorf("error generating container_request CSV: %s", err.Error())
                        }
-                       for k, v := range crCsv {
+                       for k, v := range crInfo {
                                cost[k] = v
                        }
                }
        } else {
                                cost[k] = v
                        }
                }
        } else {
-               logger.Infof("No top level container requests found in project %s\n", uuid)
+               logger.Infof("No top level container requests found in project %s", uuid)
        }
        return
 }
 
        }
        return
 }
 
-func generateCrCsv(logger *logrus.Logger, uuid string, arv *arvadosclient.ArvadosClient, ac *arvados.Client, kc *keepclient.KeepClient, resultsDir string, cache bool) (cost map[string]float64, err error) {
+func generateCrInfo(logger *logrus.Logger, uuid string, arv *arvadosclient.ArvadosClient, ac *arvados.Client, kc *keepclient.KeepClient, resultsDir string, cache bool) (cost map[string]consumption, err error) {
 
 
-       cost = make(map[string]float64)
+       cost = make(map[string]consumption)
 
        csv := "CR UUID,CR name,Container UUID,State,Started At,Finished At,Duration in seconds,Compute node type,Preemptible,Hourly node cost,Total cost\n"
        var tmpCsv string
 
        csv := "CR UUID,CR name,Container UUID,State,Started At,Finished At,Duration in seconds,Compute node type,Preemptible,Hourly node cost,Total cost\n"
        var tmpCsv string
-       var tmpTotalCost float64
-       var totalCost float64
-       fmt.Printf("Processing %s\n", uuid)
+       var total, tmpTotal consumption
+       logger.Debugf("Processing %s", uuid)
 
        var crUUID = uuid
        if strings.Contains(uuid, "-4zz18-") {
 
        var crUUID = uuid
        if strings.Contains(uuid, "-4zz18-") {
@@ -439,7 +438,7 @@ func generateCrCsv(logger *logrus.Logger, uuid string, arv *arvadosclient.Arvado
        }
        if len(cr.ContainerUUID) == 0 {
                // Nothing to do! E.g. a CR in 'Uncommitted' state.
        }
        if len(cr.ContainerUUID) == 0 {
                // Nothing to do! E.g. a CR in 'Uncommitted' state.
-               logger.Infof("No container associated with container request %s, skipping\n", crUUID)
+               logger.Infof("No container associated with container request %s, skipping", crUUID)
                return nil, nil
        }
        var container arvados.Container
                return nil, nil
        }
        var container arvados.Container
@@ -453,10 +452,9 @@ func generateCrCsv(logger *logrus.Logger, uuid string, arv *arvadosclient.Arvado
                logger.Errorf("Skipping container request %s: error getting node %s: %s", cr.UUID, cr.UUID, err)
                return nil, nil
        }
                logger.Errorf("Skipping container request %s: error getting node %s: %s", cr.UUID, cr.UUID, err)
                return nil, nil
        }
-       tmpCsv, totalCost = addContainerLine(logger, topNode, cr, container)
+       tmpCsv, total = addContainerLine(logger, topNode, cr, container)
        csv += tmpCsv
        csv += tmpCsv
-       totalCost += tmpTotalCost
-       cost[container.UUID] = totalCost
+       cost[container.UUID] = total
 
        // Find all container requests that have the container we found above as requesting_container_uuid
        var childCrs arvados.ContainerRequestList
 
        // Find all container requests that have the container we found above as requesting_container_uuid
        var childCrs arvados.ContainerRequestList
@@ -473,28 +471,34 @@ func generateCrCsv(logger *logrus.Logger, uuid string, arv *arvadosclient.Arvado
        if err != nil {
                return nil, fmt.Errorf("error querying container_requests: %s", err.Error())
        }
        if err != nil {
                return nil, fmt.Errorf("error querying container_requests: %s", err.Error())
        }
-       logger.Infof("Collecting child containers for container request %s", crUUID)
-       for _, cr2 := range childCrs.Items {
-               logger.Info(".")
+       logger.Infof("Collecting child containers for container request %s (%s)", crUUID, container.FinishedAt)
+       progressTicker := time.NewTicker(5 * time.Second)
+       defer progressTicker.Stop()
+       for i, cr2 := range childCrs.Items {
+               select {
+               case <-progressTicker.C:
+                       logger.Infof("... %d of %d", i+1, len(childCrs.Items))
+               default:
+               }
                node, err := getNode(arv, ac, kc, cr2)
                if err != nil {
                        logger.Errorf("Skipping container request %s: error getting node %s: %s", cr2.UUID, cr2.UUID, err)
                        continue
                }
                node, err := getNode(arv, ac, kc, cr2)
                if err != nil {
                        logger.Errorf("Skipping container request %s: error getting node %s: %s", cr2.UUID, cr2.UUID, err)
                        continue
                }
-               logger.Debug("\nChild container: " + cr2.ContainerUUID + "\n")
+               logger.Debug("Child container: " + cr2.ContainerUUID)
                var c2 arvados.Container
                err = loadObject(logger, ac, cr.UUID, cr2.ContainerUUID, cache, &c2)
                if err != nil {
                        return nil, fmt.Errorf("error loading object %s: %s", cr2.ContainerUUID, err)
                }
                var c2 arvados.Container
                err = loadObject(logger, ac, cr.UUID, cr2.ContainerUUID, cache, &c2)
                if err != nil {
                        return nil, fmt.Errorf("error loading object %s: %s", cr2.ContainerUUID, err)
                }
-               tmpCsv, tmpTotalCost = addContainerLine(logger, node, cr2, c2)
-               cost[cr2.ContainerUUID] = tmpTotalCost
+               tmpCsv, tmpTotal = addContainerLine(logger, node, cr2, c2)
+               cost[cr2.ContainerUUID] = tmpTotal
                csv += tmpCsv
                csv += tmpCsv
-               totalCost += tmpTotalCost
+               total.Add(tmpTotal)
        }
        }
-       logger.Info(" done\n")
+       logger.Debug("Done collecting child containers")
 
 
-       csv += "TOTAL,,,,,,,,," + strconv.FormatFloat(totalCost, 'f', 8, 64) + "\n"
+       csv += "TOTAL,,,,,," + strconv.FormatFloat(total.duration, 'f', 3, 64) + ",,,," + strconv.FormatFloat(total.cost, 'f', 2, 64) + "\n"
 
        if resultsDir != "" {
                // Write the resulting CSV file
 
        if resultsDir != "" {
                // Write the resulting CSV file
@@ -503,19 +507,20 @@ func generateCrCsv(logger *logrus.Logger, uuid string, arv *arvadosclient.Arvado
                if err != nil {
                        return nil, fmt.Errorf("error writing file with path %s: %s", fName, err.Error())
                }
                if err != nil {
                        return nil, fmt.Errorf("error writing file with path %s: %s", fName, err.Error())
                }
-               logger.Infof("\nUUID report in %s\n\n", fName)
+               logger.Infof("\nUUID report in %s", fName)
        }
 
        return
 }
 
        }
 
        return
 }
 
-func costanalyzer(prog string, args []string, loader *config.Loader, logger *logrus.Logger, stdout, stderr io.Writer) (exitcode int, err error) {
-       exitcode, uuids, resultsDir, cache, begin, end, err := parseFlags(prog, args, loader, logger, stderr)
-       if exitcode != 0 {
+func (c *command) costAnalyzer(prog string, args []string, logger *logrus.Logger, stdout, stderr io.Writer) (exitcode int, err error) {
+       var ok bool
+       ok, exitcode = c.parseFlags(prog, args, logger, stderr)
+       if !ok {
                return
        }
                return
        }
-       if resultsDir != "" {
-               err = ensureDirectory(logger, resultsDir)
+       if c.resultsDir != "" {
+               err = ensureDirectory(logger, c.resultsDir)
                if err != nil {
                        exitcode = 3
                        return
                if err != nil {
                        exitcode = 3
                        return
@@ -542,13 +547,15 @@ func costanalyzer(prog string, args []string, loader *config.Loader, logger *log
 
        // Populate uuidChannel with the requested uuid list
        go func() {
 
        // Populate uuidChannel with the requested uuid list
        go func() {
-               for _, uuid := range uuids {
+               defer close(uuidChannel)
+               for _, uuid := range c.uuids {
                        uuidChannel <- uuid
                }
 
                        uuidChannel <- uuid
                }
 
-               if !begin.IsZero() {
+               if !c.begin.IsZero() {
                        initialParams := arvados.ResourceListParams{
                        initialParams := arvados.ResourceListParams{
-                               Filters: []arvados.Filter{{"container.finished_at", ">=", begin}, {"container.finished_at", "<", end}, {"requesting_container_uuid", "=", nil}},
+                               Filters: []arvados.Filter{{"container.finished_at", ">=", c.begin}, {"container.finished_at", "<", c.end}, {"requesting_container_uuid", "=", nil}},
+                               Order:   "created_at",
                        }
                        params := initialParams
                        for {
                        }
                        params := initialParams
                        for {
@@ -560,7 +567,7 @@ func costanalyzer(prog string, args []string, loader *config.Loader, logger *log
 
                                err := ac.RequestAndDecode(&list, "GET", "arvados/v1/container_requests", nil, params)
                                if err != nil {
 
                                err := ac.RequestAndDecode(&list, "GET", "arvados/v1/container_requests", nil, params)
                                if err != nil {
-                                       logger.Errorf("Error getting container request list from Arvados API: %s\n", err)
+                                       logger.Errorf("Error getting container request list from Arvados API: %s", err)
                                        break
                                }
                                if len(list.Items) == 0 {
                                        break
                                }
                                if len(list.Items) == 0 {
@@ -574,16 +581,15 @@ func costanalyzer(prog string, args []string, loader *config.Loader, logger *log
                        }
 
                }
                        }
 
                }
-               close(uuidChannel)
        }()
 
        }()
 
-       cost := make(map[string]float64)
+       cost := make(map[string]consumption)
 
        for uuid := range uuidChannel {
 
        for uuid := range uuidChannel {
-               fmt.Printf("Considering %s\n", uuid)
+               logger.Debugf("Considering %s", uuid)
                if strings.Contains(uuid, "-j7d0g-") {
                        // This is a project (group)
                if strings.Contains(uuid, "-j7d0g-") {
                        // This is a project (group)
-                       cost, err = handleProject(logger, uuid, arv, ac, kc, resultsDir, cache)
+                       cost, err = handleProject(logger, uuid, arv, ac, kc, c.resultsDir, c.cache)
                        if err != nil {
                                exitcode = 1
                                return
                        if err != nil {
                                exitcode = 1
                                return
@@ -592,15 +598,15 @@ func costanalyzer(prog string, args []string, loader *config.Loader, logger *log
                                cost[k] = v
                        }
                } else if strings.Contains(uuid, "-xvhdp-") || strings.Contains(uuid, "-4zz18-") {
                                cost[k] = v
                        }
                } else if strings.Contains(uuid, "-xvhdp-") || strings.Contains(uuid, "-4zz18-") {
-                       // This is a container request
-                       var crCsv map[string]float64
-                       crCsv, err = generateCrCsv(logger, uuid, arv, ac, kc, resultsDir, cache)
+                       // This is a container request or collection
+                       var crInfo map[string]consumption
+                       crInfo, err = generateCrInfo(logger, uuid, arv, ac, kc, c.resultsDir, c.cache)
                        if err != nil {
                                err = fmt.Errorf("error generating CSV for uuid %s: %s", uuid, err.Error())
                                exitcode = 2
                                return
                        }
                        if err != nil {
                                err = fmt.Errorf("error generating CSV for uuid %s: %s", uuid, err.Error())
                                exitcode = 2
                                return
                        }
-                       for k, v := range crCsv {
+                       for k, v := range crInfo {
                                cost[k] = v
                        }
                } else if strings.Contains(uuid, "-tpzed-") {
                                cost[k] = v
                        }
                } else if strings.Contains(uuid, "-tpzed-") {
@@ -610,46 +616,46 @@ func costanalyzer(prog string, args []string, loader *config.Loader, logger *log
                        // keep going.
                        logger.Errorf("cost analysis is not supported for the 'Home' project: %s", uuid)
                } else {
                        // keep going.
                        logger.Errorf("cost analysis is not supported for the 'Home' project: %s", uuid)
                } else {
-                       logger.Errorf("this argument does not look like a uuid: %s\n", uuid)
+                       logger.Errorf("this argument does not look like a uuid: %s", uuid)
                        exitcode = 3
                        return
                }
        }
 
        if len(cost) == 0 {
                        exitcode = 3
                        return
                }
        }
 
        if len(cost) == 0 {
-               logger.Info("Nothing to do!\n")
+               logger.Info("Nothing to do!")
                return
        }
 
        var csv string
 
                return
        }
 
        var csv string
 
-       csv = "# Aggregate cost accounting for uuids:\n"
-       for _, uuid := range uuids {
+       csv = "# Aggregate cost accounting for uuids:\n# UUID, Duration in seconds, Total cost\n"
+       for _, uuid := range c.uuids {
                csv += "# " + uuid + "\n"
        }
 
                csv += "# " + uuid + "\n"
        }
 
-       var total float64
+       var total consumption
        for k, v := range cost {
        for k, v := range cost {
-               csv += k + "," + strconv.FormatFloat(v, 'f', 8, 64) + "\n"
-               total += v
+               csv += k + "," + strconv.FormatFloat(v.duration, 'f', 3, 64) + "," + strconv.FormatFloat(v.cost, 'f', 8, 64) + "\n"
+               total.Add(v)
        }
 
        }
 
-       csv += "TOTAL," + strconv.FormatFloat(total, 'f', 8, 64) + "\n"
+       csv += "TOTAL," + strconv.FormatFloat(total.duration, 'f', 3, 64) + "," + strconv.FormatFloat(total.cost, 'f', 2, 64) + "\n"
 
 
-       if resultsDir != "" {
+       if c.resultsDir != "" {
                // Write the resulting CSV file
                // Write the resulting CSV file
-               aFile := resultsDir + "/" + time.Now().Format("2006-01-02-15-04-05") + "-aggregate-costaccounting.csv"
+               aFile := c.resultsDir + "/" + time.Now().Format("2006-01-02-15-04-05") + "-aggregate-costaccounting.csv"
                err = ioutil.WriteFile(aFile, []byte(csv), 0644)
                if err != nil {
                        err = fmt.Errorf("error writing file with path %s: %s", aFile, err.Error())
                        exitcode = 1
                        return
                }
                err = ioutil.WriteFile(aFile, []byte(csv), 0644)
                if err != nil {
                        err = fmt.Errorf("error writing file with path %s: %s", aFile, err.Error())
                        exitcode = 1
                        return
                }
-               logger.Infof("Aggregate cost accounting for all supplied uuids in %s\n", aFile)
+               logger.Infof("Aggregate cost accounting for all supplied uuids in %s", aFile)
        }
 
        // Output the total dollar amount on stdout
        }
 
        // Output the total dollar amount on stdout
-       fmt.Fprintf(stdout, "%s\n", strconv.FormatFloat(total, 'f', 8, 64))
+       fmt.Fprintf(stdout, "%s\n", strconv.FormatFloat(total.cost, 'f', 2, 64))
 
        return
 }
 
        return
 }