Merge branch '21678-installer-diagnostics-internal'. Closes #21678
[arvados.git] / lib / costanalyzer / costanalyzer.go
index dfe3d584cec7a7f07d16ec2e3c267e760201d8dc..e68e2cb8c11115330001e67bca71d4310f07b1a7 100644 (file)
@@ -17,6 +17,7 @@ import (
        "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"
@@ -25,6 +26,8 @@ import (
 
 const timestampFormat = "2006-01-02T15:04:05"
 
+var pagesize = 1000
+
 type nodeInfo struct {
        // Legacy (records created by Arvados Node Manager with Arvados <= 1.4.3)
        Properties struct {
@@ -39,6 +42,16 @@ type nodeInfo struct {
        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 {
@@ -52,10 +65,9 @@ func (i *arrayFlags) Set(value string) error {
        return nil
 }
 
-func (c *command) parseFlags(prog string, args []string, logger *logrus.Logger, stderr io.Writer) (exitCode int, 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)
-       flags.SetOutput(stderr)
        flags.Usage = func() {
                fmt.Fprintf(flags.Output(), `
 Usage:
@@ -125,22 +137,14 @@ Options:
        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")
-       err = flags.Parse(args)
-       if err == flag.ErrHelp {
-               err = nil
-               exitCode = 1
-               return
-       } else if err != nil {
-               exitCode = 2
-               return
+       if ok, code := cmd.ParseFlags(flags, prog, args, "[uuid ...]", stderr); !ok {
+               return false, code
        }
        c.uuids = flags.Args()
 
        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 {
@@ -148,30 +152,26 @@ Options:
                c.begin, errB = time.Parse(timestampFormat, beginStr)
                c.end, errE = time.Parse(timestampFormat, endStr)
                if (errB != nil) || (errE != nil) {
-                       flags.Usage()
-                       err = fmt.Errorf("When specifying a date range, both begin and end must be of the format %s %+v, %+v", timestampFormat, 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(c.uuids) < 1) && (len(beginStr) == 0) {
-               flags.Usage()
-               err = fmt.Errorf("error: no uuid(s) provided")
-               exitCode = 2
-               return
+               fmt.Fprintf(stderr, "error: no uuid(s) provided (try -help)\n")
+               return false, 2
        }
 
        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)
        if !c.cache {
                logger.Debug("Caching disabled")
        }
-       return
+       return true, 0
 }
 
 func ensureDirectory(logger *logrus.Logger, dir string) (err error) {
@@ -189,7 +189,9 @@ func ensureDirectory(logger *logrus.Logger, dir string) (err error) {
        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 + ","
@@ -204,7 +206,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)
-               csv += strconv.FormatFloat(delta.Seconds(), 'f', 0, 64) + ","
+               csv += strconv.FormatFloat(delta.Seconds(), 'f', 3, 64) + ","
        } else {
                csv += ",,"
        }
@@ -217,9 +219,10 @@ func addContainerLine(logger *logrus.Logger, node nodeInfo, cr arvados.Container
                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) {
@@ -354,17 +357,44 @@ func getNode(arv *arvadosclient.ArvadosClient, ac *arvados.Client, kc *keepclien
        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 getContainerRequests(ac *arvados.Client, filters []arvados.Filter) ([]arvados.ContainerRequest, error) {
+       var allItems []arvados.ContainerRequest
+       for {
+               pagefilters := append([]arvados.Filter(nil), filters...)
+               if len(allItems) > 0 {
+                       pagefilters = append(pagefilters, arvados.Filter{
+                               Attr:     "uuid",
+                               Operator: ">",
+                               Operand:  allItems[len(allItems)-1].UUID,
+                       })
+               }
+               var resp arvados.ContainerRequestList
+               err := ac.RequestAndDecode(&resp, "GET", "arvados/v1/container_requests", nil, arvados.ResourceListParams{
+                       Filters: pagefilters,
+                       Limit:   &pagesize,
+                       Order:   "uuid",
+                       Count:   "none",
+               })
+               if err != nil {
+                       return nil, fmt.Errorf("error querying container_requests: %w", err)
+               }
+               if len(resp.Items) == 0 {
+                       // no more pages
+                       return allItems, nil
+               }
+               allItems = append(allItems, resp.Items...)
+       }
+}
+
+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)
        if err != nil {
                return nil, fmt.Errorf("error loading object %s: %s", uuid, err.Error())
        }
-
-       var childCrs map[string]interface{}
-       filterset := []arvados.Filter{
+       allItems, err := getContainerRequests(ac, []arvados.Filter{
                {
                        Attr:     "owner_uuid",
                        Operator: "=",
@@ -375,41 +405,34 @@ func handleProject(logger *logrus.Logger, uuid string, arv *arvadosclient.Arvado
                        Operator: "=",
                        Operand:  nil,
                },
-       }
-       err = ac.RequestAndDecode(&childCrs, "GET", "arvados/v1/container_requests", nil, map[string]interface{}{
-               "filters": filterset,
-               "limit":   10000,
        })
        if err != nil {
                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", uuid)
-               items := value.([]interface{})
-               for _, item := range items {
-                       itemMap := item.(map[string]interface{})
-                       crCsv, err := generateCrCsv(logger, itemMap["uuid"].(string), arv, ac, kc, resultsDir, cache)
-                       if err != nil {
-                               return nil, fmt.Errorf("error generating container_request CSV: %s", err.Error())
-                       }
-                       for k, v := range crCsv {
-                               cost[k] = v
-                       }
-               }
-       } else {
+       if len(allItems) == 0 {
                logger.Infof("No top level container requests found in project %s", uuid)
+               return
+       }
+       logger.Infof("Collecting top level container requests in project %s", uuid)
+       for _, cr := range allItems {
+               crInfo, err := generateCrInfo(logger, cr.UUID, arv, ac, kc, resultsDir, cache)
+               if err != nil {
+                       return nil, fmt.Errorf("error generating container_request CSV for %s: %s", cr.UUID, err)
+               }
+               for k, v := range crInfo {
+                       cost[k] = v
+               }
        }
        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
-       var tmpTotalCost float64
-       var totalCost float64
+       var total, tmpTotal consumption
        logger.Debugf("Processing %s", uuid)
 
        var crUUID = uuid
@@ -452,33 +475,24 @@ 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
        }
-       tmpCsv, totalCost = addContainerLine(logger, topNode, cr, container)
+       tmpCsv, total = addContainerLine(logger, topNode, cr, container)
        csv += tmpCsv
-       totalCost += tmpTotalCost
-       cost[container.UUID] = totalCost
-
-       // Find all container requests that have the container we found above as requesting_container_uuid
-       var childCrs arvados.ContainerRequestList
-       filterset := []arvados.Filter{
-               {
-                       Attr:     "requesting_container_uuid",
-                       Operator: "=",
-                       Operand:  container.UUID,
-               }}
-       err = ac.RequestAndDecode(&childCrs, "GET", "arvados/v1/container_requests", nil, map[string]interface{}{
-               "filters": filterset,
-               "limit":   10000,
-       })
-       if err != nil {
-               return nil, fmt.Errorf("error querying container_requests: %s", err.Error())
-       }
-       logger.Infof("Collecting child containers for container request %s (%s)", crUUID, container.FinishedAt)
+       cost[container.UUID] = total
+
+       // Find all container requests that have the container we
+       // found above as requesting_container_uuid.
+       allItems, err := getContainerRequests(ac, []arvados.Filter{{
+               Attr:     "requesting_container_uuid",
+               Operator: "=",
+               Operand:  container.UUID,
+       }})
+       logger.Infof("Looking up %d child containers for container %s (%s)", len(allItems), container.UUID, container.FinishedAt)
        progressTicker := time.NewTicker(5 * time.Second)
        defer progressTicker.Stop()
-       for i, cr2 := range childCrs.Items {
+       for i, cr2 := range allItems {
                select {
                case <-progressTicker.C:
-                       logger.Infof("... %d of %d", i+1, len(childCrs.Items))
+                       logger.Infof("... %d of %d", i+1, len(allItems))
                default:
                }
                node, err := getNode(arv, ac, kc, cr2)
@@ -492,14 +506,14 @@ func generateCrCsv(logger *logrus.Logger, uuid string, arv *arvadosclient.Arvado
                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
-               totalCost += tmpTotalCost
+               total.Add(tmpTotal)
        }
        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
@@ -515,9 +529,9 @@ func generateCrCsv(logger *logrus.Logger, uuid string, arv *arvadosclient.Arvado
 }
 
 func (c *command) costAnalyzer(prog string, args []string, logger *logrus.Logger, stdout, stderr io.Writer) (exitcode int, err error) {
-       exitcode, err = c.parseFlags(prog, args, logger, stderr)
-
-       if exitcode != 0 {
+       var ok bool
+       ok, exitcode = c.parseFlags(prog, args, logger, stderr)
+       if !ok {
                return
        }
        if c.resultsDir != "" {
@@ -584,7 +598,7 @@ func (c *command) costAnalyzer(prog string, args []string, logger *logrus.Logger
                }
        }()
 
-       cost := make(map[string]float64)
+       cost := make(map[string]consumption)
 
        for uuid := range uuidChannel {
                logger.Debugf("Considering %s", uuid)
@@ -599,15 +613,15 @@ func (c *command) costAnalyzer(prog string, args []string, logger *logrus.Logger
                                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, c.resultsDir, c.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
                        }
-                       for k, v := range crCsv {
+                       for k, v := range crInfo {
                                cost[k] = v
                        }
                } else if strings.Contains(uuid, "-tpzed-") {
@@ -630,18 +644,18 @@ func (c *command) costAnalyzer(prog string, args []string, logger *logrus.Logger
 
        var csv string
 
-       csv = "# Aggregate cost accounting for uuids:\n"
+       csv = "# Aggregate cost accounting for uuids:\n# UUID, Duration in seconds, Total cost\n"
        for _, uuid := range c.uuids {
                csv += "# " + uuid + "\n"
        }
 
-       var total float64
+       var total consumption
        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 c.resultsDir != "" {
                // Write the resulting CSV file
@@ -656,7 +670,7 @@ func (c *command) costAnalyzer(prog string, args []string, logger *logrus.Logger
        }
 
        // 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
 }