FAIL: tests/services/log-rotation
=================================

+ shepherd --version
shepherd (GNU Shepherd) 1.0.5
Copyright (C) 2025 the Shepherd authors
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
+ herd --version
herd (GNU Shepherd) 1.0.5
Copyright (C) 2025 the Shepherd authors
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
+ socket=t-socket-2781150
+ conf=t-conf-2781150
+ log=t-log-2781150
+ pid=t-pid-2781150
+ service_log1=/build/shepherd-1.0.5/t-service-log1-2781150
+ service_log2=/build/shepherd-1.0.5/t-service-log2-2781150
+ service_log3=/build/shepherd-1.0.5/t-service-log3-2781150
+ external_log=/build/shepherd-1.0.5/t-service-extlog-2781150
+ invalid_external_log=/build/shepherd-1.0.5/t-service-invalid-extlog-2781150
+ herd='herd -s t-socket-2781150'
+ trap 'zcat t-log-2781150.* || true; cat t-log-2781150 || true;
      rm -f t-socket-2781150 t-conf-2781150 t-log-2781150* /build/shepherd-1.0.5/t-service-log1-2781150* /build/shepherd-1.0.5/t-service-log2-2781150* /build/shepherd-1.0.5/t-service-log3-2781150* /build/shepherd-1.0.5/t-service-extlog-2781150*;
      rmdir /build/shepherd-1.0.5/t-service-invalid-extlog-2781150;
      test -f t-pid-2781150 && kill `cat t-pid-2781150` || true; rm -f t-pid-2781150' EXIT
+ cat
+ rm -f t-pid-2781150
+ test -f t-pid-2781150
+ sleep 0.3
+ shepherd -I -s t-socket-2781150 -c t-conf-2781150 -l t-log-2781150 --pid=t-pid-2781150
GNU Shepherd 1.0.5 (Guile 3.0.10, x86_64-pc-linux-gnu)
Starting service root...
Service root started.
Service root running with value #<<process> id: 2781604 command: #f>.
Service root has been started.
Configuration successfully loaded from 't-conf-2781150'.
+ test -f t-pid-2781150
++ cat t-pid-2781150
+ shepherd_pid=2781604
+ herd -s t-socket-2781150 start one
Starting service one...
Service one has been started.
+ herd -s t-socket-2781150 start two
Starting service two...
Service two has been started.
+ herd -s t-socket-2781150 start log-rotation
Starting service log-rotation...
Service log-rotation started.
Service log-rotation running with value #<timer #<<calendar-event> seconds: (0) minutes: (0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59) hours: (0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23) days-of-month: (1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31) months: (6) days-of-week: (0 1 2 3 4 5 6)> #<procedure rotation ()> 7f239d58dea0>.
Service log-rotation has been started.
+ sleep 0.5
+ for file in "$service_log1" "$service_log2" "$external_log" "$invalid_external_log" "$log"
+ herd -s t-socket-2781150 files log-rotation
+ grep /build/shepherd-1.0.5/t-service-log1-2781150
/build/shepherd-1.0.5/t-service-log1-2781150	one
+ for file in "$service_log1" "$service_log2" "$external_log" "$invalid_external_log" "$log"
+ herd -s t-socket-2781150 files log-rotation
+ grep /build/shepherd-1.0.5/t-service-log2-2781150
/build/shepherd-1.0.5/t-service-log2-2781150	two
+ for file in "$service_log1" "$service_log2" "$external_log" "$invalid_external_log" "$log"
+ herd -s t-socket-2781150 files log-rotation
+ grep /build/shepherd-1.0.5/t-service-extlog-2781150
/build/shepherd-1.0.5/t-service-extlog-2781150	(external)
+ for file in "$service_log1" "$service_log2" "$external_log" "$invalid_external_log" "$log"
+ herd -s t-socket-2781150 files log-rotation
+ grep /build/shepherd-1.0.5/t-service-invalid-extlog-2781150
/build/shepherd-1.0.5/t-service-invalid-extlog-2781150	(external)
+ for file in "$service_log1" "$service_log2" "$external_log" "$invalid_external_log" "$log"
+ herd -s t-socket-2781150 files log-rotation
+ grep t-log-2781150
/build/shepherd-1.0.5/t-log-2781150	root
+ test -f /build/shepherd-1.0.5/t-service-log1-2781150
+ test -f /build/shepherd-1.0.5/t-service-log2-2781150
+ echo 'This is an external log file.'
+ mkdir /build/shepherd-1.0.5/t-service-invalid-extlog-2781150
+ herd -s t-socket-2781150 trigger log-rotation
Triggering timer.
+ grep 'Rotated ' t-log-2781150
+ sleep 0.5
Rotating '/build/shepherd-1.0.5/t-log-2781150' to '/build/shepherd-1.0.5/t-log-2781150.1'.
+ grep 'Rotated ' t-log-2781150
2025-07-06 20:02:58 Rotated '/build/shepherd-1.0.5/t-log-2781150'.
2025-07-06 20:02:58 Rotated '/build/shepherd-1.0.5/t-service-extlog-2781150'.
+ test -f /build/shepherd-1.0.5/t-service-log1-2781150
+ test -f /build/shepherd-1.0.5/t-service-log2-2781150
+ test -f t-log-2781150
+ test -f /build/shepherd-1.0.5/t-service-log1-2781150.1.gz
+ test -f t-log-2781150.1.gz
+ test -f /build/shepherd-1.0.5/t-service-log2-2781150.1.gz
+ test -f /build/shepherd-1.0.5/t-service-extlog-2781150.1.gz
+ gunzip
+ grep 'external log file'
This is an external log file.
+ test -f /build/shepherd-1.0.5/t-service-extlog-2781150
+ guile -c '(exit (zero? (stat:size (stat "/build/shepherd-1.0.5/t-service-extlog-2781150"))))'
+ zgrep 'Not rotating .*/build/shepherd-1.0.5/t-service-invalid-extlog-2781150' t-log-2781150 t-log-2781150.1.gz
t-log-2781150:2025-07-06 20:02:58 Not rotating '/build/shepherd-1.0.5/t-service-invalid-extlog-2781150', which is not a regular file.
+ herd -s t-socket-2781150 trigger log-rotation
Triggering timer.
+ test -f /build/shepherd-1.0.5/t-service-log1-2781150.2.gz
+ test -f /build/shepherd-1.0.5/t-service-log1-2781150.1.gz
+ sleep 0.5
Rotating '/build/shepherd-1.0.5/t-log-2781150' to '/build/shepherd-1.0.5/t-log-2781150.1'.
+ test -f /build/shepherd-1.0.5/t-service-log1-2781150.1.gz
+ test -f t-log-2781150.2.gz
+ test -f /build/shepherd-1.0.5/t-service-log1-2781150
+ test -f /build/shepherd-1.0.5/t-service-log2-2781150.1.gz
+ touch -d 2017-10-01 /build/shepherd-1.0.5/t-service-log1-2781150.2.gz
+ test -s /build/shepherd-1.0.5/t-service-log1-2781150
+ herd -s t-socket-2781150 trigger log-rotation
Triggering timer.
+ zgrep 'Deleting .*/build/shepherd-1.0.5/t-service-log1-2781150.2.gz' t-log-2781150 t-log-2781150.1.gz t-log-2781150.2.gz
t-log-2781150:2025-07-06 20:02:59 Deleting old log file '/build/shepherd-1.0.5/t-service-log1-2781150.2.gz'.
Rotating '/build/shepherd-1.0.5/t-log-2781150' to '/build/shepherd-1.0.5/t-log-2781150.1'.
+ test -f /build/shepherd-1.0.5/t-service-log1-2781150.2.gz
+ test -f /build/shepherd-1.0.5/t-service-log1-2781150.1.gz
+ test -f /build/shepherd-1.0.5/t-service-log1-2781150.3.gz
++ file_descriptor_count
++ ls -l /proc/2781604/fd/
total 0
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:02 0 -> /dev/null
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 1 -> /build/shepherd-1.0.5/tests/services/log-rotation.log
lrwx------ 1 pbuilder pbuilder 64 Jul  6 20:02 10 -> anon_inode:[signalfd]
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 11 -> pipe:[143612]
lrwx------ 1 pbuilder pbuilder 64 Jul  6 20:02 12 -> anon_inode:[eventpoll]
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 13 -> /build/shepherd-1.0.5/t-log-2781150
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 14 -> /build/shepherd-1.0.5/t-service-log1-2781150
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:02 15 -> pipe:[144392]
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:02 16 -> pipe:[141921]
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 17 -> /build/shepherd-1.0.5/t-service-log2-2781150
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:02 19 -> pipe:[105208]
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 2 -> /build/shepherd-1.0.5/tests/services/log-rotation.log
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:02 3 -> pipe:[139831]
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 4 -> pipe:[139831]
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:02 5 -> /build/shepherd-1.0.5/shepherd
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:02 6 -> pipe:[143610]
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 7 -> pipe:[143610]
lrwx------ 1 pbuilder pbuilder 64 Jul  6 20:02 8 -> socket:[143611]
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:02 9 -> pipe:[143612]
++ ls -l /proc/2781604/fd/0 /proc/2781604/fd/1 /proc/2781604/fd/10 /proc/2781604/fd/11 /proc/2781604/fd/12 /proc/2781604/fd/13 /proc/2781604/fd/14 /proc/2781604/fd/15 /proc/2781604/fd/16 /proc/2781604/fd/17 /proc/2781604/fd/19 /proc/2781604/fd/2 /proc/2781604/fd/3 /proc/2781604/fd/4 /proc/2781604/fd/5 /proc/2781604/fd/6 /proc/2781604/fd/7 /proc/2781604/fd/8 /proc/2781604/fd/9
++ wc -l
+ initial_fd_count=19
+ herd -s t-socket-2781150 start three
Service three has been started.
+ herd -s t-socket-2781150 trigger three
Triggering timer.
+ test -f /build/shepherd-1.0.5/t-service-log3-2781150
+ herd -s t-socket-2781150 status three
+ grep 'Child process'
+ herd -s t-socket-2781150 status three
+ grep 'Timer triggered from /build/shepherd-1.0.5'
  2025-07-06 20:02:59 Timer triggered from /build/shepherd-1.0.5.
