Assertion `ticks_now == trace_ticks' failed to hold

This issue happens while replaying firefox under rr 4.2.0, rr 4.3.0 fails with a different error message which spew all the different register content.

I can reproduce this issue with some work-in-progress patches on top of firefox, which breaks the load/reload of pages ( https://github.com/nbp/gecko-dev/tree/bugzil.la/js-startup-cache/wip ). Note, firefox crashes quite easily after reloading pages, and I replayed one of these crashed process.

Here is the error message I got while replaying with rr -M replay -a (rr 4.2.0):

…
[rr 2172 113952][Child 2172] WARNING: No inner window available!: file /home/nicolas/mozilla/alternate-dev/dom/base/nsGlobalWindow.cpp, line 10026
[rr 2172 113955][Child 2172] WARNING: No inner window available!: file /home/nicolas/mozilla/alternate-dev/dom/base/nsGlobalWindow.cpp, line 10026
[rr 2172 115132]++DOMWINDOW == 2 (0x1822d10) [pid = 2172] [serial = 2] [outer = 0x173b200]
[FATAL /tmp/nix-build-rr-4.2.0.drv-0/rr-4.2.0-src/src/ReplaySession.cc:742:check_ticks_consistency() errno: 0 'Success'] 
 (task 3747 (rec:2091) at time 124280)
 -> Assertion `ticks_now == trace_ticks' failed to hold. ticks mismatch for 'SYSCALL: setsockopt'; expected 8318556, got 8318560
Launch gdb with
  gdb /home/nicolas/.local/share/rr/firefox-25/mmap_1_hardlink_firefox
and attach to the rr debug server with:
  target remote :3747

Looking at the result of rr dump -b -m -p command as suggested in the issue #1734 , and selecting some events above the one which has a matching global time, I obtain:

{
  real_time:1440395.696222 global_time:124273, event:`SCHED' tid:2084, ticks:4662502892
 rax:0x1 rbx:0x0 rcx:0x1da1e70 rdx:0x7f4ff2e48a70 rsi:0x1 rdi:0x1d75d38 rbp:0x7ffe0c93e890 rsp:0x7ffe0c93e870 r8:0x7ffe0c93e6a0 r9:0x7f4f78de87e0 r10:0x7ffe0c93e570 r11:0x60 r12:0
x4056e0 r13:0x7ffe0c941060 r14:0x0 r15:0x0 rip:0x7f4fe27fb8bc eflags:0x202 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f4ff2e48740 gs_base:0
x0
}
{
  real_time:1440395.696243 global_time:124274, event:`SYSCALL: poll' (state:EXITING_SYSCALL) tid:2091, ticks:8287405
 rax:0x1 rbx:0x1d8 rcx:0xffffffffffffffff rdx:0xffffffffffffffff rsi:0x4 rdi:0x7f4fd18761f0 rbp:0x7f4fd1876000 rsp:0x7f4fd23751b8 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x7f4fd237548
0 r13:0xffffffff r14:0x4 r15:0x7f4fd23752d8 rip:0x7000000b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x7 fs_base:0x7f4fd2376700 gs_base:0x0
  { addr:0x7f4fd18761e0, length:0x8 }
  { addr:0x7f4fd18761f0, length:0x20 }
}
{
  real_time:1440395.696246 global_time:124275, event:`SYSCALLBUF_ABORT_COMMIT' tid:2091, ticks:8287405
}
{
  real_time:1440395.696526 global_time:124276, event:`SYSCALL: rrcall_notify_syscall_hook_exit' (state:ENTERING_SYSCALL) tid:2091, ticks:8287415
 rax:0xffffffffffffffda rbx:0x7f4fd18761f0 rcx:0xffffffffffffffff rdx:0xffffffff rsi:0x4 rdi:0x7f4fd2375480 rbp:0x20 rsp:0x7f4fd23751e8 r8:0x0 r9:0x0 r10:0x2 r11:0x246 r12:0x7f4fd
2375480 r13:0x70000009 r14:0x4 r15:0x7f4fd23752d8 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x1bc fs_base:0x7f4fd2376700 gs_base:0x0
}
{
  real_time:1440395.696529 global_time:124277, event:`SYSCALLBUF_RESET' tid:2091, ticks:8287415
}
{
  real_time:1440395.696569 global_time:124278, event:`SYSCALL: rrcall_notify_syscall_hook_exit' (state:EXITING_SYSCALL) tid:2091, ticks:8287415
 rax:0x1 rbx:0x7f4fd18761f0 rcx:0xffffffffffffffff rdx:0xffffffff rsi:0x4 rdi:0x7f4fd2375480 rbp:0x20 rsp:0x7f4fd23751e8 r8:0x0 r9:0x0 r10:0x2 r11:0x246 r12:0x7f4fd2375480 r13:0x7
0000009 r14:0x4 r15:0x7f4fd23752d8 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x7 fs_base:0x7f4fd2376700 gs_base:0x0
  { addr:0x7f4fd1876005, length:0x1 }
}
{
  real_time:1440395.697022 global_time:124279, event:`SYSCALLBUF_FLUSH' tid:2091, ticks:8318556
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'read', ret:0x1, size:0x11 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'poll', ret:0x1, size:0x30 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'gettimeofday', ret:0x0, size:0x20 }
  { syscall:'gettimeofday', ret:0x0, size:0x20 }
  { syscall:'futex', ret:0x1, size:0x18 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'clock_gettime', ret:0x0, size:0x20 }
  { syscall:'recvfrom', ret:0x5, size:0x15 }
  { syscall:'recvfrom', ret:0x39, size:0x49 }
}
{
  real_time:1440395.697027 global_time:124280, event:`SYSCALL: setsockopt' (state:ENTERING_SYSCALL) tid:2091, ticks:8318556
 rax:0xffffffffffffffda rbx:0x36 rcx:0xffffffffffffffff rdx:0x4 rsi:0x6 rdi:0x30 rbp:0x7f4fd2375250 rsp:0x7f4fd2374fb0 r8:0x4 r9:0xd1 r10:0x7f4fd2375238 r11:0x246 r12:0x0 r13:0x7ffe0c93ce3f r14:0x3 r15:0x7f4fd23750b0 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x36 fs_base:0x7f4fd2376700 gs_base:0x0
}

Reproduce the failure with rr -M replay -a using the Firefox trace described, then inspect ReplaySession.cc around check_ticks_consistency() and the rr dump -b -m -p output near global times 124273–124280. Compare the recorded and replayed tick values for the setsockopt event; done means the trace replays without the tick-mismatch assertion.