diff --git a/docs/log-table/README.md b/docs/log-table/README.md index 2930efe..2628741 100644 --- a/docs/log-table/README.md +++ b/docs/log-table/README.md @@ -181,8 +181,10 @@ configured with, and CloudFront has no field carrying somebody else's payload. A table over the same objects meets the same wall, since no SerDe parses a query string. The [searches](../searches/) rollup already reads a search term out of the same column the same way. -`beaconQueryString`, `beaconEventColumn` and `aBeaconEvent` are exported from the package root, so -the browser writing the payload and the SQL reading it hold one definition between them. +`beaconQueryString`, `beaconEventColumn`, `aBeaconEvent` and `outsideTheBeaconPath` are exported +from the package root, so the browser writing the payload and the SQL reading it hold one definition +between them. Which of the shipped questions count beacon rows is on the +[rollups](../rollups/#the-beacons-own-requests) page. `status-codes` is the one that had to be told. Partitions written before the beacon shipped answer no rows at all. A beacon row is identified by the path it was sent to. A query for that path over an older day matches nothing, where a column diff --git a/docs/rollups/README.md b/docs/rollups/README.md index ef1501d..5323320 100644 --- a/docs/rollups/README.md +++ b/docs/rollups/README.md @@ -36,7 +36,8 @@ out, and so are the ones this site sent itself. Those are somebody moving around reference site an unfiltered version of this is topped by its own stylesheet. **`status-codes`** counts every response, including the assets the pageview count leaves out. A -stylesheet returning 404 is worth seeing and a rollup looking only at pages never would. +stylesheet returning 404 is worth seeing and a rollup looking only at pages never would. Requests to +the [beacon's own path](#the-beacons-own-requests) are the exception. **`cache-hit-ratio`** counts over the requests the cache had a say in, being a Hit, a RefreshHit or a Miss. A redirect, an error and a response a CloudFront Function generated are requests the cache @@ -88,6 +89,43 @@ rainlytics pageviews --last 7d --include-bots `status-codes` is the one where `--include-bots` is usually what you want. Bots find the broken links first and in numbers. +## The beacon's own requests + +The beacon sends a GET to `/_rainlytics` on the site's own domain and carries its payload in the +query string. An event is another row in the same log. It writes one row per event, and a +single-page app reporting route changes, web vitals and errors sends several per reader per page. A +quiet site can end up with more beacon rows than responses of its own. + +`status-codes` leaves those requests out, and no option puts them back. Every event answers 204. A +window of them leads the table under one status, and the 404 the question exists to surface sits +somewhere below it. The question is what the site answered for the things it serves, and the beacon +is Rainlytics measuring the site. + +Anybody checking that the beacon is delivering has [`rainlytics query`](../query/): + +```bash +rainlytics query "SELECT sc_status, count(*) AS events FROM cloudfront_logs + WHERE year = '2026' AND month = '08' AND day = '29' + AND strpos(cs_uri_stem, '/_rainlytics') = 1 + GROUP BY 1" +``` + +The path is one constant, `defaultBeaconPath`, that the beacon and the rollup both read. Naming a +different one belongs to the beacon construct. + +The other four questions leave beacon rows out already, for reasons they had anyway: + +- **`pageviews`** and **`referrers`** count a GET that answered `text/html` with a 200 or a 304. An + event answers 204 and names no content type. +- **`searches`** wants its parameter non-empty. A payload names its parameters `v`, `e` and `p`, and + carries no `q`. +- **`cache-hit-ratio`** counts a Hit, a RefreshHit or a Miss. A CloudFront Function answers every + event, and the cache is never asked. + +Those four are checked against delivered beacon records rather than taken on trust, in +`src/beacon-events.test.ts`. Each of them leaves the rows out through a condition it has for its own +reasons, and a rollup of your own gets none of that for free. + ## `--path` and `--host` narrow the question `--path` counts one section of a site, as a prefix of the address: diff --git a/src/beacon-events.test.ts b/src/beacon-events.test.ts index 6c31f93..33631ef 100644 --- a/src/beacon-events.test.ts +++ b/src/beacon-events.test.ts @@ -1,6 +1,17 @@ +import { gzipSync } from "node:zlib"; + +import { AthenaClient } from "@aws-sdk/client-athena"; +import { S3Client } from "@aws-sdk/client-s3"; import { faker } from "@faker-js/faker"; +import { SimSdk } from "@kensio/yulin/sdk"; +import { Distribution } from "aws-cdk-lib/aws-cloudfront"; +import { HttpOrigin } from "aws-cdk-lib/aws-cloudfront-origins"; +import { type App, CfnOutput, Stack } from "aws-cdk-lib/core"; import { describe, expect, it } from "vitest"; +import { deployStacks } from "#test/simulated-deployment.js"; + +import { runAthenaQuery } from "./athena/athena-query.js"; import { aBeaconEvent, beaconEventColumn, @@ -8,7 +19,15 @@ import { beaconQueryString, beaconSchemaVersion, defaultBeaconPath, + outsideTheBeaconPath, } from "./beacon-events.js"; +import { CloudFrontLogDelivery } from "./cdk/log-delivery.js"; +import { LogBucket } from "./cdk/log-bucket.js"; +import { LogTable } from "./cdk/log-table.js"; +import { QueryWorkgroup } from "./cdk/query-workgroup.js"; +import { partitionPrefix } from "./partitions.js"; +import { rollups } from "./rollup-questions.js"; +import { rollupRequest, rollupSql } from "./rollups.js"; describe("the beacon event envelope", () => { it("stamps every event with the version it was written under", () => { @@ -74,6 +93,17 @@ describe("the beacon event envelope", () => { expect(aBeaconEvent.join(" ")).toContain(`'${beaconParameters.version}'`); }); + it("names the path where the envelope's own conditions leave it out", () => { + // Given the condition status-codes takes the beacon's requests back out + // with. + // Then it names the path, where `aBeaconEvent` leaves the path to the + // request's own `paths`. The two run in opposite directions. It reads + // the column as delivered, since the path carries nothing a browser or + // CloudFront escapes. + expect(outsideTheBeaconPath).toContain(`'${defaultBeaconPath}'`); + expect(outsideTheBeaconPath).not.toContain("url_decode"); + }); + it("sends to a path a site is unlikely to serve already", () => { // Given the default path. // Then it is one path, absolute, and marked as not a page. Pointing the @@ -82,3 +112,280 @@ describe("the beacon event envelope", () => { expect(defaultBeaconPath).toMatch(/^\/_/u); }); }); + +/* + * What each shipped question does with a window holding beacon events. + * + * Run against delivered records rather than read off the SQL. Four of the + * five leave beacon rows out through conditions they had for their own + * reasons, and a case asserting the condition is there says nothing about + * whether it covers a beacon row. KensioSoftware/rainlytics#103 asked which + * of the five were exposed, and this is the answer being checked rather than + * argued. + */ +describe("a window holding beacon events", () => { + let intercepted: SimSdk | undefined; + + const anHour = new Date("2026-08-23T08:00:00.000Z"); + const theHour = { + from: anHour, + to: new Date(anHour.getTime() + 60 * 60 * 1000), + }; + + /** A pipeline in a simulated account, with the SDK pointed at it. */ + const deployAnalytics = async () => { + const logBucketName = `rainlytics-logs-${faker.string.uuid()}`; + + const { simAws, stacks } = await deployStacks( + (app: App, account: string) => { + const stack = new Stack(app, "AnalyticsStack", { + env: { account, region: "us-east-1" }, + }); + const logs = new LogBucket(stack, "RainlyticsLogs", { + bucketName: logBucketName, + }); + const distribution = new Distribution(stack, "Site", { + defaultBehavior: { origin: new HttpOrigin("origin.example.com") }, + }); + new CfnOutput(stack, "DistributionId", { + value: distribution.distributionId, + }); + const delivery = new CloudFrontLogDelivery(stack, "Delivery", { + distributionId: distribution.distributionId, + logBucket: logs.bucket, + }); + new LogTable(stack, "RainlyticsTable", { deliveries: [delivery] }); + new QueryWorkgroup(stack, "RainlyticsQueries", { + resultsBucketName: `rainlytics-results-${faker.string.uuid()}`, + }); + }, + ); + + await simAws.region("us-east-1").account().athena().engine().enable(); + + // What the previous case in this file replaced, put back before this one + // replaces it again. + intercepted?.restoreAll(); + intercepted = new SimSdk({ simAws }); + intercepted.intercept(AthenaClient); + intercepted.intercept(S3Client); + + return { + simAws, + logBucketName, + distributionId: String( + stacks.get("AnalyticsStack")?.output("DistributionId"), + ), + }; + }; + + type Deployed = Awaited>; + + /** + * One value as CloudFront writes it into a record. + * + * The pass this package decodes back off. A URI reaches the edge carrying + * the browser's own encoding and CloudFront encodes the result again, so a + * beacon payload holding `%2F` is delivered as `%252F`. + */ + const delivered = (value: string): string => value.replaceAll("%", "%25"); + + /** One delivered record, over the fields these questions read. */ + const putRecord = async ( + deployed: Deployed, + record: Readonly>, + ): Promise => { + const prefix = partitionPrefix({ + distributionId: deployed.distributionId, + at: anHour, + }); + const delivery = { + "timestamp(ms)": String(anHour.getTime()), + "x-host-header": "www.example.com", + "cs-method": "GET", + "cs-uri-query": "-", + "cs(Referer)": "-", + "cs(User-Agent)": "Mozilla/5.0%20(Macintosh)", + "c-ip": "203.0.113.7", + "c-country": "GB", + ...record, + }; + + await deployed.simAws + .region("us-east-1") + .account() + .s3() + .putObject({ + input: { + Bucket: deployed.logBucketName, + Key: `rainlytics/${prefix}/${faker.string.uuid()}.gz`, + Body: gzipSync(JSON.stringify(delivery)), + }, + }); + }; + + /** A page the site served, referred to by somewhere else. */ + const putPageView = (deployed: Deployed, path: string): Promise => + putRecord(deployed, { + "cs-uri-stem": path, + "sc-status": "200", + "sc-content-type": "text/html", + "cs(Referer)": delivered("https://news.example.org/a"), + "x-edge-result-type": "Hit", + }); + + /** The broken asset this question exists to surface. */ + const putMissingAsset = (deployed: Deployed): Promise => + putRecord(deployed, { + "cs-uri-stem": "/style.css", + "sc-status": "404", + "sc-content-type": "text/html", + "x-edge-result-type": "Error", + }); + + /** One search, as the site's own search page answers it. */ + const putSearch = (deployed: Deployed, term: string): Promise => + putRecord(deployed, { + "cs-uri-stem": "/search/", + "cs-uri-query": delivered(`q=${encodeURIComponent(term)}`), + "sc-status": "200", + "sc-content-type": "text/html", + "x-edge-result-type": "Miss", + }); + + /** + * One beacon event, as CloudFront records the request carrying it. + * + * A 204 from a CloudFront Function on viewer request. Nothing reaches the + * origin, no body comes back, and the query string is logged whatever the + * cache key is set to. + */ + const putBeaconEvent = (deployed: Deployed, page: string): Promise => + putRecord(deployed, { + "cs-uri-stem": defaultBeaconPath, + "cs-uri-query": delivered(beaconQueryString({ event: "route", page })), + "sc-status": "204", + "sc-content-type": "-", + "cs(Referer)": delivered(`https://www.example.com${page}`), + "x-edge-result-type": "FunctionGeneratedResponse", + }); + + /** + * A window holding more beacon events than responses of the site's own. + * + * The shape the issue describes. A single-page app reporting route changes + * sends several events per reader per page, and three pages of reading + * against five events is a mild version of it. + */ + const seedTheHour = async (deployed: Deployed): Promise => { + await Promise.all([ + putPageView(deployed, "/"), + putMissingAsset(deployed), + putSearch(deployed, "green tea"), + ...["/", "/guides/", "/guides/", "/liju/", "/liju/"].map((page) => + putBeaconEvent(deployed, page), + ), + ]); + }; + + /** What one question answers over that hour. */ + const answerTo = async ( + name: string, + ): Promise>[]> => { + const rollup = rollups.find((each) => each.name === name); + + if (rollup === undefined) { + throw new Error(`No rollup called ${name}.`); + } + + const outcome = await runAthenaQuery({ + sql: rollupSql(rollup, rollupRequest({ range: theHour })), + database: "rainlytics", + workgroup: "rainlytics", + region: "us-east-1", + }); + + expect(outcome.state).toBe("SUCCEEDED"); + + return outcome.rows; + }; + + it("counts the site's own responses under status-codes", async () => { + // Given an hour holding five beacon events and three responses the site + // itself gave. + const deployed = await deployAnalytics(); + await seedTheHour(deployed); + + // When the status codes are counted. + const rows = await answerTo("status-codes"); + + // Then the 404 the question exists to surface is there, and the 204 the + // beacon answers every event with is not. Five 204s would lead this + // table and say nothing about how the site is answering. + expect(rows.map((row) => row["status"])).toStrictEqual(["200", "404"]); + expect(rows.find((row) => row["status"] === "200")?.["responses"]).toBe( + "2", + ); + }); + + it("counts no beacon event as a pageview", async () => { + // Given the same hour. + const deployed = await deployAnalytics(); + await seedTheHour(deployed); + + // When the pages are counted. + const rows = await answerTo("pageviews"); + + // Then the beacon's path is not among them. A beacon event answers 204 + // with no content type, and a pageview is a GET that answered HTML and + // succeeded. + expect(rows.map((row) => row["path"])).toStrictEqual(["/", "/search/"]); + }); + + it("counts no beacon event as an arrival", async () => { + // Given the same hour, where every beacon event carries a referrer of + // the page it happened on. + const deployed = await deployAnalytics(); + await seedTheHour(deployed); + + // When the referrers are counted. + const rows = await answerTo("referrers"); + + // Then only the arrival is counted. The beacon's own referrer is this + // site, which referrers leaves out anyway, and its rows are not + // pageviews. + expect(rows.map((row) => row["referrer"])).toStrictEqual([ + "news.example.org", + ]); + expect(rows[0]?.["views"]).toBe("1"); + }); + + it("counts no beacon event as a search", async () => { + // Given the same hour, where every beacon event carries a query string. + const deployed = await deployAnalytics(); + await seedTheHour(deployed); + + // When the searches are counted. + const rows = await answerTo("searches"); + + // Then only what somebody typed is counted. A beacon payload names its + // parameters `v`, `e` and `p`, and carries no `q` to read. + expect(rows.map((row) => row["term"])).toStrictEqual(["green tea"]); + }); + + it("leaves beacon events out of the cache hit ratio", async () => { + // Given the same hour. + const deployed = await deployAnalytics(); + await seedTheHour(deployed); + + // When the cache is counted. + const rows = await answerTo("cache-hit-ratio"); + + // Then the denominator is the two requests the cache had a say in. A + // CloudFront Function answered every beacon event, and the cache was + // never asked about any of them. + expect(rows[0]?.["hits"]).toBe("1"); + expect(rows[0]?.["misses"]).toBe("1"); + expect(Number(rows[0]?.["hit_percent"])).toBe(50); + }); +}); diff --git a/src/beacon-events.ts b/src/beacon-events.ts index 4e74ed8..ff4c497 100644 --- a/src/beacon-events.ts +++ b/src/beacon-events.ts @@ -36,6 +36,7 @@ // and a rollup reads the same parameters back as SQL. import { decodedParameter } from "./log-encoding.js"; +import { quoted } from "./sql-text.js"; /** * The path a beacon reports to, where a site chooses none. @@ -154,3 +155,23 @@ export const aBeaconEvent: readonly string[] = [ "cs_uri_query <> '-'", `${beaconVersionColumn} <> ''`, ]; + +/** + * The rows outside the beacon's path, as a condition for `rowsFor`. + * + * The other direction from {@link aBeaconEvent}, and it names the path that + * one leaves out. A question about beacon events narrows to the beacon + * through the request's own `paths`. A question about what the site answered + * has to take the beacon's requests back out, and `status-codes` is the one + * that does. + * + * Matched against the column as CloudFront delivered it, where `--path` + * decodes twice first. The path here is a constant this package chose and it + * carries nothing a browser or CloudFront escapes, so a record holds it as it + * was sent. An address somebody typed can hold anything. + * + * A prefix, the way every path match in Rainlytics is one. + */ +export const outsideTheBeaconPath = `strpos(cs_uri_stem, ${quoted( + defaultBeaconPath, +)}) <> 1`; diff --git a/src/index.ts b/src/index.ts index c4f657f..5abdb6e 100644 --- a/src/index.ts +++ b/src/index.ts @@ -82,6 +82,7 @@ export { beaconSchemaVersion, beaconVersionColumn, defaultBeaconPath, + outsideTheBeaconPath, } from "./beacon-events.js"; export { decodedColumn, decodedParameter } from "./log-encoding.js"; export { diff --git a/src/rollup-questions.ts b/src/rollup-questions.ts index 8538d66..1e98511 100644 --- a/src/rollup-questions.ts +++ b/src/rollup-questions.ts @@ -6,6 +6,7 @@ // rollup that filtered differently would answer a different question from // its neighbours without saying so. +import { defaultBeaconPath, outsideTheBeaconPath } from "./beacon-events.js"; import { qualifiedTableName } from "./dataset.js"; import { decodedColumn, decodedParameter } from "./log-encoding.js"; import { @@ -141,12 +142,22 @@ that only looks at pages. Automated traffic is left out by default here as it is everywhere else. Bots find the broken links first and in numbers, so \`--include-bots\` is usually -what you want when reading this one.`, +what you want when reading this one. + +Requests to the beacon's own path (\`${defaultBeaconPath}\`) are left out too, +and no option puts them back. The beacon writes one row per event, and a +single-page app sends several per reader per page. Those 204s can outnumber +every response the site itself served, and they carry one status between +them. The 404 this rollup exists to surface then sits somewhere below them. + +The beacon is Rainlytics measuring the site, and what the site answered is +the question here. \`rainlytics query\` counts the beacon's own rows for +anybody checking that it is delivering.`, body: (request) => [ "SELECT sc_status AS status, count(*) AS responses", ` FROM ${qualifiedTableName(request.dataset)}`, - rowsFor(request), + rowsFor(request, [outsideTheBeaconPath]), " GROUP BY 1", rankedOrder, limitOf(request), diff --git a/src/rollups.test.ts b/src/rollups.test.ts index 3b04c4e..e2846b5 100644 --- a/src/rollups.test.ts +++ b/src/rollups.test.ts @@ -3,6 +3,7 @@ import { describe, expect, it } from "vitest"; import { defaultLogDataset, qualifiedTableName } from "./dataset.js"; import { decodedParameter } from "./log-encoding.js"; +import { defaultBeaconPath, outsideTheBeaconPath } from "./beacon-events.js"; import { rollups } from "./rollup-questions.js"; import type { Rollup, RollupRequest } from "./rollups.js"; import { @@ -165,9 +166,11 @@ describe("the SQL a rollup runs", () => { // given, so the two arrive here as the same question. for (const sql of [sqlFor(name), sqlFor(name, { paths: [] })]) { // Then neither filter is written at all, rather than written as a - // condition matching everything. + // condition matching everything. `--path` matches the decoded + // address, which is what tells its prefix test from the one + // `status-codes` writes to leave the beacon out. expect(sql).not.toContain("x_host_header ="); - expect(sql).not.toContain("strpos("); + expect(sql).not.toContain("strpos(url_decode"); } }, ); @@ -247,7 +250,8 @@ describe("the SQL a rollup runs", () => { // Given the three rollups that read no path. // Then none of them decodes anything. The referrer is read for its host, // which is ASCII whatever the rest of the URL holds, and a status code - // and a result type carry no encoding at all. + // and a result type carry no encoding at all. The beacon's path that + // status-codes leaves out is matched undecoded for the same reason. expect(sqlFor("referrers")).not.toContain("url_decode"); expect(sqlFor("status-codes")).not.toContain("url_decode"); expect(sqlFor("cache-hit-ratio")).not.toContain("url_decode"); @@ -263,6 +267,17 @@ describe("the SQL a rollup runs", () => { expect(sql).toContain("cs_referer <> '-'"); }); + it("leaves the beacon's own requests out of the status codes", () => { + // Given the status-code rollup. + const sql = sqlFor("status-codes"); + + // Then a request to the beacon's path is not counted. The beacon writes + // one row per event, and a single-page app's 204s can outnumber every + // response the site itself served. + expect(sql).toContain(outsideTheBeaconPath); + expect(sql).toContain(`'${defaultBeaconPath}'`); + }); + it("counts the cache over the requests it had a say in", () => { // Given the cache hit ratio. const sql = sqlFor("cache-hit-ratio");