+ herd -s t-socket-2781150 files log-rotation
+ grep /build/shepherd-1.0.5/t-service-log3-2781150
/build/shepherd-1.0.5/t-service-log3-2781150	three
+ herd -s t-socket-2781150 trigger log-rotation
Rotating '/build/shepherd-1.0.5/t-service-log3-2781150' to '/build/shepherd-1.0.5/t-service-log3-2781150.1'.
Triggering timer.
+ test -f /build/shepherd-1.0.5/t-service-log3-2781150.1.gz
+ sleep 0.2
Rotating '/build/shepherd-1.0.5/t-log-2781150' to '/build/shepherd-1.0.5/t-log-2781150.1'.
+ test -f /build/shepherd-1.0.5/t-service-log3-2781150.1.gz
+ herd -s t-socket-2781150 status three
Status of three:
  It is running since 20:02:59 (0 seconds ago).
  Timed service.
  Periodically running: sh -c "echo Timer triggered from $PWD."
  It is enabled.
  Provides: three
  Custom action: trigger
  Will not be respawned.
  Log file: /build/shepherd-1.0.5/t-service-log3-2781150

Recent runs:
  2025-07-06 20:02:59 Process exited successfully after 0 seconds.

Recent messages (use '-n' to view more or less):
  2025-07-06 20:02:59 Timer triggered from /build/shepherd-1.0.5.

Upcoming timer alarms:
  Tue Jan  6 20:03:00 2026 (in 184 days)
  Tue Jan  6 20:04:00 2026 (in 184 days)
  Tue Jan  6 20:05:00 2026 (in 184 days)
  Tue Jan  6 20:06:00 2026 (in 184 days)
  Tue Jan  6 20:07:00 2026 (in 184 days)
+ herd -s t-socket-2781150 status three
+ grep 'Timer triggered from /build/shepherd-1.0.5'
  2025-07-06 20:02:59 Timer triggered from /build/shepherd-1.0.5.
