Cost.Mark() and Cost.StatementsSince(mark)

Summary#

osy test prints what each test sent to the database. Cost.Mark() lets a test measure ONE PART of itself — the action it is about, without its fixture and its setup — and hold a line on it:

var mark = Cost.Mark();
PlaceOrder(basket);
Assert.AtMost(40, Cost.StatementsSince(mark));

Signature#

string Cost.Mark()                       // a reading, now — a [Test] only
int    Cost.StatementsSince(string mark) // SQL statements sent since the mark
int    Cost.RoundTripsSince(string mark) // network exchanges (a batch of statements is one)
int    Cost.RowsReadSince(string mark)   // rows read from the database
int    Cost.RowsWrittenSince(string mark)// rows inserted, updated or deleted
int    Cost.RequestsSince(string mark)   // requests a page made for data or actions (see below)
int    Cost.ServerCallsSince(string mark)// of those, calls of a server function
int    Cost.AllocatedKbSince(string mark)// kilobytes the test's unit of work allocated
bool   Cost.OptimizedBuild               // the platform running the test is a release (optimised) build

Description#

A mark is a reading, the way a stopwatch's start is: take it in a statement of its own, run as many statements as the action needs — calls, loops, commits, Ui.* steps — and read the difference afterwards. The four numbers are the ones a plan's limits count, and the ones osy test prints beside each test, so a number asserted here is the number an app is metered by.

What is counted: everything the running test caused — its own reads and writes, the functions it calls, the workflows its commits start, and the requests of a page it drives with Ui.*.

Requests and server calls are what a page asks of the server, which is what a reader waits for over a network: Cost.RequestsSince counts the requests a page the test drives made for data or actions, and Cost.ServerCallsSince those of them that called a server function. Not counted: the page's document and its static files, anything fetched by its content hash (a browser keeps those, so they cost a first visit and no later one), the live-update connection, and the housekeeping a reader never waits for. So "this page opens in three requests" and "moving to the next ticket is one server call" are lines a test can hold.

A reading waits for the page to settle. While a test has a page open, Cost.Mark() and every Cost.*Since(mark) first wait until the page has nothing on the wire and nothing owed (no action, navigation, refetch or list render still to come) for a short quiet moment. An Assert.Visible passes as soon as the words are there, and a page often goes on working after that — a write that marks what you opened as read, the refetch it triggers — so a reading taken straight away would miss part of the step and count it in the next one. If the page never settles, the reading fails and names what was still running, rather than giving you a number taken half way.

Measure one more, not the first. The first time an action runs in a test it also pays for whatever is only paid once (a counter created, a workflow's first run). To hold a line on what the action costs a busy app, run it once before the mark.

A test settles background work at once that a deployed app queues, so a test's number is an upper bound on what the same action costs in production.

The same counter in production. A deployed application's Usage tab shows, for the month so far, what each page action, each page and each workflow cost — statements, rows read and written, and how many calls — beside the plan's allowance. Those figures come from the same counter as Cost.*, so a budget held here with Assert.AtMost is a line on the number the Usage tab shows. A page action's line is the whole click: every server function it calls and its commit. The one difference is the background work above: in production a workflow's later steps are counted on the workflow's own line, not on the action that started it.

Memory: Cost.AllocatedKbSince is what the work cost the garbage collector — kilobytes this test's unit of work allocated since the mark, read off the same allocation meter a deployed app is metered by. It is per test, so tests a suite runs side by side each read their own. The figure belongs to the BUILD of the platform running the test: a development (Debug) build allocates many times what a release build does for the same work — measured on one report, about thirty times.

Cost.OptimizedBuild says which build is running the test: true on a release build, the kind production runs, and false on a development one. It is read off the platform's own compiled code, so it is what the code actually runs as. Use it to hold a line on each build rather than one line loose enough for both:

Assert.AtMost(Cost.OptimizedBuild ? 15000 : 450000, Cost.AllocatedKbSince(mark));

The release number is the one that matches what production pays; the development one only says "did this get worse".

Cost.* is refused outside a running [Test].

Where the statements come from: osy test --cost. A number says how much; it does not say which line. Run the test you are asking about with --cost and its statements are listed under its result by the line that issued them, most first — the line to open, the line that called it, and what the platform was doing there:

$ osy test --filter placing_an_order_stays_cheap --cost
  ✓ placing_an_order_stays_cheap (212ms · 38 statements · 9 rows read · 14 written)
         31 × model/orders.osy:44  ‹ tests/orders.test.osy:9
                18  commit > autostart   (mostly UPDATE Osysharp.Workflow.WorkflowRun)
                 9  commit   (mostly INSERT OrderLine)
                 4  commit > audit.write   (mostly INSERT Osysharp.Observability.AuditEntry)
          5 × model/orders.osy:31  ‹ tests/orders.test.osy:9   SELECT Product
          2 × … on 2 more lines

One line of Osy# — a UnitOfWork.Commit() — can be most of what an action costs: the rule checks of every row it writes, the workflow runs those rows start, the audit rows it leaves. None of that is visible in the source, and this is where it is said. A line in a package you use is shown by the package's own path (Capabilities/<Package>/…). --json carries the same rows on each test's cost event, as lines.

Examples#

entity Parcel {
  [Required, MaxLength(40)] string Label;
  int Weight;
  security { allow read, create when IsAnonymous || IsAuthenticated; }
}

void Receive(string label, int weight) {
  new Parcel { Label = label, Weight = weight };
  UnitOfWork.Commit();
}

[Test]
void Receiving_a_parcel_stays_cheap() {
  Receive("warm-up", 1);                     // the first one pays what only the first pays

  var mark = Cost.Mark();
  Receive("north-7", 12);
  Assert.AtMost(10, Cost.StatementsSince(mark));
  Assert.Equal(1, Cost.RowsWrittenSince(mark));

  // Several statements between a mark and its reading: three more parcels, and reading them all back.
  var three = Cost.Mark();
  for (var i = 0; i < 3; i++) { Receive($"south-{i}", i); }
  var all = Parcel.Where(p => p.Weight >= 0).ToList();
  Assert.Equal(3, Cost.RowsWrittenSince(three));
  Assert.AtMost(40, Cost.StatementsSince(three));
  Assert.True(Cost.AllocatedKbSince(three) > 0);   // what the three cost the garbage collector, in KB
  // A release build allocates far less than a development one (here ~140 KB against ~780), so each holds its own line.
  Assert.AtMost(Cost.OptimizedBuild ? 400 : 2000, Cost.AllocatedKbSince(three));
  Assert.Equal(5, all.Count);
}

See also#

• Assert — Assert.AtMost and the other assertions
• Running tests — the per-test cost osy test prints
• [Test] / [TestFixture] — [Test]