track_event() mechanism for analytics and plugins

* Closes #2240
* Documentation for event plugin hooks, refs #2240
* Include example track_event plugin in docs, refs #2240
* Tests for track_event() and register_events() hooks, refs #2240
* Initial documentation for core events, refs #2240
* Internals documentation for datasette.track_event()

tests/conftest.py

@@ -1,4 +1,3 @@
-import asyncio
 import httpx
 import os
 import pathlib
@@ -8,7 +7,8 @@ import re
 import subprocess
 import tempfile
 import time
-import trustme
+from dataclasses import dataclass, field
+from datasette import Event, hookimpl
 
 
 try:
@@ -164,6 +164,35 @@ def check_permission_actions_are_documented():
     )
 
 
+class TrackEventPlugin:
+    __name__ = "TrackEventPlugin"
+
+    @dataclass
+    class OneEvent(Event):
+        name = "one"
+
+        extra: str
+
+    @hookimpl
+    def register_events(self, datasette):
+        async def inner():
+            return [self.OneEvent]
+
+        return inner
+
+    @hookimpl
+    def track_event(self, datasette, event):
+        datasette._tracked_events = getattr(datasette, "_tracked_events", [])
+        datasette._tracked_events.append(event)
+
+
+@pytest.fixture(scope="session", autouse=True)
+def install_event_tracking_plugin():
+    from datasette.plugins import pm
+
+    pm.register(TrackEventPlugin(), name="TrackEventPlugin")
+
+
 @pytest.fixture(scope="session")
 def ds_localhost_http_server():
     ds_proc = subprocess.Popen(

tests/test_api.py

@@ -786,7 +786,12 @@ async def test_threads_json(ds_client):
 @pytest.mark.asyncio
 async def test_plugins_json(ds_client):
     response = await ds_client.get("/-/plugins.json")
-    assert EXPECTED_PLUGINS == sorted(response.json(), key=lambda p: p["name"])
+    # Filter out TrackEventPlugin
+    actual_plugins = sorted(
+        [p for p in response.json() if p["name"] != "TrackEventPlugin"],
+        key=lambda p: p["name"],
+    )
+    assert EXPECTED_PLUGINS == actual_plugins
     # Try with ?all=1
     response = await ds_client.get("/-/plugins.json?all=1")
     names = {p["name"] for p in response.json()}

tests/test_api_write.py

@@ -1,5 +1,6 @@
 from datasette.app import Datasette
 from datasette.utils import sqlite3
+from .utils import last_event
 import pytest
 import time
 
@@ -49,6 +50,14 @@ async def test_insert_row(ds_write):
     assert response.json()["rows"] == [expected_row]
     rows = (await ds_write.get_database("data").execute("select * from docs")).rows
     assert dict(rows[0]) == expected_row
+    # Analytics event
+    event = last_event(ds_write)
+    assert event.name == "insert-rows"
+    assert event.num_rows == 1
+    assert event.database == "data"
+    assert event.table == "docs"
+    assert not event.ignore
+    assert not event.replace
 
 
 @pytest.mark.asyncio
@@ -68,6 +77,16 @@ async def test_insert_rows(ds_write, return_rows):
         headers=_headers(token),
     )
     assert response.status_code == 201