+ herd -s t-socket-2781150 trigger three
Triggering timer.
+ herd -s t-socket-2781150 trigger log-rotation
Rotating '/build/shepherd-1.0.5/t-service-log3-2781150' to '/build/shepherd-1.0.5/t-service-log3-2781150.1'.
Triggering timer.
+ test -f /build/shepherd-1.0.5/t-service-log3-2781150.2.gz
+ herd -s t-socket-2781150 status three
Rotating '/build/shepherd-1.0.5/t-log-2781150' to '/build/shepherd-1.0.5/t-log-2781150.1'.
Status of three:
  It is running since 20:02:59 (1 second ago).
  Timed service.
  Periodically running: sh -c "echo Timer triggered from $PWD."
  It is enabled.
  Provides: three
  Custom action: trigger
  Will not be respawned.
  Log file: /build/shepherd-1.0.5/t-service-log3-2781150

Recent runs:
  2025-07-06 20:02:59 Process exited successfully after 0 seconds.
  2025-07-06 20:03:00 Process exited successfully after 0 seconds.

Recent messages (use '-n' to view more or less):
  2025-07-06 20:03:00 Timer triggered from /build/shepherd-1.0.5.

Upcoming timer alarms:
  Tue Jan  6 20:04:00 2026 (in 184 days)
  Tue Jan  6 20:05:00 2026 (in 184 days)
  Tue Jan  6 20:06:00 2026 (in 184 days)
  Tue Jan  6 20:07:00 2026 (in 184 days)
  Tue Jan  6 20:08:00 2026 (in 184 days)
+ herd -s t-socket-2781150 stop three
++ file_descriptor_count
++ ls -l /proc/2781604/fd/
total 0
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:02 0 -> /dev/null
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 1 -> /build/shepherd-1.0.5/tests/services/log-rotation.log
lrwx------ 1 pbuilder pbuilder 64 Jul  6 20:02 10 -> anon_inode:[signalfd]
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 11 -> pipe:[143612]
lrwx------ 1 pbuilder pbuilder 64 Jul  6 20:02 12 -> anon_inode:[eventpoll]
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 13 -> /build/shepherd-1.0.5/t-log-2781150
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 14 -> /build/shepherd-1.0.5/t-service-log1-2781150
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:02 16 -> pipe:[141921]
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 17 -> /build/shepherd-1.0.5/t-service-log2-2781150
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:03 18 -> pipe:[139900]
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:02 19 -> pipe:[105208]
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 2 -> /build/shepherd-1.0.5/tests/services/log-rotation.log
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:03 20 -> pipe:[139900]
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:03 21 -> pipe:[124124]
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:03 22 -> pipe:[124124]
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:02 3 -> pipe:[139831]
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 4 -> pipe:[139831]
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:02 5 -> /build/shepherd-1.0.5/shepherd
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:02 6 -> pipe:[143610]
l-wx------ 1 pbuilder pbuilder 64 Jul  6 20:02 7 -> pipe:[143610]
lrwx------ 1 pbuilder pbuilder 64 Jul  6 20:02 8 -> socket:[143611]
lr-x------ 1 pbuilder pbuilder 64 Jul  6 20:02 9 -> pipe:[143612]
++ ls -l /proc/2781604/fd/0 /proc/2781604/fd/1 /proc/2781604/fd/10 /proc/2781604/fd/11 /proc/2781604/fd/12 /proc/2781604/fd/13 /proc/2781604/fd/14 /proc/2781604/fd/16 /proc/2781604/fd/17 /proc/2781604/fd/18 /proc/2781604/fd/19 /proc/2781604/fd/2 /proc/2781604/fd/20 /proc/2781604/fd/21 /proc/2781604/fd/22 /proc/2781604/fd/3 /proc/2781604/fd/4 /proc/2781604/fd/5 /proc/2781604/fd/6 /proc/2781604/fd/7 /proc/2781604/fd/8 /proc/2781604/fd/9
++ wc -l
+ test 22 -le 19
+ zcat t-log-2781150.1.gz t-log-2781150.2.gz t-log-2781150.3.gz t-log-2781150.4.gz t-log-2781150.5.gz
2025-07-06 20:02:59 Rotating '/build/shepherd-1.0.5/t-log-2781150' to '/build/shepherd-1.0.5/t-log-2781150.1'.
2025-07-06 20:02:59 Registering new logger for log-rotation.
2025-07-06 20:02:59 Rotated '/build/shepherd-1.0.5/t-log-2781150'.
2025-07-06 20:02:59 Not rotating '/build/shepherd-1.0.5/t-service-invalid-extlog-2781150', which is not a regular file.
2025-07-06 20:02:59 Not rotating '/build/shepherd-1.0.5/t-service-extlog-2781150', which is below the 0 B threshold.
2025-07-06 20:03:00 Triggering timer.
2025-07-06 20:03:00 Timer 'three' spawned process 2801243.
2025-07-06 20:03:00 Registering new logger for three.
2025-07-06 20:03:00 Process 2801243 of timer 'three' terminated with status 0 after 0 seconds.
2025-07-06 20:03:00 Triggering timer.
2025-07-06 20:03:00 Rotating '/build/shepherd-1.0.5/t-service-log3-2781150' to '/build/shepherd-1.0.5/t-service-log3-2781150.1'.
2025-07-06 20:03:00 Registering new logger for log-rotation.
2025-07-06 20:03:00 Rotated '/build/shepherd-1.0.5/t-service-log3-2781150'.
2025-07-06 20:03:00 Not rotating '/build/shepherd-1.0.5/t-service-log2-2781150', which is below the 0 B threshold.
2025-07-06 20:03:00 Rotating '/build/shepherd-1.0.5/t-service-log1-2781150' to '/build/shepherd-1.0.5/t-service-log1-2781150.1'.
2025-07-06 20:03:00 Registering new logger for log-rotation.
2025-07-06 20:03:00 Rotated '/build/shepherd-1.0.5/t-service-log1-2781150'.

