shepherd hangs when date goes backwards #105

civodul commented 2026年02月03日 17:57:21 +01:00

Live from the Guix Days — @group experienced and reported a bug that has an easy reproducer: take a VM like guix system vm gnu/system/examples/bare-bones.tmpl, run date -s to move the clock backwards by a few hours, and notice that herd status doesn’t respond.

straceing shows that clients are accepted, requests are read, but then nothing happens. Also, services whose associated process is terminated are not restarted.

This is sort of the converse of #92.

To be continued...

Live from the Guix Days — @group experienced and reported a bug that has an easy reproducer: take a VM like `guix system vm gnu/system/examples/bare-bones.tmpl`, run `date -s` to move the clock backwards by a few hours, and notice that `herd status` doesn’t respond. `strace`ing shows that clients are `accept`ed, requests are read, but then nothing happens. Also, services whose associated process is terminated are not restarted. This is sort of the converse of #92. To be continued...

stund commented 2026年02月03日 21:29:43 +01:00

Could be a side effect of a negative time value, perhaps?

guile/fibers#89 (comment)

Could be a side effect of a negative time value, perhaps? https://codeberg.org/guile/fibers/issues/89#issuecomment-9246248

group commented 2026年02月03日 21:30:30 +01:00

From the strace, I noticed the problem happens, epoll_wait runs with a excessively large non-zero timeout:

