Css 4824/expire audit logs (#1007)

* domain object method to cleanup logs

* add service to manage cleanup

* Update charms

* PR comments

* Update tests

* Line checks

* Fix charm tests

* More test fixes

* Fix tests

* Handle negative durations

* Add missing utc.

* Unit test calc poll duration

* PR comments

* Fix monitoring

* New line

* Update to fit with Minas PR

charms/jimm-k8s/config.yaml

@@ -2,6 +2,14 @@
 # See LICENSE file for licensing details.
 
 options:
+  audit-log-retention-period-in-days:
+    type: string
+    description: |
+      How long to hold audit logs for in days, i.e., 10 = 10 days.
+      If the value 0 is used, the logs will never be purged.
+      Logs are purged at 9AM UTC. Defaults to 0, which means by 
+      default logs are never purged.
+    default: "0"
   candid-agent-private-key:
     type: string
     description: |

charms/jimm-k8s/src/charm.py

@@ -243,6 +243,7 @@ def _update_workload(self, event):
         config_values = {
             "CANDID_PUBLIC_KEY": self.config.get("candid-public-key", ""),
             "CANDID_URL": self.config.get("candid-url", ""),
+            "JIMM_AUDIT_LOG_RETENTION_PERIOD_IN_DAYS": self.config.get("audit-log-retention-period-in-days", ""),
             "JIMM_ADMINS": self.config.get("controller-admins", ""),
             "JIMM_DNS_NAME": dns_name,
             "JIMM_LOG_LEVEL": self.config.get("log-level", ""),

charms/jimm-k8s/tests/unit/test_charm.py

@@ -21,6 +21,7 @@
     "public-key": "izcYsQy3TePp6bLjqOo3IRPFvkQd2IKtyODGqC6SdFk=",
     "private-key": "ly/dzsI9Nt/4JxUILQeAX79qZ4mygDiuYGqc2ZEiDEc=",
     "vault-access-address": "10.0.1.123",
+    "audit-log-retention-period-in-days": "10",
 }
 
 
@@ -79,6 +80,7 @@ def test_on_pebble_ready(self):
                             "JIMM_LOG_LEVEL": "info",
                             "JIMM_UUID": "1234567890",
                             "JIMM_WATCH_CONTROLLERS": "1",
+                            "JIMM_AUDIT_LOG_RETENTION_PERIOD_IN_DAYS": "10",
                             "PRIVATE_KEY": "ly/dzsI9Nt/4JxUILQeAX79qZ4mygDiuYGqc2ZEiDEc=",
                             "PUBLIC_KEY": "izcYsQy3TePp6bLjqOo3IRPFvkQd2IKtyODGqC6SdFk=",
                         },
@@ -117,6 +119,7 @@ def test_on_config_changed(self):
                             "JIMM_LOG_LEVEL": "info",
                             "JIMM_UUID": "1234567890",
                             "JIMM_WATCH_CONTROLLERS": "1",
+                            "JIMM_AUDIT_LOG_RETENTION_PERIOD_IN_DAYS": "10",
                             "PRIVATE_KEY": "ly/dzsI9Nt/4JxUILQeAX79qZ4mygDiuYGqc2ZEiDEc=",
                             "PUBLIC_KEY": "izcYsQy3TePp6bLjqOo3IRPFvkQd2IKtyODGqC6SdFk=",
                         },
@@ -159,6 +162,7 @@ def test_bakery_configuration(self):
                             "BAKERY_AGENT_FILE": "/root/config/agent.json",
                             "CANDID_URL": "test-candid-url",
                             "JIMM_DASHBOARD_LOCATION": "https://jaas.ai/models",
+                            "JIMM_AUDIT_LOG_RETENTION_PERIOD_IN_DAYS": "0",
                             "JIMM_DNS_NAME": "juju-jimm-k8s-0.juju-jimm-k8s-endpoints.None.svc.cluster.local",
                             "JIMM_ENABLE_JWKS_ROTATOR": "1",
                             "JIMM_LISTEN_ADDR": ":8080",

charms/jimm/config.yaml