2025-07-06 20:03:00 Rotating log.
2025-07-06 20:02:59 Rotating '/build/shepherd-1.0.5/t-log-2781150' to '/build/shepherd-1.0.5/t-log-2781150.1'.
2025-07-06 20:02:59 Registering new logger for log-rotation.
2025-07-06 20:02:59 Rotated '/build/shepherd-1.0.5/t-log-2781150'.
2025-07-06 20:02:59 Not rotating '/build/shepherd-1.0.5/t-service-invalid-extlog-2781150', which is not a regular file.
2025-07-06 20:02:59 Not rotating '/build/shepherd-1.0.5/t-service-extlog-2781150', which is below the 0 B threshold.
2025-07-06 20:02:59 Starting service three...
2025-07-06 20:02:59 Service three has been started.
2025-07-06 20:02:59 Service three started.
2025-07-06 20:02:59 Service three running with value #<timer #<<calendar-event> seconds: (0) minutes: (0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59) hours: (0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23) days-of-month: (1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31) months: (1) days-of-week: (0 1 2 3 4 5 6)> #<<command> arguments: ("sh" "-c" "echo Tim
2025-07-06 20:02:59 er triggered from $PWD.") user: #f group: #f supplementary-groups: () environment-variables: ("SHELL=/bin/bash" "SESSION_MANAGER=local/kaka:@/tmp/.ICE-unix/2302,unix/kaka:/tmp/.ICE-unix/2302" "QT_ACCESSIBILITY=1" "COLORTERM=truecolor" "DEB_HOST_ARCH_LIBC=gnu" "XDG_CONFIG_DIRS=/home/jas/.guix-home/profile/etc/xdg:/etc/xdg/xdg-gnome:/etc/xdg" "SSH_AGENT_LAUNCHER=gnome-keyring" "SUDO_GID=1000" "XDG_MENU_PREFIX=gnome-" "DDU_BUILD_DEBIAN_BOOKWORM_AMD64_STAGE0_POOL_GIT_TOKEN=glpat-KhpzkNzu1Lt5kxoRR7Y4" "DISTS_PUR
2025-07-06 20:02:59 EOS=/home/jas/src/dists/pureos" "GNOME_DESKTOP_SESSION_ID=this-is-deprecated" "DEB_TARGET_GNU_SYSTEM=linux-gnu" "DDU_BUILD_DEBIAN_BOOKWORM_AMD64_STAGE0_POOL_TRIGGER_TOKEN=glptt-1f76b69c2323931b05be6dabce858360b13d7487" "DPKG_ADMINDIR=/var/lib/dpkg" "PKG_CONFIG_PATH=/home/jas/.guix-profile/lib/pkgconfig:/home/jas/.guix-profile/share/pkgconfig:/home/jas/.guix-profile/lib/pkgconfig:/home/jas/.guix-profile/share/pkgconfig" "DEB_HOST_MULTIARCH=x86_64-linux-gnu" "CPPFLAGS_FOR_BUILD=-Wdate-time -D_FORTIFY_SOURCE=2
2025-07-06 20:02:59 " "OBJCXXFLAGS_FOR_BUILD=-g -O2 -ffile-prefix-map=/build/shepherd-1.0.5=. -fstack-protector-strong -fstack-clash-protection -Wformat -Werror=format-security -fcf-protection" "LDFLAGS_FOR_BUILD=-Wl,-z,relro -Wl,-z,now" "DEB_TARGET_ARCH_CPU=amd64" "DDU_BUILD_DEBIAN_TRIXIE_ARM64_STAGE0_PIPELINE_TRIGGER_TOKEN=glptt-99b6eac82b98e014608e3020957fa23028403252" "SSH_AUTH_SOCK=/run/user/1000/gnupg/S.gpg-agent.ssh" "DDU_BUILD_DEBIAN_BOOKWORM_AMD64_STAGE0_GIT_TOKEN=glpat-HzLL_JrxeDWiTu4rzvy4" "XDG_DATA_HOME=/home/jas/.
2025-07-06 20:02:59 local/share" "GBP_PBUILDER_DIST=debian_latest" "DH_INTERNAL_OVERRIDE=dh_auto_test" "DDU_BUILD_DEBIAN_BOOKWORM_ARM64_STAGE0_PIPELINE_PROJECT=69100903" "PBUILDER_PKGLIBDIR=/usr/lib/pbuilder" "COWDANCER_REUSE=yes" "TEST_LOGS=tests/services/log-rotation.log" "XCURSOR_PATH=/home/jas/.guix-home/profile/share/icons:" "DEBFULLNAME=Simon Josefsson" "SUDO_COMMAND=/usr/sbin/cowbuilder --build --buildresult /home/jas/dpkg --debbuildopts  --debbuildopts  --source-only-changes --basepath /var/cache/pbuilder/base-debian_l
2025-07-06 20:02:59 atest.cow ../shepherd_1.0.5-1.dsc" "XMODIFIERS=@im=ibus" "DESKTOP_SESSION=gnome" "SUDO_USER=jas" "DEB_TARGET_ARCH_BITS=64" "EDITOR=nano" "FFLAGS=-g -O2 -ffile-prefix-map=/build/shepherd-1.0.5=. -fstack-protector-strong -fstack-clash-protection -fcf-protection" "PBUILDER_SYSCONFDIR=/etc" "DISTS_GNUINOS=/home/jas/src/dists/gnuinos" "DDU_BUILD_DEBIAN_BOOKWORM_AMD64_STAGE0_PIPELINE_TRIGGER_TOKEN=glptt-e3369473d1e749f15bd6ed9078f133ad13ea5737" "GTK_MODULES=gail:atk-bridge" "PWD=/build/shepherd-1.0.5" "DEB_BUILD_
2025-07-06 20:02:59 MULTIARCH=x86_64-linux-gnu" "SOURCE_DATE_EPOCH=1751527360" "LOGNAME=pbuilder" "XDG_SESSION_DESKTOP=gnome" "XDG_SESSION_TYPE=wayland" "DEB_HOST_GNU_SYSTEM=linux-gnu" "CCACHE_DIR=/var/cache/pbuilder/ccache" "DEB_RULES_REQUIRES_ROOT=no" "CFLAGS_FOR_BUILD=-g -O2 -Werror=implicit-function-declaration -ffile-prefix-map=/build/shepherd-1.0.5=. -fstack-protector-strong -fstack-clash-protection -Wformat -Werror=format-security -fcf-protection" "MANPATH=/home/jas/.guix-home/profile/share/man:" "DEB_BUILD_ARCH_BITS=64
2025-07-06 20:02:59 " "SYSTEMD_EXEC_PID=2327" "DDU_BUILD_DEBIAN_BOOKWORM_AMD64_STAGE0_BUILD_PIPELINE_TRIGGER_TOKEN=glptt-c0716a7cd5d7e0f64d2a4aaa175be73629c04870" "GUILE_LOAD_PATH=/build/shepherd-1.0.5/modules:/build/shepherd-1.0.5/modules:" "CXXFLAGS=-g -O2 -ffile-prefix-map=/build/shepherd-1.0.5=. -fstack-protector-strong -fstack-clash-protection -Wformat -Werror=format-security -fcf-protection" "DEB_BUILD_ARCH_OS=linux" "XAUTHORITY=/run/user/1000/.mutter-Xwaylandauth.XKD682" "DISTS_DEVUAN=/home/jas/src/dists/devuan" "DDU_BU
2025-07-06 20:02:59 ILD_DEBIAN_TRIXIE_AMD64_STAGE0_PIPELINE_TRIGGER_TOKEN=glptt-afb3c982190007b086a8627a95f87bc2301a43dd" "ASFLAGS_FOR_BUILD=" "LD_PRELOAD=" "DDU_BUILD_DEBIAN_TRIXIE_AMD64_STAGE0_PIPELINE_PROJECT=69108031" "DDU_ARCHIVES_DEBIAN_STAGE0_BOOKWORM_AMD64_TRIGGER_TOKEN=glptt-603e27e96c6c5e9bc914092c87d2f67683844310" "GIT_EXEC_PATH=/home/jas/.guix-home/profile/libexec/git-core" "LDFLAGS=-Wl,-z,relro -Wl,-z,now" "DDU_BUILD_DEBIAN_BOOKWORM_AMD64_STAGE0_PIPELINE_PROJECT=69099423" "HOME=/nonexistent" "USERNAME=jas" "COWDAN
2025-07-06 20:02:59 CER_ILISTFILE=/.ilist" "IM_CONFIG_PHASE=1" "DDU_BUILD_DEBIAN_BOOKWORM_ARM64_STAGE0_PIPELINE_TRIGGER_TOKEN=glptt-8f7a7e2e95acbf781a1af27682b77039dc83a162" "GIT_SSL_CAINFO=/home/jas/.guix-profile/etc/ssl/certs/ca-certificates.crt" "LANG=C" "DEB_HOST_ARCH_ABI=base" "LS_COLORS=rs=0:di=01;34:ln=01;36:mh=00:pi=40;33:so=01;35:do=01;35:bd=40;33;01:cd=40;33;01:or=40;31;01:mi=00:su=37;41:sg=30;43:ca=00:tw=30;42:ow=34;42:st=37;44:ex=01;32:*.tar=01;31:*.tgz=01;31:*.arc=01;31:*.arj=01;31:*.taz=01;31:*.lha=01;31:*.lz4=01
2025-07-06 20:02:59 ;31:*.lzh=01;31:*.lzma=01;31:*.tlz=01;31:*.txz=01;31:*.tzo=01;31:*.t7z=01;31:*.zip=01;31:*.z=01;31:*.dz=01;31:*.gz=01;31:*.lrz=01;31:*.lz=01;31:*.lzo=01;31:*.xz=01;31:*.zst=01;31:*.tzst=01;31:*.bz2=01;31:*.bz=01;31:*.tbz=01;31:*.tbz2=01;31:*.tz=01;31:*.deb=01;31:*.rpm=01;31:*.jar=01;31:*.war=01;31:*.ear=01;31:*.sar=01;31:*.rar=01;31:*.alz=01;31:*.ace=01;31:*.zoo=01;31:*.cpio=01;31:*.7z=01;31:*.rz=01;31:*.cab=01;31:*.wim=01;31:*.swm=01;31:*.dwm=01;31:*.esd=01;31:*.avif=01;35:*.jpg=01;35:*.jpeg=01;35:*.mjpg=0
2025-07-06 20:02:59 1;35:*.mjpeg=01;35:*.gif=01;35:*.bmp=01;35:*.pbm=01;35:*.pgm=01;35:*.ppm=01;35:*.tga=01;35:*.xbm=01;35:*.xpm=01;35:*.tif=01;35:*.tiff=01;35:*.png=01;35:*.svg=01;35:*.svgz=01;35:*.mng=01;35:*.pcx=01;35:*.mov=01;35:*.mpg=01;35:*.mpeg=01;35:*.m2v=01;35:*.mkv=01;35:*.webm=01;35:*.webp=01;35:*.ogm=01;35:*.mp4=01;35:*.m4v=01;35:*.mp4v=01;35:*.vob=01;35:*.qt=01;35:*.nuv=01;35:*.wmv=01;35:*.asf=01;35:*.rm=01;35:*.rmvb=01;35:*.flc=01;35:*.avi=01;35:*.fli=01;35:*.flv=01;35:*.gl=01;35:*.dl=01;35:*.xcf=01;35:*.xwd=01;3
2025-07-06 20:02:59 5:*.yuv=01;35:*.cgm=01;35:*.emf=01;35:*.ogv=01;35:*.ogx=01;35:*.aac=00;36:*.au=00;36:*.flac=00;36:*.m4a=00;36:*.mid=00;36:*.midi=00;36:*.mka=00;36:*.mp3=00;36:*.mpc=00;36:*.ogg=00;36:*.ra=00;36:*.wav=00;36:*.oga=00;36:*.opus=00;36:*.spx=00;36:*.xspf=00;36:*~=00;90:*#=00;90:*.bak=00;90:*.old=00;90:*.orig=00;90:*.part=00;90:*.rej=00;90:*.swp=00;90:*.tmp=00;90:*.dpkg-dist=00;90:*.dpkg-old=00;90:*.ucf-dist=00;90:*.ucf-new=00;90:*.ucf-old=00;90:*.rpmnew=00;90:*.rpmorig=00;90:*.rpmsave=00;90:" "XDG_CURRENT_DESKTO
2025-07-06 20:02:59 P=GNOME" "srcdir=." "VTE_VERSION=6800" "GIT_PBUILDER_OPTIONS=--source-only-changes" "DEB_TARGET_ARCH_LIBC=gnu" "DEB_TARGET_GNU_TYPE=x86_64-linux-gnu" "WAYLAND_DISPLAY=wayland-0" "SSL_CERT_DIR=/home/jas/.guix-profile/etc/ssl/certs" "BUILDRESULTGID=1000" "DEB_TARGET_ARCH_ABI=base" "DEBEMAIL=simon@josefsson.org" "DDU_BUILD_TRIXIE_AMD64_TRIGGER_TOKEN=glptt-2a3e7330e1058e0277bd9059ca81a4e345d4b0c5" "GNOME_TERMINAL_SCREEN=/org/gnome/Terminal/screen/362e78af_0476_4b94_a421_1f9b387c96e6" "CPPFLAGS=-Wdate-time -D_FO
2025-07-06 20:02:59 RTIFY_SOURCE=2" "OBJCFLAGS_FOR_BUILD=-g -O2 -ffile-prefix-map=/build/shepherd-1.0.5=. -fstack-protector-strong -fstack-clash-protection -Wformat -Werror=format-security -fcf-protection" "DDU_BUILD_SCRATCH_ACCESS_TOKEN=glpat-1Xa2gjzbxdcGb_2WWiaS" "GUILE_LOAD_COMPILED_PATH=/build/shepherd-1.0.5/modules:/build/shepherd-1.0.5/modules:" "DEB_TARGET_ARCH=amd64" "DEB_BUILD_ARCH=amd64" "GUILE=/usr/bin/guile-3.0" "DOTNET_BUNDLE_EXTRACT_BASE_DIR=/home/jas/.cache/dotnet_bundle_extract" "PBCURRENTCOMMANDLINEOPERATION=b
2025-07-06 20:02:59 uild" "PBUILDER_PKGDATADIR=/usr/share/pbuilder" "DEB_TARGET_ARCH_OS=linux" "MFLAGS=" "XDG_CACHE_HOME=/home/jas/.cache" "PBUILDER_OPERATION=build" "INFOPATH=/home/jas/.guix-home/profile/share/info:/home/jas/.guix-profile/share/info:/home/jas/.guix-profile/share/info:/home/jas/.config/guix/current/share/info:" "GNOME_SETUP_DISPLAY=:1" "DDU_BUILD_BOOKWORM_ARM64_TRIGGER_TOKEN=glptt-56595017909976c40a98bdc789a725e6a6c3e11f" "FCFLAGS=-g -O2 -ffile-prefix-map=/build/shepherd-1.0.5=. -fstack-protector-strong -fstac
2025-07-06 20:02:59 k-clash-protection -fcf-protection" "XDG_SESSION_CLASS=user" "MAKEFLAGS= -- TEST_LOGS=tests/services/log-rotation.log VERBOSE=1 TESTS=tests/services/log-rotation.sh" "TERM=xterm-256color" "DEB_TARGET_MULTIARCH=x86_64-linux-gnu" "FCFLAGS_FOR_BUILD=-g -O2 -ffile-prefix-map=/build/shepherd-1.0.5=. -fstack-protector-strong -fstack-clash-protection -fcf-protection" "DEB_BUILD_ARCH_CPU=amd64" "DEB_BUILD_ARCH_LIBC=gnu" "OBJCFLAGS=-g -O2 -ffile-prefix-map=/build/shepherd-1.0.5=. -fstack-protector-strong -fstack-cla
2025-07-06 20:02:59 sh-protection -Wformat -Werror=format-security -fcf-protection" "ACLOCAL_PATH=/home/jas/.guix-profile/share/aclocal:/home/jas/.guix-profile/share/aclocal" "LIBVIRT_DEFAULT_URI=qemu:///system" "USER=pbuilder" "GBP_BUILD_DIR=/home/jas/dpkg/shepherd" "CURL_CA_BUNDLE=/home/jas/.guix-profile/etc/ssl/certs/ca-certificates.crt" "DEB_HOST_ARCH_BITS=64" "GNOME_TERMINAL_SERVICE=:1.91" "FFLAGS_FOR_BUILD=-g -O2 -ffile-prefix-map=/build/shepherd-1.0.5=. -fstack-protector-strong -fstack-clash-protection -fcf-protection" 
2025-07-06 20:02:59 "DEB_BUILD_GNU_TYPE=x86_64-linux-gnu" "CXXFLAGS_FOR_BUILD=-g -O2 -ffile-prefix-map=/build/shepherd-1.0.5=. -fstack-protector-strong -fstack-clash-protection -Wformat -Werror=format-security -fcf-protection" "DEB_BUILD_OPTIONS=parallel=16" "SHLVL=7" "GUIX_LOCPATH=/home/jas/.guix-home/profile/lib/locale:/home/jas/.guix-profile/lib/locale" "MAKELEVEL=7" "DEB_BUILD_GNU_SYSTEM=linux-gnu" "DH_INTERNAL_OPTIONS=" "QT_IM_MODULE=ibus" "LC_MESSAGES=C" "DFLAGS_FOR_BUILD=-frelease" "DEB_BUILD_MAINT_OPTIONS=hardening=+bi
2025-07-06 20:02:59 ndnow" "DEB_TARGET_GNU_CPU=x86_64" "BUILDRESULTUID=1000" "DEB_TARGET_ARCH_ENDIAN=little" "DEB_HOST_ARCH=amd64" "XDG_STATE_HOME=/home/jas/.local/state" "GUIX_PROFILE=/home/jas/.guix-profile" "DDU_BUILD_DEBIAN_BOOKWORM_ARM64_STAGE0_GIT_TOKEN=glpat-X5P7zy3H9u7QPXesxJSh" "DEB_HOST_ARCH_ENDIAN=little" "XDG_RUNTIME_DIR=/run/user/1000" "SSL_CERT_FILE=/home/jas/.guix-profile/etc/ssl/certs/ca-certificates.crt" "DEB_HOST_GNU_TYPE=x86_64-linux-gnu" "DDU_BUILD_DEBIAN_TRIXIE_ARM64_STAGE0_PIPELINE_PROJECT=69108209" "LC_A
2025-07-06 20:02:59 LL=C" "DISTS_DEBIAN=/home/jas/src/dists/debian" "DISTS_UBUNTU=/home/jas/src/dists/ubuntu" "XDG_DATA_DIRS=/home/jas/.guix-home/profile/share:/home/jas/.guix-profile/share:/usr/share/gnome:/usr/local/share/:/usr/share/" "ICECAT_SYSTEM_DIR=/home/jas/.guix-home/profile/lib/icecat" "CONFIG_SITE=/home/jas/moln/dot-files/config.site" "PATH=/build/shepherd-1.0.5:/usr/lib/ccache:/usr/sbin:/usr/bin:/sbin:/bin" "DEB_BUILD_ARCH_ENDIAN=little" "DEB_HOST_ARCH_CPU=amd64" "DDU_ARCHIVES_DEBIAN_STAGE0_BOOKWORM_AMD64_GIT_TOKE
2025-07-06 20:02:59 N=glpat-xtGhb85bTtLgXqHyohEB" "CC=gcc" "GDMSESSION=gnome" "TESTS=tests/services/log-rotation.sh" "CFLAGS=-g -O2 -Werror=implicit-function-declaration -ffile-prefix-map=/build/shepherd-1.0.5=. -fstack-protector-strong -fstack-clash-protection -Wformat -Werror=format-security -fcf-protection" "SUDO_UID=1000" "DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus" "DDU_BUILD_BOOKWORM_AMD64_TRIGGER_TOKEN=glptt-4d6dfa0a133b0d35bb3b7640b6d48f554bd3b868" "OBJCXXFLAGS=-g -O2 -ffile-prefix-map=/build/shepherd-1.0.5=
2025-07-06 20:02:59 . -fstack-protector-strong -fstack-clash-protection -Wformat -Werror=format-security -fcf-protection" "PASSWORD_STORE_DIR=/home/jas/moln/password-store/" "EMACSLOADPATH=/home/jas/.guix-profile/share/emacs/site-lisp:/home/jas/.guix-profile/share/emacs/site-lisp" "GBP_PBUILDER_OPTIONS=--source-only-changes" "DFLAGS=-frelease" "DISTS_TRISQUEL=/home/jas/src/dists/trisquel" "DEB_HOST_GNU_CPU=x86_64" "DEB_HOST_ARCH_OS=linux" "DEB_BUILD_GNU_CPU=x86_64" "DEBIAN_FRONTEND=noninteractive" "DEB_BUILD_ARCH_ABI=base" "DH
2025-07-06 20:02:59 _INTERNAL_BUILDFLAGS=1" "OLDPWD=/" "VERBOSE=1" "ASFLAGS=" "_=/build/shepherd-1.0.5/shepherd") directory: "/build/shepherd-1.0.5" resource-limits: ()> 7f23948ff0c0>.
2025-07-06 20:02:59 Triggering timer.
2025-07-06 20:02:59 Timer 'three' spawned process 2797970.
2025-07-06 20:02:59 Process 2797970 of timer 'three' terminated with status 0 after 0 seconds.
2025-07-06 20:02:59 /build/shepherd-1.0.5/t-service-log3-2781150	three
2025-07-06 20:02:59 /build/shepherd-1.0.5/t-service-log2-2781150	two
2025-07-06 20:02:59 /build/shepherd-1.0.5/t-service-log1-2781150	one
2025-07-06 20:02:59 /build/shepherd-1.0.5/t-log-2781150	root
2025-07-06 20:02:59 /build/shepherd-1.0.5/t-service-invalid-extlog-2781150	(external)
2025-07-06 20:02:59 /build/shepherd-1.0.5/t-service-extlog-2781150	(external)
2025-07-06 20:02:59 Triggering timer.
2025-07-06 20:02:59 Rotating '/build/shepherd-1.0.5/t-service-log3-2781150' to '/build/shepherd-1.0.5/t-service-log3-2781150.1'.
2025-07-06 20:02:59 Registering new logger for log-rotation.
2025-07-06 20:02:59 Rotated '/build/shepherd-1.0.5/t-service-log3-2781150'.
2025-07-06 20:02:59 Not rotating '/build/shepherd-1.0.5/t-service-log2-2781150', which is below the 0 B threshold.
2025-07-06 20:02:59 Rotating '/build/shepherd-1.0.5/t-service-log1-2781150' to '/build/shepherd-1.0.5/t-service-log1-2781150.1'.
2025-07-06 20:02:59 Registering new logger for log-rotation.
2025-07-06 20:02:59 Rotated '/build/shepherd-1.0.5/t-service-log1-2781150'.

