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