@@ -2,6 +2,14 @@
 # See LICENSE file for licensing details.
 
 options:
+  audit-log-retention-period-in-days:
+    type: string
+    description: |
+      How long to hold audit logs for in days, i.e., 10 = 10 days.
+      If the value 0 is used, the logs will never be purged.
+      Logs are purged at 9AM UTC. Defaults to 0, which means by 
+      default logs are never purged.
+    default: "0"
   candid-agent-private-key:
     type: string
     description: |

charms/jimm/src/charm.py

@@ -132,6 +132,7 @@ def _on_config_changed(self, _):
             "dashboard_location": self.config.get("juju-dashboard-location"),
             "public_key": self.config.get("public-key"),
             "private_key": self.config.get("private-key"),
+            "audit_retention_period": self.config.get("audit-log-retention-period-in-days", ""),
         }
 
         with open(self._env_filename(), "wt") as f:

charms/jimm/templates/jimm.env

@@ -14,4 +14,5 @@ PRIVATE_KEY={{private_key}}
 {% endif %}
 {% if public_key %}
 PUBLIC_KEY={{public_key}}
-{% endif %}
+{% endif %}
+JIMM_AUDIT_LOG_RETENTION_PERIOD_IN_DAYS={{audit_retention_period}}

charms/jimm/tests/test_charm.py

@@ -117,13 +117,14 @@ def test_config_changed(self):
                 "uuid": "caaa4ba4-e2b5-40dd-9bf3-2bd26d6e17aa",
                 "public-key": "izcYsQy3TePp6bLjqOo3IRPFvkQd2IKtyODGqC6SdFk=",
                 "private-key": "ly/dzsI9Nt/4JxUILQeAX79qZ4mygDiuYGqc2ZEiDEc=",
+                "audit-log-retention-period-in-days": "10",
             }
         )
         self.assertTrue(os.path.exists(config_file))
         with open(config_file) as f:
             lines = f.readlines()
         os.unlink(config_file)
-        self.assertEqual(len(lines), 16)
+        self.assertEqual(len(lines), 18)
         self.assertEqual(lines[0].strip(), "BAKERY_AGENT_FILE=")
         self.assertEqual(lines[1].strip(), "CANDID_URL=https://candid.example.com")
         self.assertEqual(lines[2].strip(), "JIMM_ADMINS=user1 user2 group1")
@@ -142,6 +143,10 @@ def test_config_changed(self):
             lines[15].strip(),
             "PUBLIC_KEY=izcYsQy3TePp6bLjqOo3IRPFvkQd2IKtyODGqC6SdFk=",
         )
+        self.assertEqual(
+            lines[17].strip(),
+            "JIMM_AUDIT_LOG_RETENTION_PERIOD_IN_DAYS=10",
+        )
 
     def test_config_changed_redirect_to_dashboard(self):
         config_file = os.path.join(self.harness.charm.charm_dir, "juju-jimm.env")
@@ -155,13 +160,14 @@ def test_config_changed_redirect_to_dashboard(self):
                 "juju-dashboard-location": "https://test.jaas.ai/models",
                 "public-key": "izcYsQy3TePp6bLjqOo3IRPFvkQd2IKtyODGqC6SdFk=",
                 "private-key": "ly/dzsI9Nt/4JxUILQeAX79qZ4mygDiuYGqc2ZEiDEc=",
+                "audit-log-retention-period-in-days": "10",
             }
         )
         self.assertTrue(os.path.exists(config_file))
         with open(config_file) as f:
             lines = f.readlines()
         os.unlink(config_file)
-        self.assertEqual(len(lines), 16)
+        self.assertEqual(len(lines), 18)
         self.assertEqual(lines[0].strip(), "BAKERY_AGENT_FILE=")
         self.assertEqual(lines[1].strip(), "CANDID_URL=https://candid.example.com")
         self.assertEqual(lines[2].strip(), "JIMM_ADMINS=user1 user2 group1")