2025-07-06 20:02:59 Rotating log.
2025-07-06 20:02:58 Rotating '/build/shepherd-1.0.5/t-log-2781150' to '/build/shepherd-1.0.5/t-log-2781150.1'.
2025-07-06 20:02:58 Registering new logger for log-rotation.
2025-07-06 20:02:58 Rotated '/build/shepherd-1.0.5/t-log-2781150'.
2025-07-06 20:02:58 Not rotating '/build/shepherd-1.0.5/t-service-invalid-extlog-2781150', which is not a regular file.
2025-07-06 20:02:58 Not rotating '/build/shepherd-1.0.5/t-service-extlog-2781150', which is below the 0 B threshold.
2025-07-06 20:02:59 Triggering timer.
2025-07-06 20:02:59 Not rotating '/build/shepherd-1.0.5/t-service-log2-2781150', which is below the 0 B threshold.
2025-07-06 20:02:59 Deleting old log file '/build/shepherd-1.0.5/t-service-log1-2781150.2.gz'.
2025-07-06 20:02:59 Rotating '/build/shepherd-1.0.5/t-service-log1-2781150' to '/build/shepherd-1.0.5/t-service-log1-2781150.1'.
2025-07-06 20:02:59 Registering new logger for log-rotation.
2025-07-06 20:02:59 Rotated '/build/shepherd-1.0.5/t-service-log1-2781150'.

