lib/controller/localdb/log_activity.go

   1 // Copyright (C) The Arvados Authors. All rights reserved.
   2 //
   3 // SPDX-License-Identifier: AGPL-3.0
   4
   5 package localdb
   6
   7 import (
   8         "context"
   9         "time"
  10
  11         "git.arvados.org/arvados.git/lib/ctrlctx"
  12         "git.arvados.org/arvados.git/sdk/go/arvados"
  13         "git.arvados.org/arvados.git/sdk/go/ctxlog"
  14 )
  15
  16 var loggedLogActivityDisabled = false
  17
  18 func (conn *Conn) logActivity(ctx context.Context) {
  19         p := conn.cluster.Users.ActivityLoggingPeriod.Duration()
  20         if p < 1 {
  21                 if !loggedLogActivityDisabled {
  22                         ctxlog.FromContext(ctx).Debug("logActivity disabled by config")
  23                         loggedLogActivityDisabled = true
  24                 }
  25                 return
  26         }
  27         user, _, err := ctrlctx.CurrentAuth(ctx)
  28         if err == ctrlctx.ErrUnauthenticated {
  29                 ctxlog.FromContext(ctx).Debug("logActivity skipped for unauthenticated request")
  30                 return
  31         } else if err != nil {
  32                 ctxlog.FromContext(ctx).WithError(err).Error("logActivity CurrentAuth failed")
  33                 return
  34         }
  35         now := time.Now()
  36         conn.activeUsersLock.Lock()
  37         if conn.activeUsers == nil || conn.activeUsersReset.IsZero() || conn.activeUsersReset.Before(now) {
  38                 conn.activeUsersReset = alignedPeriod(now, p)
  39                 conn.activeUsers = map[string]bool{}
  40         }
  41         logged := conn.activeUsers[user.UUID]
  42         if !logged {
  43                 // Prevent other concurrent calls from logging about
  44                 // this user until we finish.
  45                 conn.activeUsers[user.UUID] = true
  46         }
  47         conn.activeUsersLock.Unlock()
  48         if logged {
  49                 return
  50         }
  51         defer func() {
  52                 // If we return without logging, reset the flag so we
  53                 // try again on the user's next API call.
  54                 if !logged {
  55                         conn.activeUsersLock.Lock()
  56                         conn.activeUsers[user.UUID] = false
  57                         conn.activeUsersLock.Unlock()
  58                 }
  59         }()
  60
  61         tx, err := ctrlctx.NewTx(ctx)
  62         if err != nil {
  63                 ctxlog.FromContext(ctx).WithError(err).Error("logActivity NewTx failed")
  64                 return
  65         }
  66         defer tx.Rollback()
  67         _, err = tx.ExecContext(ctx, `
  68 insert into logs
  69  (uuid,
  70   owner_uuid, modified_by_user_uuid, object_owner_uuid,
  71   event_type,
  72   summary,
  73   object_uuid,
  74   properties,
  75   event_at, created_at, updated_at, modified_at)
  76  values
  77  ($1, $2, $2, $2, $3, $4, $5, $6,
  78   current_timestamp at time zone 'UTC',
  79   current_timestamp at time zone 'UTC',
  80   current_timestamp at time zone 'UTC',
  81   current_timestamp at time zone 'UTC')
  82  returning id`,
  83                 arvados.RandomUUID(conn.cluster.ClusterID, "57u5n"),
  84                 conn.cluster.ClusterID+"-tpzed-000000000000000", // both modified_by and object_owner
  85                 "activity",
  86                 "activity of "+user.UUID,
  87                 user.UUID,
  88                 "{}")
  89         if err != nil {
  90                 ctxlog.FromContext(ctx).WithError(err).Error("logActivity query failed")
  91                 return
  92         }
  93         err = tx.Commit()
  94         if err != nil {
  95                 ctxlog.FromContext(ctx).WithError(err).Error("logActivity commit failed")
  96                 return
  97         }
  98         logged = true
  99 }
 100
 101 // alignedPeriod computes a time interval that includes now and aligns
 102 // to local clock times that are multiples of p. For example, if local
 103 // time is UTC-5 and ActivityLoggingPeriod=4h, periodStart and
 104 // periodEnd will be 0000-0400, 0400-0800, etc., in local time. If p
 105 // is a multiple of 24h, periods will start and end at midnight.
 106 //
 107 // If DST starts or ends during this period, the boundaries will be
 108 // aligned based on either DST or non-DST time depending on whether
 109 // now is before or after the DST transition. The consequences are
 110 // presumed to be inconsequential, e.g., logActivity may unnecessarily
 111 // log activity more than once in a period that includes a DST
 112 // transition.
 113 //
 114 // In all cases, the period ends in the future.
 115 //
 116 // Only the end of the period is returned.
 117 func alignedPeriod(now time.Time, p time.Duration) time.Time {
 118         _, tzsec := now.Zone()
 119         tzoff := time.Duration(tzsec) * time.Second
 120         periodStart := now.Add(tzoff).Truncate(p).Add(-tzoff)
 121         return periodStart.Add(p)
 122 }