@@ -180,6 +186,10 @@ def test_config_changed_redirect_to_dashboard(self):
             lines[15].strip(),
             "PUBLIC_KEY=izcYsQy3TePp6bLjqOo3IRPFvkQd2IKtyODGqC6SdFk=",
         )
+        self.assertEqual(
+            lines[17].strip(),
+            "JIMM_AUDIT_LOG_RETENTION_PERIOD_IN_DAYS=10",
+        )
 
     def test_config_changed_ready(self):
         config_file = os.path.join(self.harness.charm.charm_dir, "juju-jimm.env")
@@ -192,13 +202,14 @@ def test_config_changed_ready(self):
                 "uuid": "caaa4ba4-e2b5-40dd-9bf3-2bd26d6e17aa",
                 "public-key": "izcYsQy3TePp6bLjqOo3IRPFvkQd2IKtyODGqC6SdFk=",
                 "private-key": "ly/dzsI9Nt/4JxUILQeAX79qZ4mygDiuYGqc2ZEiDEc=",
+                "audit-log-retention-period-in-days": "10",
             }
         )
         self.assertTrue(os.path.exists(config_file))
         with open(config_file) as f:
             lines = f.readlines()
         os.unlink(config_file)
-        self.assertEqual(len(lines), 14)
+        self.assertEqual(len(lines), 16)
         self.assertEqual(lines[0].strip(), "BAKERY_AGENT_FILE=")
         self.assertEqual(lines[1].strip(), "CANDID_URL=https://candid.example.com")
         self.assertEqual(lines[2].strip(), "JIMM_ADMINS=user1 user2 group1")
@@ -216,6 +227,10 @@ def test_config_changed_ready(self):
             lines[13].strip(),
             "PUBLIC_KEY=izcYsQy3TePp6bLjqOo3IRPFvkQd2IKtyODGqC6SdFk=",
         )
+        self.assertEqual(
+            lines[15].strip(),
+            "JIMM_AUDIT_LOG_RETENTION_PERIOD_IN_DAYS=10",
+        )
 
     def test_config_changed_with_agent(self):
         config_file = os.path.join(self.harness.charm.charm_dir, "juju-jimm.env")
@@ -242,7 +257,7 @@ def test_config_changed_with_agent(self):
 
         with open(config_file) as f:
             lines = f.readlines()
-        self.assertEqual(len(lines), 14)
+        self.assertEqual(len(lines), 16)
         self.assertEqual(
             lines[0].strip(),
             "BAKERY_AGENT_FILE=" + self.harness.charm._agent_filename,
@@ -268,7 +283,7 @@ def test_config_changed_with_agent(self):
         )
         with open(config_file) as f:
             lines = f.readlines()
-        self.assertEqual(len(lines), 14)
+        self.assertEqual(len(lines), 16)
         self.assertEqual(lines[0].strip(), "BAKERY_AGENT_FILE=")
         self.assertEqual(lines[1].strip(), "CANDID_URL=https://candid.example.com")
         self.assertEqual(lines[2].strip(), "JIMM_ADMINS=user1 user2 group1")

cmd/jimmsrv/main.go

@@ -68,8 +68,9 @@ func start(ctx context.Context, s *service.Service) error {
 			Token:     os.Getenv("OPENFGA_TOKEN"),
 			Port:      os.Getenv("OPENFGA_PORT"),
 		},