2025-07-06 20:02:59 Rotating log.
2025-07-06 20:02:58 Rotating '/build/shepherd-1.0.5/t-log-2781150' to '/build/shepherd-1.0.5/t-log-2781150.1'.
2025-07-06 20:02:58 Registering new logger for log-rotation.
2025-07-06 20:02:58 Rotated '/build/shepherd-1.0.5/t-log-2781150'.
2025-07-06 20:02:58 Not rotating '/build/shepherd-1.0.5/t-service-invalid-extlog-2781150', which is not a regular file.
2025-07-06 20:02:58 Registering new logger for log-rotation.
2025-07-06 20:02:58 Rotated '/build/shepherd-1.0.5/t-service-extlog-2781150'.
2025-07-06 20:02:58 Triggering timer.
2025-07-06 20:02:58 Not rotating '/build/shepherd-1.0.5/t-service-log2-2781150', which is below the 0 B threshold.
2025-07-06 20:02:58 Rotating '/build/shepherd-1.0.5/t-service-log1-2781150' to '/build/shepherd-1.0.5/t-service-log1-2781150.1'.
2025-07-06 20:02:58 Registering new logger for log-rotation.
2025-07-06 20:02:58 Rotated '/build/shepherd-1.0.5/t-service-log1-2781150'.

