intermittent failure in 'meter timestamps' test

[warner]

@turadg observed an intermittent CI failure of the meter timestamps test:

https://github.com/Agoric/agoric-sdk/blob/master/packages/xsnap/test/test-xs-perf.js#L69

This test takes two separate event lists (one from the kernel side, one from the worker side), each naturally ordered by their timestamps, then concatenates the two lists, then sorts by timestamp, then compares to the expected total order. The timestamps are coming from the same time source (the host OS clock).

The problem is that the timestamps have only microsecond precision. If the computer runs fast enough, then you might get multiple events for the same microsecond, and the sort won't tell you the correct total order (even an insertion sort of the two initially-sorted lists won't get the interleaving correct).

So if this persists, we should either find a way to improve the precision, or relax the test to inspect the two lists separately.

One reason I check the merged list instead of doing them separately was to make it clear what the overall sequence was supposed to be:

  const expected = [
    'kern send delivery',
    '    worker rx delivery',
    '    worker tx syscall 1',
    'kern receive syscall 1',
    'kern send syscall-result 1',
    '    worker rx syscall-result 1',
    '    worker tx syscall 2',
    'kern receive syscall 2',
    'kern send syscall-result 2',
    '    worker rx syscall-result 2',
    '    worker tx delivery-result',
    'kern receive deliver-result',
  ];

The kern messages are coming from one list, the worker messages from the other, but the total ordering shows that every syscall request is paired with a kernel receipt, every syscall result send is paired with a worker receipt, and the delivery/deliver-result messages have similar pairs.

[turadg]

Other instances,

• Aug 1: https://github.com/Agoric/agoric-sdk/runs/7623298006?check_suite_focus=true#step:6:282
• Aug 24: https://github.com/Agoric/agoric-sdk/runs/8000450000?check_suite_focus=true