[pid 1] 19:53:34.876892 epoll_wait(12 <unfinished ...>
[pid 1] 19:48:39.000046 epoll_wait(12, [{events=EPOLLIN, data=0x8}], 8, 126843) = 1
[pid 1] 19:48:39.017196 epoll_wait(12, [], 8, 26420) = 0
[pid 1] 19:49:05.446980 epoll_wait(12, [{events=EPOLLIN, data=0x8}], 8, 100396) = 1
[pid 1] 19:49:28.066643 epoll_wait(12, [{events=EPOLLIN, data=0x8}], 8, 77776) = 1
[pid 1] 19:49:37.110527 epoll_wait(12, [{events=EPOLLIN, data=0x8}], 8, 68732) = 1
[pid 1] 19:49:49.952007 epoll_wait(12, [{events=EPOLLIN, data=0x8}], 8, 55891) = 1
[pid 1] 19:50:12.488891 epoll_wait(12, [], 8, 33354) = 0
[pid 1] 19:50:47.112726 epoll_wait(12 <unfinished ...>
[pid 1] 19:50:47.112749 epoll_wait(12 <unfinished ...>

epoll invokes get-internal-run-time:

❯ guile
GNU Guile 3.0.10-1.402e0df
Copyright (C) 1995-2024 Free Software Foundation, Inc.
Guile comes with ABSOLUTELY NO WARRANTY; for details type `,show w'.
This program is free software, and you are welcome to redistribute it
under certain conditions; type `,show c' for details.
Enter `,help' for help.
@scheme@(guile-user)> (get-internal-real-time )
1ドル = 1870388861
@scheme@(guile-user)> (get-internal-real-time )
2ドル = 2996037899
@scheme@(guile-user)> (get-internal-real-time )
3ドル = 3850935924
@scheme@(guile-user)> (get-internal-real-time )
4ドル = 21114397250

After flipping clock backwards by 5':

@scheme@(guile-user)> (get-internal-real-time )
5ドル = -275065221680
@scheme@(guile-user)> (get-internal-real-time )
6ドル = -269979934651
@scheme@(guile-user)> (get-internal-real-time )
7ドル = -269270429248
@scheme@(guile-user)> (get-internal-real-time )
8ドル = -268552595598
@scheme@(guile-user)> (get-internal-real-time )
9ドル = -268059022670
@scheme@(guile-user)> (get-internal-real-time )
10ドル = -267647318177
@scheme@(guile-user)> (get-internal-real-time )
11ドル = -267163099132

HTH

From the `strace`, I noticed the problem happens, `epoll_wait` runs with a excessively large non-zero timeout: ```text [pid 1] 19:53:34.876892 epoll_wait(12 <unfinished ...> [pid 1] 19:48:39.000046 epoll_wait(12, [{events=EPOLLIN, data=0x8}], 8, 126843) = 1 [pid 1] 19:48:39.017196 epoll_wait(12, [], 8, 26420) = 0 [pid 1] 19:49:05.446980 epoll_wait(12, [{events=EPOLLIN, data=0x8}], 8, 100396) = 1 [pid 1] 19:49:28.066643 epoll_wait(12, [{events=EPOLLIN, data=0x8}], 8, 77776) = 1 [pid 1] 19:49:37.110527 epoll_wait(12, [{events=EPOLLIN, data=0x8}], 8, 68732) = 1 [pid 1] 19:49:49.952007 epoll_wait(12, [{events=EPOLLIN, data=0x8}], 8, 55891) = 1 [pid 1] 19:50:12.488891 epoll_wait(12, [], 8, 33354) = 0 [pid 1] 19:50:47.112726 epoll_wait(12 <unfinished ...> [pid 1] 19:50:47.112749 epoll_wait(12 <unfinished ...> ``` `epoll` [invokes](https://codeberg.org/guile/fibers/src/branch/main/fibers/epoll.scm#L163) `get-internal-run-time`: ```text ❯ guile GNU Guile 3.0.10-1.402e0df Copyright (C) 1995-2024 Free Software Foundation, Inc. Guile comes with ABSOLUTELY NO WARRANTY; for details type `,show w'. This program is free software, and you are welcome to redistribute it under certain conditions; type `,show c' for details. Enter `,help' for help. @scheme@(guile-user)> (get-internal-real-time ) 1ドル = 1870388861 @scheme@(guile-user)> (get-internal-real-time ) 2ドル = 2996037899 @scheme@(guile-user)> (get-internal-real-time ) 3ドル = 3850935924 @scheme@(guile-user)> (get-internal-real-time ) 4ドル = 21114397250 ``` After flipping clock backwards by `5'`: ```text @scheme@(guile-user)> (get-internal-real-time ) 5ドル = -275065221680 @scheme@(guile-user)> (get-internal-real-time ) 6ドル = -269979934651 @scheme@(guile-user)> (get-internal-real-time ) 7ドル = -269270429248 @scheme@(guile-user)> (get-internal-real-time ) 8ドル = -268552595598 @scheme@(guile-user)> (get-internal-real-time ) 9ドル = -268059022670 @scheme@(guile-user)> (get-internal-real-time ) 10ドル = -267647318177 @scheme@(guile-user)> (get-internal-real-time ) 11ドル = -267163099132 ``` HTH

stund commented 2026年02月04日 01:02:26 +01:00

Yes indeed, @group.

If the now value is negative (and expiry positive), it'll effectively be added to the latter, producing a potentially large timeout value.

Yes indeed, @group. https://codeberg.org/guile/fibers/src/commit/258ad6fb482a6314dd9a6961c68600e20768a455/fibers/epoll.scm#L159-L166 If the `now` value is negative (and `expiry` positive), it'll effectively be _added_ to the latter, producing a potentially large timeout value.

civodul commented 2026年02月06日 18:22:47 +01:00

This is terrible.

This is terrible.

stund commented 2026年02月06日 21:51:42 +01:00

Of course, it wouldn't occur with a monotonic clock based Fibers.

Of course, it wouldn't occur with a monotonic clock based Fibers.

apteryx commented 2026年02月10日 07:07:06 +01:00

So is the underlying bug that Guile does not expose a true monotonic clock? See:

So is the underlying bug that Guile does not expose a true monotonic clock? See: https://codeberg.org/guile/guile/src/commit/d5e4ac8a5b80b1f752f39d1c66e7343d79c82d98/doc/ref/srfi-modules.texi#L2548

stund commented 2026年02月10日 21:23:05 +01:00

A monotonic time can be obtained from the POSIX clock_gettime function, as @civodul does in guile/fibers!166.

There's definitely a case to be made for implementing it in the Guile core, like get-internal-real-time (but without the latter's questionable behavior).

That Fibers PR, when (if?) merged, would prevent this issue, among others, but there is still a downstream impact on Shepherd (shepherd/shepherd!101) that needs to be sorted. I've made an attempt in shepherd/shepherd!104.

A monotonic time can be obtained from the POSIX `clock_gettime` function, as @civodul does in guile/fibers!166. There's definitely a case to be made for implementing it in the Guile core, like `get-internal-real-time` (but without the latter's questionable behavior). That Fibers PR, when (if?) merged, would prevent this issue, among others, but there is still a downstream impact on Shepherd (shepherd/shepherd!101) that needs to be sorted. I've made an attempt in shepherd/shepherd!104.