2025-07-06 20:02:58 Rotating log.
2025-07-06 20:02:57 GNU Shepherd 1.0.5 (Guile 3.0.10, x86_64-pc-linux-gnu)
2025-07-06 20:02:57 Starting service root...
2025-07-06 20:02:57 Service root started.
2025-07-06 20:02:57 Service root running with value #<<process> id: 2781604 command: #f>.
2025-07-06 20:02:57 Service root has been started.
2025-07-06 20:02:57 Configuration successfully loaded from 't-conf-2781150'.
2025-07-06 20:02:57 Starting service one...
2025-07-06 20:02:57 Service one has been started.
2025-07-06 20:02:57 Service one started.
2025-07-06 20:02:57 Service one running with value #<<process> id: 2784212 command: ("/bin/bash" "-c" "while true; do echo logging things; sleep 0.2; done")>.
2025-07-06 20:02:57 Starting service two...
2025-07-06 20:02:57 Service two has been started.
2025-07-06 20:02:57 Service two started.
2025-07-06 20:02:57 Service two running with value #<<process> id: 2784406 command: ("sleep" "600")>.
2025-07-06 20:02:57 Starting service log-rotation...
2025-07-06 20:02:57 Service log-rotation started.
2025-07-06 20:02:57 Service log-rotation running with value #<timer #<<calendar-event> seconds: (0) minutes: (0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59) hours: (0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23) days-of-month: (1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31) months: (6) days-of-week: (0 1 2 3 4 5 6)> #<procedure rotation ()> 7f239d58dea
2025-07-06 20:02:57 0>.
2025-07-06 20:02:57 Service log-rotation has been started.
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-log2-2781150	two
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-log1-2781150	one
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-log-2781150	root
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-invalid-extlog-2781150	(external)
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-extlog-2781150	(external)
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-log2-2781150	two
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-log1-2781150	one
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-log-2781150	root
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-invalid-extlog-2781150	(external)
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-extlog-2781150	(external)
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-log2-2781150	two
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-log1-2781150	one
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-log-2781150	root
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-invalid-extlog-2781150	(external)
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-extlog-2781150	(external)
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-log2-2781150	two
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-log1-2781150	one
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-log-2781150	root
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-invalid-extlog-2781150	(external)
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-extlog-2781150	(external)
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-log2-2781150	two
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-log1-2781150	one
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-log-2781150	root
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-invalid-extlog-2781150	(external)
2025-07-06 20:02:58 /build/shepherd-1.0.5/t-service-extlog-2781150	(external)
2025-07-06 20:02:58 Triggering timer.
2025-07-06 20:02:58 Not rotating '/build/shepherd-1.0.5/t-service-log2-2781150', which is below the 0 B threshold.
2025-07-06 20:02:58 Rotating '/build/shepherd-1.0.5/t-service-log1-2781150' to '/build/shepherd-1.0.5/t-service-log1-2781150.1'.
2025-07-06 20:02:58 Rotated '/build/shepherd-1.0.5/t-service-log1-2781150'.