-		PrivateKey: os.Getenv("BAKERY_PRIVATE_KEY"),
-		PublicKey:  os.Getenv("BAKERY_PUBLIC_KEY"),
+		PrivateKey:                    os.Getenv("BAKERY_PRIVATE_KEY"),
+		PublicKey:                     os.Getenv("BAKERY_PUBLIC_KEY"),
+		AuditLogRetentionPeriodInDays: os.Getenv("JIMM_AUDIT_LOG_RETENTION_PERIOD_IN_DAYS"),
 	})
 	if err != nil {
 		return err

docker-compose.yaml

@@ -54,6 +54,7 @@ services:
       JIMM_TEST_PGXDSN: ""
       JIMM_JWT_EXPIRY: 30s
       JIMM_ENABLE_JWKS_ROTATOR: "1"
+      JIMM_AUDIT_LOG_RETENTION_PERIOD_IN_DAYS: "1"
       TEST_LOGGING_CONFIG: ""
       PUBLIC_KEY: "izcYsQy3TePp6bLjqOo3IRPFvkQd2IKtyODGqC6SdFk="
       PRIVATE_KEY: "ly/dzsI9Nt/4JxUILQeAX79qZ4mygDiuYGqc2ZEiDEc="

internal/db/audit.go

@@ -8,6 +8,7 @@ import (
 
 	"github.com/canonical/jimm/internal/dbmodel"
 	"github.com/canonical/jimm/internal/errors"
+	"github.com/canonical/jimm/internal/servermon"
 )
 
 // AddAuditLogEntry adds a new entry to the audit log.
@@ -103,3 +104,20 @@ func (d *Database) ForEachAuditLogEntry(ctx context.Context, filter AuditLogFilt
 	}
 	return nil
 }
+
+// CleanupAuditLogs cleans up audit logs after the auditLogRetentionPeriodInDays,
+// HARD deleting them from the database.
+func (d *Database) DeleteAuditLogsBefore(ctx context.Context, before time.Time) (int64, error) {
+	const op = errors.Op("db.DeleteAuditLogsBefore")
+	now := time.Now()
+	tx := d.DB.
+		WithContext(ctx).
+		Unscoped().
+		Where("time < ?", before).
+		Delete(&dbmodel.AuditLogEntry{})
+	servermon.QueryTimeAuditLogCleanUpHistogram.Observe(time.Since(now).Seconds())
+	if tx.Error != nil {
+		return 0, errors.E(op, dbError(tx.Error))
+	}
+	return tx.RowsAffected, nil
+}

internal/db/auditlog_test.go

@@ -149,3 +149,57 @@ func (s *dbSuite) TestForEachAuditLogEntry(c *qt.C) {
 	c.Check(calls, qt.Equals, 1)
 	c.Check(err, qt.DeepEquals, testError)
 }
+
+func (s *dbSuite) TestDeleteAuditLogsBefore(c *qt.C) {
+	ctx := context.Background()
+	now := time.Now()
+
+	err := s.Database.AddAuditLogEntry(ctx, &dbmodel.AuditLogEntry{
+		Time: now.AddDate(0, 0, -1),
+	})
+	c.Check(errors.ErrorCode(err), qt.Equals, errors.CodeUpgradeInProgress)
+
+	err = s.Database.Migrate(context.Background(), true)
+	c.Assert(err, qt.IsNil)
+
+	// Delete all when none exist
+	retentionDate := time.Now()
+	deleted, err := s.Database.DeleteAuditLogsBefore(ctx, retentionDate)
+	c.Assert(err, qt.IsNil)
+	c.Assert(deleted, qt.Equals, int64(0))
+
+	// A log from 1 day ago
+	c.Assert(s.Database.AddAuditLogEntry(ctx, &dbmodel.AuditLogEntry{
+		Time: now.AddDate(0, 0, -1),
+	}), qt.IsNil)
+
+	// A log from 2 days ago
+	c.Assert(s.Database.AddAuditLogEntry(ctx, &dbmodel.AuditLogEntry{
+		Time: now.AddDate(0, 0, -2),
+	}), qt.IsNil)
+
+	// A log from 3 days ago
+	c.Assert(s.Database.AddAuditLogEntry(ctx, &dbmodel.AuditLogEntry{
+		Time: now.AddDate(0, 0, -3),
+	}), qt.IsNil)
+
+	// Ensure 3 exist
+	logs := make([]dbmodel.AuditLogEntry, 0)
+	err = s.Database.DB.Find(&logs).Error
+	c.Assert(err, qt.IsNil)
+	c.Assert(logs, qt.HasLen, 3)
+
+	// Delete all 2 or more days older, leaving 1 log left
+	retentionDate = time.Now().AddDate(0, 0, -(2))
+	deleted, err = s.Database.DeleteAuditLogsBefore(ctx, retentionDate)
+	c.Assert(err, qt.IsNil)
+
+	// Check that 2 were infact deleted
+	c.Assert(deleted, qt.Equals, int64(2))
+
+	// Check only 1 remains
+	logs = make([]dbmodel.AuditLogEntry, 0)
+	err = s.Database.DB.Find(&logs).Error
+	c.Assert(err, qt.IsNil)
+	c.Assert(logs, qt.HasLen, 1)
+}