+
+    # Analytics event
+    event = last_event(ds_write)
+    assert event.name == "insert-rows"
+    assert event.num_rows == 20
+    assert event.database == "data"
+    assert event.table == "docs"
+    assert not event.ignore
+    assert not event.replace
+
     actual_rows = [
         dict(r)
         for r in (
@@ -353,6 +372,16 @@ async def test_insert_ignore_replace(
         headers=_headers(token),
     )
     assert response.status_code == 201
+
+    # Analytics event
+    event = last_event(ds_write)
+    assert event.name == "insert-rows"
+    assert event.num_rows == 1
+    assert event.database == "data"
+    assert event.table == "docs"
+    assert event.ignore == ignore
+    assert event.replace == replace
+
     actual_rows = [
         dict(r)
         for r in (
@@ -427,6 +456,14 @@ async def test_upsert(ds_write, initial, input, expected_rows, should_return):
     )
     assert response.status_code == 200
     assert response.json()["ok"] is True
+
+    # Analytics event
+    event = last_event(ds_write)
+    assert event.name == "upsert-rows"
+    assert event.num_rows == 1
+    assert event.database == "data"
+    assert event.table == "upsert_test"
+
     if should_return:
         # We only expect it to return rows corresponding to those we sent
         expected_returned_rows = expected_rows[: len(input["rows"])]
@@ -530,6 +567,13 @@ async def test_delete_row(ds_write, table, row_for_create, pks, delete_path):
         headers=_headers(write_token(ds_write)),
     )
     assert delete_response.status_code == 200
+
+    # Analytics event
+    event = last_event(ds_write)
+    assert event.name == "delete-row"
+    assert event.database == "data"
+    assert event.table == table
+    assert event.pks == str(delete_path).split(",")
     assert (
         await ds_write.client.get(
             "/data.json?_shape=arrayfirst&sql=select+count(*)+from+{}".format(table)
@@ -610,6 +654,13 @@ async def test_update_row(ds_write, input, expected_errors, use_return):
         for k, v in input.items():
             assert returned_row[k] == v
 
+    # Analytics event
+    event = last_event(ds_write)
+    assert event.actor == {"id": "root", "token": "dstok"}
+    assert event.database == "data"
+    assert event.table == "docs"
+    assert event.pks == [str(pk)]
+
     # And fetch the row to check it's updated
     response = await ds_write.client.get(
         "/data/docs/{}.json?_shape=array".format(pk),
@@ -676,6 +727,13 @@ async def test_drop_table(ds_write, scenario):
             headers=_headers(token),
         )
         assert response2.json() == {"ok": True}
+        # Check event
+        event = last_event(ds_write)
+        assert event.name == "drop-table"
+        assert event.actor == {"id": "root", "token": "dstok"}
+        assert event.table == "docs"
+        assert event.database == "data"
+        # Table should 404
         assert (await ds_write.client.get("/data/docs")).status_code == 404
 
 
@@ -1096,6 +1154,12 @@ async def test_create_table(ds_write, input, expected_status, expected_response)
     assert response.status_code == expected_status
     data = response.json()
     assert data == expected_response
+    # create-table event
+    if expected_status == 201:
+        event = last_event(ds_write)
+        assert event.name == "create-table"
+        assert event.actor == {"id": "root", "token": "dstok"}
+        assert event.schema.startswith("CREATE TABLE ")
 
 
 @pytest.mark.asyncio

tests/test_auth.py

@@ -1,6 +1,6 @@
 from bs4 import BeautifulSoup as Soup
 from .fixtures import app_client
-from .utils import cookie_was_deleted
+from .utils import cookie_was_deleted, last_event
 from click.testing import CliRunner
 from datasette.utils import baseconv
 from datasette.cli import cli
@@ -19,6 +19,10 @@ async def test_auth_token(ds_client):
     assert {"a": {"id": "root"}} == ds_client.ds.unsign(
         response.cookies["ds_actor"], "actor"
     )
+    # Should have recorded a login event
+    event = last_event(ds_client.ds)
+    assert event.name == "login"
+    assert event.actor == {"id": "root"}
     # Check that a second with same token fails
     assert ds_client.ds._root_token is None
     assert (await ds_client.get(path)).status_code == 403
@@ -57,7 +61,7 @@ async def test_actor_cookie_that_expires(ds_client, offset, expected):
     cookie = ds_client.ds.sign(
         {"a": {"id": "test"}, "e": baseconv.base62.encode(expires_at)}, "actor"
     )
-    response = await ds_client.get("/", cookies={"ds_actor": cookie})
+    await ds_client.get("/", cookies={"ds_actor": cookie})
     assert ds_client.ds._last_request.scope["actor"] == expected
 
 
@@ -86,6 +90,10 @@ def test_logout(app_client):
         csrftoken_from=True,
         cookies={"ds_actor": app_client.actor_cookie({"id": "test"})},
     )
+    # Should have recorded a logout event
+    event = last_event(app_client.ds)
+    assert event.name == "logout"
+    assert event.actor == {"id": "test"}
     # The ds_actor cookie should have been unset
     assert cookie_was_deleted(response4, "ds_actor")
     # Should also have set a message
@@ -185,6 +193,13 @@ def test_auth_create_token(
         for error in errors:
             assert '<p class="message-error">{}</p>'.format(error) in response2.text
     else:
+        # Check create-token event
+        event = last_event(app_client.ds)
+        assert event.name == "create-token"
+        assert event.expires_after == expected_duration
+        assert isinstance(event.restrict_all, list)
+        assert isinstance(event.restrict_database, dict)
+        assert isinstance(event.restrict_resource, dict)
         # Extract token from page
         token = response2.text.split('value="dstok_')[1].split('"')[0]
         details = app_client.ds.unsign(token, "token")

tests/test_cli.py

@@ -100,7 +100,11 @@ def test_spatialite_error_if_cannot_find_load_extension_spatialite():
 def test_plugins_cli(app_client):
     runner = CliRunner()
     result1 = runner.invoke(cli, ["plugins"])
-    assert json.loads(result1.output) == EXPECTED_PLUGINS
+    actual_plugins = sorted(
+        [p for p in json.loads(result1.output) if p["name"] != "TrackEventPlugin"],
+        key=lambda p: p["name"],
+    )
+    assert actual_plugins == EXPECTED_PLUGINS
     # Try with --all
     result2 = runner.invoke(cli, ["plugins", "--all"])
     names = [p["name"] for p in json.loads(result2.output)]

tests/test_plugins.py

@@ -9,8 +9,9 @@ from .fixtures import (
     TestClient as _TestClient,
 )  # noqa
 from click.testing import CliRunner
+from dataclasses import dataclass
 from datasette.app import Datasette
-from datasette import cli, hookimpl, Permission
+from datasette import cli, hookimpl, Event, Permission
 from datasette.filters import FilterArguments
 from datasette.plugins import get_plugins, DEFAULT_PLUGINS, pm
 from datasette.utils.sqlite import sqlite3
@@ -18,6 +19,7 @@ from datasette.utils import CustomRow, StartupError
 from jinja2.environment import Template
 from jinja2 import ChoiceLoader, FileSystemLoader
 import base64
+import datetime
 import importlib
 import json
 import os
@@ -1437,3 +1439,30 @@ async def test_hook_top_canned_query(ds_client):
         assert "Xtop_query:fixtures:from_hook:xyz" in response.text
     finally:
         pm.unregister(name="SlotPlugin")
+
+
+@pytest.mark.asyncio
+async def test_hook_track_event():
+    datasette = Datasette(memory=True)
+    from .conftest import TrackEventPlugin
+
+    await datasette.invoke_startup()
+    await datasette.track_event(
+        TrackEventPlugin.OneEvent(actor=None, extra="extra extra")
+    )
+    assert len(datasette._tracked_events) == 1
+    assert isinstance(datasette._tracked_events[0], TrackEventPlugin.OneEvent)
+    event = datasette._tracked_events[0]
+    assert event.name == "one"
+    assert event.properties() == {"extra": "extra extra"}
+    # Should have a recent created as well
+    created = event.created
+    assert isinstance(created, datetime.datetime)
+    assert created.tzinfo == datetime.timezone.utc
+
+
+@pytest.mark.asyncio
+async def test_hook_register_events():
+    datasette = Datasette(memory=True)
+    await datasette.invoke_startup()
+    assert any(k.__name__ == "OneEvent" for k in datasette.event_classes)

tests/utils.py

@@ -1,6 +1,11 @@
 from datasette.utils.sqlite import sqlite3
 
 
+def last_event(datasette):
+    events = getattr(datasette, "_tracked_events", [])
+    return events[-1] if events else None
+
+
 def assert_footer_links(soup):
     footer_links = soup.find("footer").findAll("a")
     assert 4 == len(footer_links)