2025-07-06 20:02:58 Rotating log.
+ cat t-log-2781150
2025-07-06 20:03:00 Rotating '/build/shepherd-1.0.5/t-log-2781150' to '/build/shepherd-1.0.5/t-log-2781150.1'.
2025-07-06 20:03:00 Registering new logger for log-rotation.
2025-07-06 20:03:00 Rotated '/build/shepherd-1.0.5/t-log-2781150'.
2025-07-06 20:03:00 Not rotating '/build/shepherd-1.0.5/t-service-invalid-extlog-2781150', which is not a regular file.
2025-07-06 20:03:00 Not rotating '/build/shepherd-1.0.5/t-service-extlog-2781150', which is below the 0 B threshold.
2025-07-06 20:03:00 Stopping service three...
2025-07-06 20:03:00 Terminating timer 'three' with 0 processes running.
2025-07-06 20:03:00 Service three stopped.
2025-07-06 20:03:00 Service three is now stopped.
+ rm -f t-socket-2781150 t-conf-2781150 t-log-2781150 t-log-2781150.1.gz t-log-2781150.2.gz t-log-2781150.3.gz t-log-2781150.4.gz t-log-2781150.5.gz /build/shepherd-1.0.5/t-service-log1-2781150 /build/shepherd-1.0.5/t-service-log1-2781150.1.gz /build/shepherd-1.0.5/t-service-log1-2781150.2.gz /build/shepherd-1.0.5/t-service-log1-2781150.3.gz /build/shepherd-1.0.5/t-service-log1-2781150.4.gz /build/shepherd-1.0.5/t-service-log2-2781150 /build/shepherd-1.0.5/t-service-log3-2781150 /build/shepherd-1.0.5/t-service-log3-2781150.1.gz /build/shepherd-1.0.5/t-service-log3-2781150.2.gz /build/shepherd-1.0.5/t-service-extlog-2781150 /build/shepherd-1.0.5/t-service-extlog-2781150.1.gz
+ rmdir /build/shepherd-1.0.5/t-service-invalid-extlog-2781150
+ test -f t-pid-2781150
++ cat t-pid-2781150
+ kill 2781604
+ rm -f t-pid-2781150
Stopping service root...
Exiting shepherd...
FAIL tests/services/log-rotation.sh (exit status: 1)
Service three is not running.
Exiting.