internal/jimm/audit_log.go

@@ -15,6 +15,7 @@ import (
 	"github.com/juju/zaputil/zapctx"
 	"go.uber.org/zap"
 
+	"github.com/canonical/jimm/internal/db"
 	"github.com/canonical/jimm/internal/dbmodel"
 	"github.com/canonical/jimm/internal/servermon"
 )
@@ -127,3 +128,77 @@ func (o recorder) HandleReply(r rpc.Request, header *rpc.Header, body interface{
 	servermon.WebsocketRequestDuration.WithLabelValues(r.Type, r.Action).Observe(float64(d) / float64(time.Second))
 	return o.logger.LogResponse(r, header, body)
 }
+
+// AuditLogCleanupService is a service capable of cleaning up audit logs
+// on a defined retention period. The retention period is in DAYS.
+type auditLogCleanupService struct {
+	auditLogRetentionPeriodInDays int
+	db                            db.Database
+}
+
+// pollTimeOfDay holds the time hour, minutes and seconds to poll at.
+type pollTimeOfDay struct {
+	Hours   int
+	Minutes int
+	Seconds int
+}
+
+var pollDuration = pollTimeOfDay{
+	Hours: 9,
+}
+
+// NewAuditLogCleanupService returns a service capable of cleaning up audit logs
+// on a defined retention period. The retention period is in DAYS.
+func NewAuditLogCleanupService(db db.Database, auditLogRetentionPeriodInDays int) *auditLogCleanupService {
+	return &auditLogCleanupService{
+		auditLogRetentionPeriodInDays: auditLogRetentionPeriodInDays,
+		db:                            db,
+	}
+}
+
+// Start starts a routine which checks daily for any logs
+// needed to be cleaned up.
+func (a *auditLogCleanupService) Start(ctx context.Context) {
+	go a.poll(ctx)
+}
+
+// poll is designed to be run in a routine where it can be cancelled safely
+// from the service's context. It calculates the poll duration at 9am each day
+// UTC.
+func (a *auditLogCleanupService) poll(ctx context.Context) {
+	retentionDate := time.Now().AddDate(0, 0, -(a.auditLogRetentionPeriodInDays))
+
+	for {
+		select {
+		case <-time.After(calculateNextPollDuration(time.Now().UTC())):
+			deleted, err := a.db.DeleteAuditLogsBefore(ctx, retentionDate)
+			if err != nil {
+				zapctx.Error(ctx, "failed to cleanup audit logs", zap.Error(err))
+				continue
+			}
+			zapctx.Debug(ctx, "audit log cleanup run successfully", zap.Int64("count", deleted))
+		case <-ctx.Done():
+			zapctx.Debug(ctx, "exiting audit log cleanup polling")
+			return
+		}
+	}
+}
+
+// calculateNextPollDuration returns the next duration to poll on.
+// We recalculate each time and not rely on running every 24 hours
+// for absolute consistency within ns apart.
+func calculateNextPollDuration(startingTime time.Time) time.Duration {
+	now := startingTime
+	nineAM := time.Date(now.Year(), now.Month(), now.Day(), pollDuration.Hours, 0, 0, 0, time.UTC)
+	nineAMDuration := nineAM.Sub(now)
+	d := time.Hour
+	// If 9am is behind the current time, i.e., 1pm
+	if nineAMDuration < 0 {
+		// Add 24 hours, flip it to an absolute duration, i.e., -10h == 10h
+		// and subtract it from 24 hours to calculate 9am tomorrow
+		d = time.Hour*24 - nineAMDuration.Abs()
+	} else {
+		d = nineAMDuration.Abs()
+	}
+	return d
+}