From debbugs-submit-bounces@debbugs.gnu.org Sun Feb 23 17:05:24 2025 Received: (at submit) by debbugs.gnu.org; 23 Feb 2025 22:05:24 +0000 Received: from localhost ([127.0.0.1]:37175 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1tmK6G-0001Zp-8P for submit@debbugs.gnu.org; Sun, 23 Feb 2025 17:05:24 -0500 Received: from lists.gnu.org ([2001:470:142::17]:49234) by debbugs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.84_2) (envelope-from <~@wolfsden.cz>) id 1tmK6E-0001ZW-6s for submit@debbugs.gnu.org; Sun, 23 Feb 2025 17:05:22 -0500 Received: from eggs.gnu.org ([2001:470:142:3::10]) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from <~@wolfsden.cz>) id 1tmK68-0007ZR-Or for bug-guix@gnu.org; Sun, 23 Feb 2025 17:05:16 -0500 Received: from wolfsden.cz ([37.205.8.62]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from <~@wolfsden.cz>) id 1tmK66-0003nQ-Bg for bug-guix@gnu.org; Sun, 23 Feb 2025 17:05:16 -0500 Received: by wolfsden.cz (Postfix, from userid 104) id EF6C434BBBA; Sun, 23 Feb 2025 22:05:09 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=wolfsden.cz; s=mail; t=1740348309; bh=iItQa61pSFev5N2XSnOe2lLjUWS5SaqXzhMnx9I99SU=; h=From:To:Subject:Date; b=PKLsenRl1IscJHJSNC9iA0RoGQtCGleGHDY3EHNlTZMuxXPiHbpCZfAO0/l5q9NVJ 3+4vXf2y3VswKKyWKL6e+FNPkUF6kkGR5g6TIPIyfx3odh+4Qo7uLxZzZeEReT1gUp FKEABQz2amz8i37icCajB28ewCMSVH5PWCQjC2rAv5iIoS0m1yZZHVYENeDarHDR25 QyiJjc64B1PeCXlD52VlDBrnP8f0t1QbnLgc+muJyvZSTGz9uu1SDvQJpXRTE3x9Hm Uc4hUi1usObZkhYKUzn77OEcURz5Y9VHJ+kOOkqBkql1NszROeIb8Gm7Db/oZMr0NW gtkfAL4w6E3CaZYkrgu6JoCPahsh6+Lf94Xwnc66JmgdDslZ3AFTdv/4Pus6ar+QUT YcSE23h1xFWdSTbLlMNI0elHTnTMPIQT0ZnxB7Zz+mixsU4sx1dkx33qZ5HpLuwIjh PqFUzzJKrY0G0NMM68yBJsV4YdpOrcosDdHNEnZvNKQ/QPfFsiQX3e5ac/SWvWqmb1 4noL4VlPrd9YYG8jakLQ3qM7OHs3GWLAsggvEa31eTgxUWDh1j8kkYkHZ8vtyZRhvf 1AYxWvHW8QXuVr5grlbZGQj8RCUTtkIyMeesnxUppDCo4wRBOmvjJGv/B+1aJ9C5iP ytrBlsEczjk9H4FyfxwopOa0= X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on wolfsden X-Spam-Level: X-Spam-Status: No, score=-3.1 required=5.0 tests=ALL_TRUSTED,BAYES_00, DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,URIBL_BLOCKED autolearn=ham autolearn_force=no version=3.4.6 Received: from localhost (unknown [128.0.188.242]) by wolfsden.cz (Postfix) with ESMTPSA id 11BB934C9BF for ; Sun, 23 Feb 2025 22:05:09 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=wolfsden.cz; s=mail; t=1740348309; bh=iItQa61pSFev5N2XSnOe2lLjUWS5SaqXzhMnx9I99SU=; h=From:To:Subject:Date; b=PKLsenRl1IscJHJSNC9iA0RoGQtCGleGHDY3EHNlTZMuxXPiHbpCZfAO0/l5q9NVJ 3+4vXf2y3VswKKyWKL6e+FNPkUF6kkGR5g6TIPIyfx3odh+4Qo7uLxZzZeEReT1gUp FKEABQz2amz8i37icCajB28ewCMSVH5PWCQjC2rAv5iIoS0m1yZZHVYENeDarHDR25 QyiJjc64B1PeCXlD52VlDBrnP8f0t1QbnLgc+muJyvZSTGz9uu1SDvQJpXRTE3x9Hm Uc4hUi1usObZkhYKUzn77OEcURz5Y9VHJ+kOOkqBkql1NszROeIb8Gm7Db/oZMr0NW gtkfAL4w6E3CaZYkrgu6JoCPahsh6+Lf94Xwnc66JmgdDslZ3AFTdv/4Pus6ar+QUT YcSE23h1xFWdSTbLlMNI0elHTnTMPIQT0ZnxB7Zz+mixsU4sx1dkx33qZ5HpLuwIjh PqFUzzJKrY0G0NMM68yBJsV4YdpOrcosDdHNEnZvNKQ/QPfFsiQX3e5ac/SWvWqmb1 4noL4VlPrd9YYG8jakLQ3qM7OHs3GWLAsggvEa31eTgxUWDh1j8kkYkHZ8vtyZRhvf 1AYxWvHW8QXuVr5grlbZGQj8RCUTtkIyMeesnxUppDCo4wRBOmvjJGv/B+1aJ9C5iP ytrBlsEczjk9H4FyfxwopOa0= From: Tomas Volf <~@wolfsden.cz> To: bug-guix@gnu.org Subject: [shepherd] Timer not executed Date: Sun, 23 Feb 2025 23:05:08 +0100 Message-ID: <87y0xw1fmz.fsf@wolfsden.cz> User-Agent: Gnus/5.13 (Gnus v5.13) MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" Received-SPF: pass client-ip=37.205.8.62; envelope-from=~@wolfsden.cz; helo=wolfsden.cz X-Spam_score_int: -20 X-Spam_score: -2.1 X-Spam_bar: -- X-Spam_report: (-2.1 / 5.0 requ) BAYES_00=-1.9, DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1, RCVD_IN_VALIDITY_RPBL_BLOCKED=0.001, RCVD_IN_VALIDITY_SAFE_BLOCKED=0.001, SPF_HELO_PASS=-0.001, SPF_PASS=-0.001 autolearn=ham autolearn_force=no X-Spam_action: no action X-Spam-Score: 1.0 (+) X-Debbugs-Envelope-To: submit X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -0.0 (/) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Hi, I might have find a bug in shepherd timers. I have a timer scheduled to run every 24 hours, the definition is as follow: =2D-8<---------------cut here---------------start------------->8--- (define %kerberos-log-in-refresh-service (let ((name 'kerberos-log-in-refresh)) (simple-service name home-shepherd-service-type (list (shepherd-service (documentation "Refresh the kerberos ticket.") (provision (list name)) (requirement '(kerberos-reachable?)) (start #~(make-timer-constructor (calendar-event #:hours '(12) #:minutes '(0)) (command (list #$%kerberos-log-in)))) (stop #~(make-timer-destructor)) (modules (cons '(shepherd service timer) %default-modules)) (actions (list (shepherd-action (name 'trigger) (documentation "Immediately refresh the ticket.= ") (procedure #~trigger-timer))))))))) =2D-8<---------------cut here---------------end--------------->8--- This should run every 24 hours (at noon) and execute the %kerberos-log-in script (simple guile program that authenticates against kerberos). However that did not happen. Here are the logs: =2D-8<---------------cut here---------------start------------->8--- 2025-02-22 19:17:00 Service kerberos-log-in running with value #< = id: 730 command: ("/gnu/store/8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log-in")= >. 2025-02-22 19:17:00 [8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log-in] 2025-02-22 19:17:00 [8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log-in] 2025-02-22 19:17:00 [8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log-in] 2025-02-22 19:17:00 [8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log-in] 2025-02-23 12:00:02 Waiting anew for timer 'kerberos-log-in-refresh' (resum= ing from sleep state?). 2025-02-23 22:00:01 Not rotating '/home//.local/state/shepherd/db= us.log', which is below the 8192 B threshold. =2D-8<---------------cut here---------------end--------------->8--- The ones from 19:17:00 are from 'kerberos-log-in service, which is one-shot executed upon login. That went fine. However the 'kerberos-log-in-refresh is only at 12:00:02, and only as "Waiting anew ...". The message indicates that the computer might be resuming from sleep, however that was not the case here. It is a desktop machine, and it was left running over night. Here is herd status: =2D-8<---------------cut here---------------start------------->8--- $ herd status kerberos-log-in-refresh =E2=97=8F Status of kerberos-log-in-refresh: It is running since Sat 22 Feb 2025 07:17:00 PM CET (28 hours ago). Timed service. Periodically running: /gnu/store/8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log= -in It is enabled. Provides: kerberos-log-in-refresh Requires: kerberos-reachable? Custom action: trigger Will be respawned. Upcoming timer alarms: Mon 24 Feb 2025 12:00:00 PM CET (in 13 hours) Tue 25 Feb 2025 12:00:00 PM CET (in 37 hours) Wed 26 Feb 2025 12:00:00 PM CET (in 3 days) Thu 27 Feb 2025 12:00:00 PM CET (in 4 days) Fri 28 Feb 2025 12:00:00 PM CET (in 5 days) =2D-8<---------------cut here---------------end--------------->8--- Have a nice day, Tomas =2D-=20 There are only two hard things in Computer Science: cache invalidation, naming things and off-by-one errors. --=-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQJCBAEBCgAsFiEEt4NJs4wUfTYpiGikL7/ufbZ/wakFAme7m5QOHH5Ad29sZnNk ZW4uY3oACgkQL7/ufbZ/wakYBQ/+K15AMkG2pgFPzykw3IaxyZTs0WYDaYgJwgw2 WQ9LrN0zit3qp3V3TaCPxjx33Lo3oiYeMpm4RsCz6MbuKkpPESZjeNp0Ei/dP2Ju m6oDV5xLbfrknxzOSmtguCCOLvFmGmmout33df6Mg2gfBEBKfNBZlRYZHQgiK12E szCSQ5QHLbV75BJfie0N+92B3XKUYDO006e1giVVNV4nhM/qxf+aPc5ezZkXtmAn t2jd6d+UCptiBhVx5TGSEACJXWg9zl9Rvac0MhXEOSKPXtaYCKwb7wbjO1jI3gAg nk53vs1s5Q9iGZE5agHlzTkwwDS8BgTBzZ7mv9nLaKF7MRIhf+5ey4P943l0goXa mfsuY7ccDpAFh028C69OBIogMswzJ24IRsIlKyxxSLRq65iKzLBfcoNsx+8uSjUV KgBuhCiAIM96KDn8KfRTFZ6WoveWln/khtRtQYFPkQRCQTHbY3PLhv/PO+Wp+Ars QAnxbhB7u1VbG8/pz/DktY4A30fguevwxf2WFYEPYh0QPvFn6+VTiFHMhO2qhoqo A+apJzk8msbMzLGmUXDl0F4n6lya3Qlq7KPRCEImtWE722s/fc8yeNxJkPfh+iTl ylOMQayzgeMamBabSAyEfWNSjBG+KzzBfxgdwqT+1i6JJVCB3H0nRdYe0U5cLXqk mrBZuGY= =RcTh -----END PGP SIGNATURE----- --=-=-=-- From debbugs-submit-bounces@debbugs.gnu.org Mon Feb 24 11:22:32 2025 Received: (at 76516) by debbugs.gnu.org; 24 Feb 2025 16:22:32 +0000 Received: from localhost ([127.0.0.1]:42128 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1tmbE0-0006kn-7X for submit@debbugs.gnu.org; Mon, 24 Feb 2025 11:22:32 -0500 Received: from eggs.gnu.org ([2001:470:142:3::10]:42072) by debbugs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.84_2) (envelope-from ) id 1tmbDx-0006kT-J3 for 76516@debbugs.gnu.org; Mon, 24 Feb 2025 11:22:30 -0500 Received: from fencepost.gnu.org ([2001:470:142:3::e]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1tmbDr-0005V8-G4; Mon, 24 Feb 2025 11:22:23 -0500 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-Version:Date:References:In-Reply-To:Subject:To: From; bh=FlB93Uxtb9iagGgkR+ec+uYjghab33TIBajNLlwze2o=; b=l/7l7pyiEoHs2c4DtMvT 3raTijV9BXCQpdcNOpJHaOra6MES3nXMevfPaVyM1Wbq2nKRvCne67qpetP03aWQUZPk6U0/5W7Uo 9NFPClgHoa9UK+a1oksyebHVHPw4zYcEinHvawcsRw409M8W88szsC7V/RW5eCgRCQ7YfEPj8gOPR bBE4eG3nrcC3ExJ3lbXLjRrmCyXaRUIRjHZz1CQ1uRT/TKycK/LhvpxLE1XuZX9YSNwVAuWYm8gc8 eECak6VV//rQwgXgOoJ08HUAP1dco+njYQH8Mmigji0wSnP29s9+76un/OejI8x1/2C506cEdtt5Q Ra4W7xY71Wu1Nw==; From: =?utf-8?Q?Ludovic_Court=C3=A8s?= To: Tomas Volf <~@wolfsden.cz> Subject: Re: bug#76516: [shepherd] Timer not executed In-Reply-To: <87y0xw1fmz.fsf@wolfsden.cz> (Tomas Volf's message of "Sun, 23 Feb 2025 23:05:08 +0100") References: <87y0xw1fmz.fsf@wolfsden.cz> Date: Mon, 24 Feb 2025 17:22:19 +0100 Message-ID: <87cyf7tiro.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 76516 Cc: 76516@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) Hi Tomas, Tomas Volf <~@wolfsden.cz> skribis: > However that did not happen. Here are the logs: > > 2025-02-22 19:17:00 Service kerberos-log-in running with value #< id: 730 command: ("/gnu/store/8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log-in= ")>. > 2025-02-22 19:17:00 [8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log-in] > 2025-02-22 19:17:00 [8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log-in] > 2025-02-22 19:17:00 [8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log-in] > 2025-02-22 19:17:00 [8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log-in] > 2025-02-23 12:00:02 Waiting anew for timer 'kerberos-log-in-refresh' (res= uming from sleep state?). > 2025-02-23 22:00:01 Not rotating '/home//.local/state/shepherd/= dbus.log', which is below the 8192 B threshold. > > > The ones from 19:17:00 are from 'kerberos-log-in service, which is > one-shot executed upon login. That went fine. > > However the 'kerberos-log-in-refresh is only at 12:00:02, and only as > "Waiting anew ...". The message indicates that the computer might be > resuming from sleep, however that was not the case here. It is a > desktop machine, and it was left running over night. What architecture is this on? >From the excerpt above, the =E2=80=98log-rotation=E2=80=99 timer did fire a= s expected. Did it also have =E2=80=9CWaiting anew=E2=80=9D messages? Ludo=E2=80=99. From debbugs-submit-bounces@debbugs.gnu.org Mon Feb 24 11:27:14 2025 Received: (at 76516) by debbugs.gnu.org; 24 Feb 2025 16:27:14 +0000 Received: from localhost ([127.0.0.1]:42185 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1tmbIX-00071i-Uw for submit@debbugs.gnu.org; Mon, 24 Feb 2025 11:27:14 -0500 Received: from eggs.gnu.org ([2001:470:142:3::10]:51464) by debbugs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.84_2) (envelope-from ) id 1tmbIV-00071Q-Kk for 76516@debbugs.gnu.org; Mon, 24 Feb 2025 11:27:12 -0500 Received: from fencepost.gnu.org ([2001:470:142:3::e]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1tmbIP-0006JV-Kv; Mon, 24 Feb 2025 11:27:05 -0500 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-Version:Date:References:In-Reply-To:Subject:To: From; bh=SyQuZE2ULthQZNOve4Q16uDLW23VldEsBEc1TGs8EdE=; b=QNpcJQD/CBrKN//6yU/s +Eh3kRiSYjlNBWG8eJp6XMPksnLbkcyvrieXL9cMjWFN2rPLZX7vGVjP4EWOoyv8+Dti4O+/fPDE9 n7E66aUCWcdhN14Yzle/Bmy11bTLwwrrm3KN4RtCk2YRBK7YXbhneZ5GEg/U5m9lJReenSbfyknnC B4dA9y/2ZEQUb+aP2x2gRA2VZ0lIgWcCeYci2t7QpitF/PAO9KMVnbAyzttSa2k/jA9ZPshUKL9I2 bJ4xqLDjB1CAh5Da/O7nUV1fqn9Hulaa5wTl2e9XzkIGauoh4plOVqXewBSbvnm7rMfRu9/odB9mR jt5Z34Egss2paw==; From: =?utf-8?Q?Ludovic_Court=C3=A8s?= To: Tomas Volf <~@wolfsden.cz> Subject: Re: bug#76516: [shepherd] Timer not executed In-Reply-To: <87cyf7tiro.fsf@gnu.org> ("Ludovic =?utf-8?Q?Court=C3=A8s=22'?= =?utf-8?Q?s?= message of "Mon, 24 Feb 2025 17:22:19 +0100") References: <87y0xw1fmz.fsf@wolfsden.cz> <87cyf7tiro.fsf@gnu.org> Date: Mon, 24 Feb 2025 17:27:03 +0100 Message-ID: <874j0jtijs.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 76516 Cc: 76516@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) Ludovic Court=C3=A8s skribis: >> 2025-02-23 12:00:02 Waiting anew for timer 'kerberos-log-in-refresh' (re= suming from sleep state?). The =E2=80=9CWaiting anew=E2=80=9D message happens when the timer fires 2 s= econds or more later than expected (see =E2=80=98sleep-operation/check=E2=80=99), whi= ch is indeed the case here. It=E2=80=99s not supposed to happen normally. Before we bump that to 10 seconds, say, it would be good to understand why the timer got late here. Are there services that could block shepherd somehow, for instance by calling =E2=80=98waitpid=E2=80=99, or running computations at 12:00pm? Ludo=E2=80=99. From debbugs-submit-bounces@debbugs.gnu.org Mon Feb 24 14:06:40 2025 Received: (at 76516) by debbugs.gnu.org; 24 Feb 2025 19:06:40 +0000 Received: from localhost ([127.0.0.1]:42630 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1tmdmp-0001qR-PK for submit@debbugs.gnu.org; Mon, 24 Feb 2025 14:06:40 -0500 Received: from wolfsden.cz ([37.205.8.62]:40938) by debbugs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.84_2) (envelope-from <~@wolfsden.cz>) id 1tmdmm-0001qE-6m for 76516@debbugs.gnu.org; Mon, 24 Feb 2025 14:06:37 -0500 Received: by wolfsden.cz (Postfix, from userid 104) id 236EE28842B; Mon, 24 Feb 2025 19:06:34 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=wolfsden.cz; s=mail; t=1740423994; bh=SNIM3O1sq9Oxd/kEr88r6Jz3sF+jo/RmyERC5l6pQhA=; h=From:To:Cc:Subject:In-Reply-To:References:Date; b=hUonOkDpPu8zflQf4sQKR24T/TO1fTe3ano5GJmrzIl4rUWiqJYzDpQBjPRdD+01t tgI7vT5/C+Tv4ZbGb5lAcZ8gW662EiG+HY49v0BDf72nByCfnYECTX0A2IIXsa0rmp Lvo/27YUk3T/Sqgw5BQe9B44KpwGO+aQHD28AxvGhhDS0Jso/tmgdBcWk7CxMhD0m/ Yw2G5l6veK573tFdmTykuHDj6W18eO3UrMYSEC0G1uI+/T/I3eJX6zAfAso5MkmLQ3 82au7QbXGqybltaC8Z9mOrhRxMBiZo3fVLLEdCLcm6S5F8QYxIgfsu4IyQafk1wq4/ zoaSOfGsBHSfg9cdq5PoiHtgYeqCXRmxrsPLMhr7FlC7pwBP/K8J/Ltrgbb4eR8zIQ u4MeJk4mZrcDvVGqNaGiM7HlH7JKYsMyLD+Iq9pP7FtNqn2uMXyLyfPR+/HY8Ok00b IpqXAmJYyQgqZirKchgGdJjVfc57d4oemIUp65lYvh0jSojXmA0jYqKh5LwH6RDFdY oVy2Kkbo07zVyz9LZZFZ9DsUcgxrEkBs6MQMOaJfe31O8363Ru5glBERTnNUAcgrr/ 7BLwwWEc1hPMxBw+onqMefzSHJFzoK3W5ZKonj4K6sopx2VjW/8yKpEdumq9VQUrkZ GaB34UVoRvID4nS5MnrthCOY= X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on wolfsden X-Spam-Level: X-Spam-Status: No, score=-3.1 required=5.0 tests=ALL_TRUSTED,BAYES_00, DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,URIBL_BLOCKED autolearn=ham autolearn_force=no version=3.4.6 Received: from localhost (unknown [128.0.188.242]) by wolfsden.cz (Postfix) with ESMTPSA id 434BB34F4FA; Mon, 24 Feb 2025 19:06:33 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=wolfsden.cz; s=mail; t=1740423993; bh=SNIM3O1sq9Oxd/kEr88r6Jz3sF+jo/RmyERC5l6pQhA=; h=From:To:Cc:Subject:In-Reply-To:References:Date; b=wfRIzuVJxqXtQ6VSL7APlJpB5SCf4Qpp3asEFd5hTW+Y7C2MHMmYO8z7SOBNOc3jE 1ri7zmxmrfn93fY8zpHzhEKkkRBWUrKCNV7P1/6I70+jBxgSTtwPMq6uluIYkvJLvw Hv03Jc54ZpCbX1YBAqIMianRQNtvfNUcZDv282Fy1ZQrXk6EsvnkVNTqoDV9wc1slX oiHXIn9WQQQdYlqEePQQNdKdMPqL5srW+WrhRP8a4p6c1eHC3xltehjGRuGVbaK7m3 7/TGsdFWsN/58ifH7DW3bSn7mAikJVPdDt3pRNID0Nqz2CmMMi/tzPghG/Bd0/YRxP YxKXcsUsndDZxeED01Yy+tUjPDU3xUSf/TO/AaHAWlPO+2c05WSdMGlfvWEDW+abTy XHdRBjBi9PUkoac/uD6akqyyNHSkddpFej9iyPPcBNODQ5cgoH4osDxmrMMFvo+ss+ gjDaIh5ASfkW/00VDjDWDYwjZnmGgjTPN2USkgCrD5EfI850ZhAHXYPmm7N/w4Vhg7 zOxePKHF/8UnHG8ZwmIJ2OVFq0pJU2Fj0AvRD0BRGeN/W3hKGk3o24rTsPybwOdlDw whw11Z0d3eZZq5YPdQKga/1RGFemOkWoWkENoun+aQUYq+qvJNDCSZ2N8bh/tz9w+Y JxB6+a8VdlOENj83HbKy8/xw= From: Tomas Volf <~@wolfsden.cz> To: Ludovic =?utf-8?Q?Court=C3=A8s?= Subject: Re: bug#76516: [shepherd] Timer not executed In-Reply-To: <87cyf7tiro.fsf@gnu.org> ("Ludovic =?utf-8?Q?Court=C3=A8s=22'?= =?utf-8?Q?s?= message of "Mon, 24 Feb 2025 17:22:19 +0100") References: <87y0xw1fmz.fsf@wolfsden.cz> <87cyf7tiro.fsf@gnu.org> Date: Mon, 24 Feb 2025 20:06:33 +0100 Message-ID: <87o6yr17t2.fsf@wolfsden.cz> User-Agent: Gnus/5.13 (Gnus v5.13) MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" X-Spam-Score: 0.0 (/) X-Debbugs-Envelope-To: 76516 Cc: 76516@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -1.0 (-) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Ludovic Court=C3=A8s writes: > Hi Tomas, > > Tomas Volf <~@wolfsden.cz> skribis: > >> However that did not happen. Here are the logs: >> >> 2025-02-22 19:17:00 Service kerberos-log-in running with value #< id: 730 command: ("/gnu/store/8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log-i= n")>. >> 2025-02-22 19:17:00 [8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log-in] >> 2025-02-22 19:17:00 [8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log-in] >> 2025-02-22 19:17:00 [8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log-in] >> 2025-02-22 19:17:00 [8m21cnqnllk6g1kcgyj91i5h05s7c0c4-krb-log-in] >> 2025-02-23 12:00:02 Waiting anew for timer 'kerberos-log-in-refresh' (re= suming from sleep state?). >> 2025-02-23 22:00:01 Not rotating '/home//.local/state/shepherd= /dbus.log', which is below the 8192 B threshold. >> >> >> The ones from 19:17:00 are from 'kerberos-log-in service, which is >> one-shot executed upon login. That went fine. >> >> However the 'kerberos-log-in-refresh is only at 12:00:02, and only as >> "Waiting anew ...". The message indicates that the computer might be >> resuming from sleep, however that was not the case here. It is a >> desktop machine, and it was left running over night. > > What architecture is this on? x86_64-linux, AMD Ryzen 5 5600G with Radeon Graphics > > From the excerpt above, the =E2=80=98log-rotation=E2=80=99 timer did fire= as expected. > Did it also have =E2=80=9CWaiting anew=E2=80=9D messages? No, no such message. Actually, there are only 2 additional lines in the log file. So the following are the last 4 lines of the shepherd.log.1.zstd (you did already see the first 2 lines): =2D-8<---------------cut here---------------start------------->8--- 2025-02-23 12:00:02 Waiting anew for timer 'kerberos-log-in-refresh' (resum= ing from sleep state?). 2025-02-23 22:00:01 Not rotating '/home//.local/state/shepherd/db= us.log', which is below the 8192 B threshold. 2025-02-23 22:00:01 Rotating log. =2D-8<---------------cut here---------------end--------------->8--- The empty line is in the log, that is not a copy&paste error. The next log (shepherd.log) starts with: =2D-8<---------------cut here---------------start------------->8--- 2025-02-23 22:00:01 Rotating '/home//.local/state/shepherd/shephe= rd.log' to '/home//.local/state/shepherd/shepherd.log.1'. 2025-02-23 22:00:01 Rotated '/home//.local/state/shepherd/shepher= d.log'. =2D-8<---------------cut here---------------end--------------->8--- So there is not much indication what happened. Tomas =2D-=20 There are only two hard things in Computer Science: cache invalidation, naming things and off-by-one errors. --=-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQJCBAEBCgAsFiEEt4NJs4wUfTYpiGikL7/ufbZ/wakFAme8wzkOHH5Ad29sZnNk ZW4uY3oACgkQL7/ufbZ/wam8IQ//Z5vwd6+bijsT0k8rb1hJRKlpABudFG1eMJXN cePwzsnOq8r1CLvjRcDNXiILgze3QJ4rzjj6bljj24UR5OxrcKy2PitJPcjynCQ4 tH+ZZ3CH/brzdm9G35/n37jW3EnIjj2NAwZuqr/kWiK5vj4yU2o+fkmJkNAjxrBz euO56+/VX3bjkKSyrzXmzMOykkaC+dk0BsPbIbQXWeSfrk2crJOblbpNgblaJhlJ 41/+hXn7QRmuiGB4oU0puLEVH4CKJrvA0IFYFErkO5IMwMWG2E0ceuAREdg3rCO9 RK4XlPo4rpnuSeZeBGbpqUkRrDATf/Jv79ehDavMzuCBP47xJLx4nrf17S4Liy1/ rKbD48DxF3DU+16DFA9lfge17beR9c5UUFh9DoGBvFRUpCSBc6C86dG3IzSK7iyI 5bchXIrJ2IfYYuMJukU9M0QzuWWLNRzCFlc+DAYUzWkVHsvNR86P/NYJApMFFukk CV7Rzaaw2YGz6QMoxY5uY0ReafRxANWBAYS3TlUxGTgxPWbnlLKzA0/+gIBQ7YT4 Tj5EpRW48ict2cGr2eVyGyxkpsYnKf+1MHOkeF+uXJs+iiYK0Y8nXLZnFAPDjpZo m23c5b6vO8TUdlbGgQTTuuBKXBcBq1u1WKQoNrS0x3hjvcrlR8VWEJEcokdjHMnf 6AoMk7E= =a6aS -----END PGP SIGNATURE----- --=-=-=-- From debbugs-submit-bounces@debbugs.gnu.org Mon Feb 24 14:24:49 2025 Received: (at 76516) by debbugs.gnu.org; 24 Feb 2025 19:24:49 +0000 Received: from localhost ([127.0.0.1]:42709 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1tme4O-0005kh-Ua for submit@debbugs.gnu.org; Mon, 24 Feb 2025 14:24:49 -0500 Received: from wolfsden.cz ([37.205.8.62]:48592) by debbugs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.84_2) (envelope-from <~@wolfsden.cz>) id 1tme4L-0005kU-21 for 76516@debbugs.gnu.org; Mon, 24 Feb 2025 14:24:46 -0500 Received: by wolfsden.cz (Postfix, from userid 104) id B6DD9289388; Mon, 24 Feb 2025 19:24:43 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=wolfsden.cz; s=mail; t=1740425083; bh=Q5clPHfcdN1FjwaeAH7xm+XAXdhEtFUh05gpYe53DXo=; h=From:To:Cc:Subject:In-Reply-To:References:Date; b=SWAqPpBv9ikKL/dTeMou9iDvqFJ+RtLNANksYp4z02Psi4usKr5GrhmnzUD9yFpvM QuoAOP8M0z8uzo/UV9WvY7chk+AYzTjgN8tJKf7CsNNXeXmJAZujgRd95KYJSRLK6I y5377Kr7Vx7r8tGxH0rrJsLt3WEkIXfduqYXlWXudOlxbZIoUWQlA1jjOU3uMFIm6/ EkfGxsbUTvn4zmRRMrg9x82Yy8WSZm9Y7e0XlmkalMjDQCABjCYzAu5TJPjEDnn12l fIu8ditvtO57p/fDetpWSuZFWWnR/eTRdYkq0SJhdJD/hiBX0RvRUDgyFoz/QVQAuT uBQtaViQ3ip1qcTRw1KupLmUGsHzKt5PquVMBUsmVwK5ZHznG3hRYen3s+Y4ZuERg6 ds3H1NOAmufxP7ewokBz0f3Z1RXa/fUHBG6T0eURjbdb4CPuv7rt5gohk/4d/Y5Bfw Qv/jpJWOhZJrJCo2ygQWPvCinFmRe00mPcA67NQDcNThrZ6zEo8lj7tKY6suu5CcV/ L2tqisP1DPIdoIt7wuiFHqAxckBLqtDl4p1r9P2ymOQaOpnGSjQLnyvDAf93KGVq5Q WBt3StXmBv24cxUXiBIoAm16dr3K5QGQawThaVzHVpG9bZurxTdjrnrVppewdItX6y srjrJtodgF9Vs2+TMPpJ/jv8= X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on wolfsden X-Spam-Level: X-Spam-Status: No, score=-3.1 required=5.0 tests=ALL_TRUSTED,BAYES_00, DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,URIBL_BLOCKED autolearn=unavailable autolearn_force=no version=3.4.6 Received: from localhost (unknown [128.0.188.242]) by wolfsden.cz (Postfix) with ESMTPSA id 0DD5B28853F; Mon, 24 Feb 2025 19:24:42 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=wolfsden.cz; s=mail; t=1740425082; bh=Q5clPHfcdN1FjwaeAH7xm+XAXdhEtFUh05gpYe53DXo=; h=From:To:Cc:Subject:In-Reply-To:References:Date; b=J8R7k+X++wD+aYpmId8H4Hym2ECH1JBqbMMRDtKYG6Q12L0WH77oWbCqCj2slMxqU 8nTfdz74V4iRtf5d9N3SfsgrrlDiqWD7f6oKP3xJeG75w4bPx33Vi54Ps0ZBYl1m1x MQWZmG7h/IFgKluY6JIwBljjPjhTL6R9tsVTLtKwnD7wfNw8v1ArNvY+vrMhjUwZsm Nar8F4So/JrNCMkeGZFCVEqK2M3tfZfc9g8HfHmHcvCNaVMHRVZZo2/hrK/W/a8ZGg tT6mb2EkOHdr0toeX4VK24qekJJ7gUTT0M7McjgJFXTmODIg/I1JV9yyUiizaULjXy kQpG0n+R0RXcSdyEzFV5upvTfQcU3Gz//Rzy19Kcs8uAT8LsrdkRs083K8NQYnRNad FfatLvO3QDWjpo79MOrMPGHzHnqI54qgDudWxdtlSSC5JUGXuzo32kFEYLmmmipPry 53hHjtvdA9UyNda3krBHmGSTsjSRFXTgwmYw+8FJUYezJPv66UEoUYNvg3rA/CHfnO X5gILsS3oXlIVvALpCwnXDxjtzFPH0Wm9Yr+tIm+3sktNsoAZw3bvyck82ep0bwkXu uVi1Mpfe1RN7u+V751C/cY33lk6L6J7ENIy/rFvzbguCBRbycimr04FK/nNOfFmdbg g1QHU8HkmyskAESZjlOUFLAk= From: Tomas Volf <~@wolfsden.cz> To: Ludovic =?utf-8?Q?Court=C3=A8s?= Subject: Re: bug#76516: [shepherd] Timer not executed In-Reply-To: <874j0jtijs.fsf@gnu.org> ("Ludovic =?utf-8?Q?Court=C3=A8s=22'?= =?utf-8?Q?s?= message of "Mon, 24 Feb 2025 17:27:03 +0100") References: <87y0xw1fmz.fsf@wolfsden.cz> <87cyf7tiro.fsf@gnu.org> <874j0jtijs.fsf@gnu.org> Date: Mon, 24 Feb 2025 20:24:42 +0100 Message-ID: <87jz9f16yt.fsf@wolfsden.cz> User-Agent: Gnus/5.13 (Gnus v5.13) MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" X-Spam-Score: 0.0 (/) X-Debbugs-Envelope-To: 76516 Cc: 76516@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -1.0 (-) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Ludovic Court=C3=A8s writes: > Ludovic Court=C3=A8s skribis: > >>> 2025-02-23 12:00:02 Waiting anew for timer 'kerberos-log-in-refresh' (r= esuming from sleep state?). > > The =E2=80=9CWaiting anew=E2=80=9D message happens when the timer fires 2= seconds or > more later than expected (see =E2=80=98sleep-operation/check=E2=80=99), w= hich is indeed > the case here. > > It=E2=80=99s not supposed to happen normally. Before we bump that to 10 > seconds, say, it would be good to understand why the timer got late > here. I definitely agree on this. (I wonder if there is better way to detect the sleep. I feel like *any* number will be wrong for someone. Do we know how for example systemd's timers handle this?) > > Are there services that could block shepherd somehow, for instance by > calling =E2=80=98waitpid=E2=80=99, or running computations at 12:00pm? Not really (I think). This is full shepherd status output: =2D-8<---------------cut here---------------start------------->8--- $ herd status Started: + dbus + pulseaudio + root + timer + transient Running timers: + kerberos-log-in-refresh + log-rotation One-shot: * kerberos-log-in * kerberos-reachable? =2D-8<---------------cut here---------------end--------------->8--- I have already shared the definition of kerberos-log-in-refresh. There is no other timer scheduled (except for log rotation). Other services are from Guix, with the exception of pulseaudio: =2D-8<---------------cut here---------------start------------->8--- (define (home-pulseaudio-shepherd-services _) "Return a shepherd service to run a pulseaudio daemon. Currently no configuration is supported." (list (shepherd-service (documentation "Run a pulseaudio daemon.") (provision '(pulseaudio)) (start #~(make-forkexec-constructor '(#$(file-append pulseaudio "/bin/pulseaudio") "--daemonize=3Dfalse"))) (stop #~(make-kill-destructor))))) =2D-8<---------------cut here---------------end--------------->8--- There is a timer scheduled to run every 15 minutes in the system shepherd, but is it not compute heavy (it just checks error counts from the root filesystem). The machine has 12 cores, each at ~3GHz, 32GB of RAM and SSD for /. I am not aware of any significant resource use that should happen at noon, but even if there would be one, it is hard to believe shepherd would not get a time slice on *any* core for 2 seconds. For what it is worth, today the cronjob worked fine, however even today it was executed at :01, so a second later then it should have been. =2D-8<---------------cut here---------------start------------->8--- 2025-02-24 12:00:01 Timer 'kerberos-log-in-refresh' spawned process 24129. 2025-02-24 12:00:01 Registering new logger for kerberos-log-in-refresh. =2D-8<---------------cut here---------------end--------------->8--- If you have any idea what additional information would be useful, I have no problem deploying patched shepherd with extra logging to this machine (assuming you know what extra logs we need). Tomas =2D-=20 There are only two hard things in Computer Science: cache invalidation, naming things and off-by-one errors. --=-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQJCBAEBCgAsFiEEt4NJs4wUfTYpiGikL7/ufbZ/wakFAme8x3oOHH5Ad29sZnNk ZW4uY3oACgkQL7/ufbZ/wanNkg//dRdCSCidVNQDR2IikDpxjzbSDm8APG5KKR3O 9u/BMoPJjKOAFWbHd6XjJkSqr4nRmWJeTDvrFtbYPwq6hEZYR0wFg11X+aopARKS X81Nsu7Nh1+56ntWvAEJT5PnIyTuPwHhe+B4F99WxZdTQiZpyo2AOVmZPMnrQ6TK /yNsJqHtwj51xNPj5BlkX8IJ/SFggASYwzWmOefoA02pamvEcxwzHAPhnFwHqmPy hQv8Bi//VdfuYO5TYuTxn2ZxmWZ+GuKMUiAKg0O6ICwHS52qo9C2OTMrznJnLVUW CFvUzoK+e6wsMCNNXOGx4cGuUlPLOy5yE7tAlgcGQjiD8D3xtHzEBQE38tlQOb33 zC6zuD1r39F4xvpVUidNIgZGPi6u9H7Ey+oXmjwbQuX4NZpx3wmQnQEOexOBqlVS evmJLp2u/4MEUP+PB4NJJPkIUqzBeDdJmjrsENXdIvSLjykZ4m7E8EVdFNxVl/vu TwE2PJsZ/T2o3D4Kcolo5cWlWZ2SNu64nYcwyrF/6AR0VVOuHmRPsP865L13kFFK pYdMMg/93QgnwlXzAJ6eCVjxehnrUn7zpc8jazfvihtWNJowZHwlLQynm6N7XvCO x8eX1yXYIrmhdLVQJRhtiGRaiE254a3Pn17TkAJcG0jThgAb0qHPpvaKpvJVrRNU JBJM5d8= =a45N -----END PGP SIGNATURE----- --=-=-=-- From debbugs-submit-bounces@debbugs.gnu.org Mon Feb 24 16:55:22 2025 Received: (at 76516) by debbugs.gnu.org; 24 Feb 2025 21:55:22 +0000 Received: from localhost ([127.0.0.1]:43173 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1tmgQ6-0002nE-1c for submit@debbugs.gnu.org; Mon, 24 Feb 2025 16:55:22 -0500 Received: from eggs.gnu.org ([2001:470:142:3::10]:48162) by debbugs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.84_2) (envelope-from ) id 1tmgQ2-0002j4-V2 for 76516@debbugs.gnu.org; Mon, 24 Feb 2025 16:55:19 -0500 Received: from fencepost.gnu.org ([2001:470:142:3::e]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1tmgPw-0004Rd-LW; Mon, 24 Feb 2025 16:55:12 -0500 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-Version:Date:References:In-Reply-To:Subject:To: From; bh=fZedmBW2e+y+05UZ2YUF3c7sdulMAjuCCHJ0emTiUic=; b=gy9oGvwmXz6WGJaVP356 PP9aFre6pndOW2XeYvvslFE0BCa+b77prwHIqddbX923+ndyEkXBAova9kb4EWGgDHegaQOW3e9WY POO6e0Fa4Fw9yi5o8A7fUWKwNBXzKT1HfNK/B7Z/PH6tgE8/8Diz0RID8Sjhcxo1JxgtGKcDAh669 UkHnzSkWsX8brQEgg9DqqGfqUoDWRANSpDoiuE1a4wdoJJs194H8rTddjmDpfTK/0bES90iYtEN5B 3QOXPYzc2q4aQkFhC2FebZ6hswHrvOga/B02FPopS1wQRWx00mNgVDqXva7aAMT7E4sOTOYYUhRQj CNPUnJzpP3zQeg==; From: =?utf-8?Q?Ludovic_Court=C3=A8s?= To: Tomas Volf <~@wolfsden.cz> Subject: Re: bug#76516: [shepherd] Timer not executed In-Reply-To: <87jz9f16yt.fsf@wolfsden.cz> (Tomas Volf's message of "Mon, 24 Feb 2025 20:24:42 +0100") References: <87y0xw1fmz.fsf@wolfsden.cz> <87cyf7tiro.fsf@gnu.org> <874j0jtijs.fsf@gnu.org> <87jz9f16yt.fsf@wolfsden.cz> Date: Mon, 24 Feb 2025 22:55:05 +0100 Message-ID: <87h64jrosm.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="=-=-=" X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 76516 Cc: 76516@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Tomas Volf <~@wolfsden.cz> skribis: > (I wonder if there is better way to detect the sleep. I feel like *any* > number will be wrong for someone. Do we know how for example systemd's > timers handle this?) I believe systemd is the one initiating hibernation, so it has the information first-hand; in our case this is initiated by elogind and shepherd doesn=E2=80=99t know. Probably something to fix. Anyway, this time drift remains a mystery to me. I would go for a hack like this: --=-=-= Content-Type: text/x-patch Content-Disposition: inline diff --git a/modules/shepherd/service.scm b/modules/shepherd/service.scm index adc4530..1587a02 100644 --- a/modules/shepherd/service.scm +++ b/modules/shepherd/service.scm @@ -2490,6 +2490,10 @@ keyword arguments as @code{fork+exec-command}: @code{#:user}, "Make an operation that returns @var{timeout} when @var{seconds} have elapsed and @var{overslept} when many more seconds have elapsed--this can happen if the machine is suspended or put into hibernation mode." + (define max-delay + ;; Time after which we consider that we missed the deadline. + (if (> seconds 180) 10 2)) + (let ((expiry (+ (get-internal-real-time) (inexact->exact (round (* seconds internal-time-units-per-second)))))) @@ -2497,7 +2501,7 @@ happen if the machine is suspended or put into hibernation mode." (lambda () (let* ((now (get-internal-real-time)) (delta (- now expiry))) - (if (> delta (* 2 internal-time-units-per-second)) + (if (> delta (* max-delay internal-time-units-per-second)) overslept timeout)))))) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: base64 DQpXRFlUPw0KDQpMdWRv4oCZLg0K --=-=-=-- From debbugs-submit-bounces@debbugs.gnu.org Mon Feb 24 17:57:33 2025 Received: (at 76516) by debbugs.gnu.org; 24 Feb 2025 22:57:33 +0000 Received: from localhost ([127.0.0.1]:43318 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1tmhOG-0006Z4-DA for submit@debbugs.gnu.org; Mon, 24 Feb 2025 17:57:33 -0500 Received: from wolfsden.cz ([37.205.8.62]:33056) by debbugs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.84_2) (envelope-from <~@wolfsden.cz>) id 1tmhMW-0006V3-5S for 76516@debbugs.gnu.org; Mon, 24 Feb 2025 17:55:45 -0500 Received: by wolfsden.cz (Postfix, from userid 104) id 11B15288F36; Mon, 24 Feb 2025 22:55:42 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=wolfsden.cz; s=mail; t=1740437742; bh=+KHm05JAqpdMzPhXJtes9e4Pi2RD4DBTzUZo8UClW0E=; h=From:To:Cc:Subject:In-Reply-To:References:Date; b=AHnLHFGIXjiBWvVmkyVc8ibyxTVDPCZGbdM5p2G12+jwSoQv4mi1A3H87JCUH6X0Q ps+pPBOrPKzk01jwbgu7D2QRdsuHGxmtym9DcaLBMlm/V/0yPmydsHEmi10yO6NNPO eUZnWHO1bISdoxDewejyK5YwO9+LFfiwzgg7CeW8YzWlf6cLM4IggPuKFw5gyxhNZF ASRFhC+nqOPZcs5jnMi5fiDtq95Lp6YHnBtH4EWq6atkSM+Xm7KjntYOIx9ORDJ33Y yV0ett1GmSg3+5HTXqw9J96Yz/nsSUWZcWWR2tiaXgsUDrUO3eDX+1CiK6o3gUzN4Q Z9bDHfbliJQ9ndpV+ywLp2d3kQxcPLLKA6ZQ7h61jCnPMFAnmISyhUYXJqNDFlS375 qxYs98Ubw5rYssaVfuaIw4zotNkIsYKmHmi7kYetrqVIxhdouX7cR4zysTodjy69XH lD7+ICjemLi2cTWdXuYwkFXyKA1KtzCTnqegzhb+Hsgo2jYTvGEr0pAgFwsyhU8Kgn tE+JvEqBhL1qi32Gq83V8yHXkXffFWvjADmBxjnK0yeurW4M2GdnWXa3qdJQCDxuOg e+QKTTDP7fL2vhwAmjAD0k2mXTMS13Yc3x151wV18EyDbl+OAac/o/KToVdpPrckt5 4nuobVP1QjCQd6CkzD1wODa0= X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on wolfsden X-Spam-Level: X-Spam-Status: No, score=-3.1 required=5.0 tests=ALL_TRUSTED,BAYES_00, DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,URIBL_BLOCKED autolearn=ham autolearn_force=no version=3.4.6 Received: from localhost (unknown [128.0.188.242]) by wolfsden.cz (Postfix) with ESMTPSA id 3552128A480; Mon, 24 Feb 2025 22:55:41 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=wolfsden.cz; s=mail; t=1740437741; bh=+KHm05JAqpdMzPhXJtes9e4Pi2RD4DBTzUZo8UClW0E=; h=From:To:Cc:Subject:In-Reply-To:References:Date; b=TElDbSFDDitjC7kWPtrOI6LT92YYpqytLd+IpNV3GVN4geuXu4STKx5i9du8vCkL1 QqyBqtH3NnZeDcah4K7Owx0pueAUsrYoN4pnMgm09ktpDjDKYaBus4aGZ3EQaubUXO 3ad7ABkjMdM+Jci65QKU0RzAwq5dN3JzUPtx1FG46CRDIhSoQIf1nrKTebR3myoMlu bCCdfFjMYo9E5iGLfQmXzutG0UiEPg4kQ77ONnCWnjr6PAGEC1p/NjGi0FnFUiKeRF J7b2pw0+aJvBUSd23dux5sM82L5/B8qBy24lj+VFM7r/vfnL3Daeyf3RHZ7V2Amadg DVQAKzEMlnbKUTQ7HlQX/hAWj+qFqfzavvod8KhoD4OqtEcGXP6ryU39RjctkWe8Pj /60wEhnG+A+yO+o5I57YOFiLTC2tv+6InEWGvsNMoozShXibJ/MryDzzDkUFK2POR9 iWkzFos+lHeaMR4gzta1hAC2tSTp+Jkx+hs5Hrz14ugMuLKk/wfe5zlZkce0V1gL69 W+voD/hJ9kLF5ztDvAUSV/L5BGH4OHz6it4RD9DygP71DQhzbw83k2bZuNln8EmVeS g2mqS/vd+BUiljDuDdEDbVjMTYVtUETLa0eLf7pXs5oZ/SyihGic0nb1y5kGlWZ3AS SheMqQfE9xAE/Y9m6RzbgwFQ= From: Tomas Volf <~@wolfsden.cz> To: Ludovic =?utf-8?Q?Court=C3=A8s?= Subject: Re: bug#76516: [shepherd] Timer not executed In-Reply-To: <87h64jrosm.fsf@gnu.org> ("Ludovic =?utf-8?Q?Court=C3=A8s=22'?= =?utf-8?Q?s?= message of "Mon, 24 Feb 2025 22:55:05 +0100") References: <87y0xw1fmz.fsf@wolfsden.cz> <87cyf7tiro.fsf@gnu.org> <874j0jtijs.fsf@gnu.org> <87jz9f16yt.fsf@wolfsden.cz> <87h64jrosm.fsf@gnu.org> Date: Mon, 24 Feb 2025 23:55:40 +0100 Message-ID: <87bjurymtv.fsf@wolfsden.cz> User-Agent: Gnus/5.13 (Gnus v5.13) MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" X-Spam-Score: 0.0 (/) X-Debbugs-Envelope-To: 76516 Cc: 76516@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -1.0 (-) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Ludovic Court=C3=A8s writes: > Tomas Volf <~@wolfsden.cz> skribis: > >> (I wonder if there is better way to detect the sleep. I feel like *any* >> number will be wrong for someone. Do we know how for example systemd's >> timers handle this?) > > I believe systemd is the one initiating hibernation, so it has the > information first-hand; in our case this is initiated by elogind and > shepherd doesn=E2=80=99t know. Probably something to fix. > > Anyway, this time drift remains a mystery to me. I would go for a hack > like this: > > diff --git a/modules/shepherd/service.scm b/modules/shepherd/service.scm > index adc4530..1587a02 100644 > --- a/modules/shepherd/service.scm > +++ b/modules/shepherd/service.scm > @@ -2490,6 +2490,10 @@ keyword arguments as @code{fork+exec-command}: @co= de{#:user}, > "Make an operation that returns @var{timeout} when @var{seconds} have > elapsed and @var{overslept} when many more seconds have elapsed--this can > happen if the machine is suspended or put into hibernation mode." > + (define max-delay > + ;; Time after which we consider that we missed the deadline. I would extend the comment to describe why both 10 and 2 are used. > + (if (> seconds 180) 10 2)) > + > (let ((expiry (+ (get-internal-real-time) > (inexact->exact > (round (* seconds internal-time-units-per-second))))= )) > @@ -2497,7 +2501,7 @@ happen if the machine is suspended or put into hibe= rnation mode." > (lambda () > (let* ((now (get-internal-real-time)) I have no idea how Shepherd works internally (and much less how Fibers work), so maybe this comment is completely off, but this seems suspicious. Should this lambda not get the wake up time as an argument, instead of calling get-internal-real-time to get the "now"? I have no idea what guarantees do Fibers make regarding the delays between detecting that time is up and calling the callback. And after quick look at the source code I have decided that it is way beyond me to try to figure it out. Is there a way to enable logging of the events? So we would know when fibers decided the timer is up, and when the lambda was called? > (delta (- now expiry))) > - (if (> delta (* 2 internal-time-units-per-second= )) > + (if (> delta (* max-delay internal-time-units-pe= r-second)) > overslept > timeout)))))) >=20=20 > > > WDYT? Well, in *this* particular case it would have resolved the problem, so great for me I guess. However I have left a suggestion above. Out of curiosity, I have scheduled a timer event for tomorrow 23:0{0..5} to see if they will fire with delay. Testing with short timer (closest whole minute) did not bring any results (the timers were executed exactly on time), so maybe the long wait is a factor? Will report tomorrow. Tomas PS: Looking into timer.scm, I see this comment =2D-8<---------------cut here---------------start------------->8--- ;; Reached when resuming from sleep state: we slept ;; significantly more than the requested number of seconds. To ;; avoid triggering every timer when resuming from sleep state, ;; sleep again to remain in sync. =2D-8<---------------cut here---------------end--------------->8--- Not sure I would call 2 (or even the 10) a "significantly more". :) If I expect the cron to sleep for 86400 seconds, 10 more seems... minor. Maybe (I did not put too much though into this and the numbers are completely thumb-sucked), the "overslept" could be if the sleep was longer by more than 10% of the timer period, clipped to be at least 2, and at most 30 minutes? If I have a cron scheduled to run once a month, I would guess most people would prefer to have it run 20 minutes late than to skip a month completely. =2D-=20 There are only two hard things in Computer Science: cache invalidation, naming things and off-by-one errors. --=-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQJCBAEBCgAsFiEEt4NJs4wUfTYpiGikL7/ufbZ/wakFAme8+OwOHH5Ad29sZnNk ZW4uY3oACgkQL7/ufbZ/wanulRAAjMwIwYvgmpwxYkejU/inXftNqIc6uTVd1aq4 VCBrI5ntgmfJf9xDqQQnklkPCmCHR8AqytlGHNOr0+cVGlQyLfpvkoX4L9mBsDrh UqtsqOl2gnrHlU9t9jfMM9RZlQAn4vL8CzKRg2Z+PRa+W4TqxRYI4rBHG05TIg7N mOmd17wKbXmUC7B6MUtojdzYMVvKTzMo/1y/4pTXKIXVf8//3PJ077p2NePygNIx KR66nKnPz0Vezp1C+Aibv1Mvmibk1ZUjdHoOT2cfPSBtzsm+1E9lY7wXUcba5vYL 2YS2huXbNS8QKnTPBUa8wL3BaYlXW+hwshQt6EIsHJXNCIk4Y96VhE/Ru4lTeORA dg69E625rlU1cm1XY2L89hOCLE9vx5TKoDCUN6AoV6wuh+JLA8YfFCQliUIZCpb7 KOw4YGPmf+cDZXVxNEgbEXVv7nl3jUlB9y3ab0WzLWTusAgLe9ZIeV3QegslPVyW 0tUHnW8xi45tMynst9nhzqJxuPSboaR4Q/pzWM367cxo1EVQMBcTErYNmMysSGXS c2AAjCFu5L/+oYWpumPSKZko3Pjja8UY7Tpuq+yvAzb8d18kLC6LlgvGeIXv+PgW KaObrXx6lsm5YwuMj6Tgahscwb2O3Syu5IR0yKY8JlbNdcfLlOnpVzhs0oLscS7c 9FRh9Is= =4G9P -----END PGP SIGNATURE----- --=-=-=-- From debbugs-submit-bounces@debbugs.gnu.org Wed Feb 26 05:09:51 2025 Received: (at 76516) by debbugs.gnu.org; 26 Feb 2025 10:09:51 +0000 Received: from localhost ([127.0.0.1]:51101 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1tnEMQ-0002Ul-7B for submit@debbugs.gnu.org; Wed, 26 Feb 2025 05:09:51 -0500 Received: from eggs.gnu.org ([2001:470:142:3::10]:47480) by debbugs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.84_2) (envelope-from ) id 1tnEMI-0002UR-Cl for 76516@debbugs.gnu.org; Wed, 26 Feb 2025 05:09:43 -0500 Received: from fencepost.gnu.org ([2001:470:142:3::e]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1tnEMB-00015c-Qx; Wed, 26 Feb 2025 05:09:35 -0500 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-Version:Date:References:In-Reply-To:Subject:To: From; bh=8IPcM0aQuqSY5HHFOeAw1jbC9xdPvoG58nPePghn5Xc=; b=CPgNOZDGr0Y3mDMyD9K9 3J8bfj6q6GPsRrfuQtV6SPVxVngh9Rcz/hkSw7LrYEv4xEeEsBOqH0jsyXGCdSyd0Xv9YBuqepTgv q9gJOygN3bSkJITM8bHNutT84TMBsQ5tvNZqY/zUdycGDfyyJ6hy+46tyYhTeP6hHCtHEb64uc7J4 +3F1sHD4YSNib/52RZjBD1kFP7CawH2kNCMKfDT12JAaKj3Tdkw2yQ3bKe6q8NYfKxeVMtdw7jr+3 T58QJbT31yax9TpZwM/AYbJeEiXCKMB6fz/1548wmgIpM4e/oJdJrY5weELwmxQ9lOVLunwWeu3fT wDG0ptdGIoKxFQ==; From: =?utf-8?Q?Ludovic_Court=C3=A8s?= To: Tomas Volf <~@wolfsden.cz> Subject: Re: bug#76516: [shepherd] Timer not executed In-Reply-To: <87bjurymtv.fsf@wolfsden.cz> (Tomas Volf's message of "Mon, 24 Feb 2025 23:55:40 +0100") References: <87y0xw1fmz.fsf@wolfsden.cz> <87cyf7tiro.fsf@gnu.org> <874j0jtijs.fsf@gnu.org> <87jz9f16yt.fsf@wolfsden.cz> <87h64jrosm.fsf@gnu.org> <87bjurymtv.fsf@wolfsden.cz> Date: Wed, 26 Feb 2025 11:09:22 +0100 Message-ID: <875xkx3tm5.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 76516 Cc: 76516@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) Hi, Tomas Volf <~@wolfsden.cz> skribis: > I have no idea how Shepherd works internally (and much less how Fibers > work), so maybe this comment is completely off, but this seems > suspicious. Should this lambda not get the wake up time as an argument, > instead of calling get-internal-real-time to get the "now"? Yes, it would probably be nicer, but it wouldn=E2=80=99t make much of a difference here (and it=E2=80=99s not related to the bug: the bug shows tha= t we sleep longer than asked for). > Is there a way to enable logging of the events? So we would know when > fibers decided the timer is up, and when the lambda was called? There=E2=80=99s no logging at the Fibers level; all we have is logging by shepherd itself. > PS: Looking into timer.scm, I see this comment > > ;; Reached when resuming from sleep state: we slept > ;; significantly more than the requested number of seconds. To > ;; avoid triggering every timer when resuming from sleep state, > ;; sleep again to remain in sync. > > Not sure I would call 2 (or even the 10) a "significantly more". :) If I > expect the cron to sleep for 86400 seconds, 10 more seems... minor. > > Maybe (I did not put too much though into this and the numbers are > completely thumb-sucked), the "overslept" could be if the sleep was > longer by more than 10% of the timer period, clipped to be at least 2, > and at most 30 minutes? Yeah, though there=E2=80=99s no reason for sleeps to drift this much, it=E2= =80=99s a pretty fundamental assumption. Maybe this: (define max-delay ;; Time after which we consider that we missed the deadline. Tolerate a ;; slight drift, which can happen occasionally. (max (min (/ seconds 10.) 120) 2)) Thanks, Ludo=E2=80=99. From debbugs-submit-bounces@debbugs.gnu.org Thu Feb 27 20:29:57 2025 Received: (at 76516) by debbugs.gnu.org; 28 Feb 2025 01:29:57 +0000 Received: from localhost ([127.0.0.1]:41011 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1tnpCP-0005k0-0Q for submit@debbugs.gnu.org; Thu, 27 Feb 2025 20:29:57 -0500 Received: from wolfsden.cz ([37.205.8.62]:50420) by debbugs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.84_2) (envelope-from <~@wolfsden.cz>) id 1tnpCL-0005jP-Dd for 76516@debbugs.gnu.org; Thu, 27 Feb 2025 20:29:55 -0500 Received: by wolfsden.cz (Postfix, from userid 104) id 7A60D31AC8D; Fri, 28 Feb 2025 01:29:51 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=wolfsden.cz; s=mail; t=1740706191; bh=TRZmN97Rb9yJsWhlwhf9Y5GLPMDspPJV2BTWgSbCwW0=; h=From:To:Cc:Subject:In-Reply-To:References:Date; b=AZHeztNjRWxWLgi24s4XZFDCicRXijOr7voFxjfcRUIXg2fZf+H/dxX0KXRKEtwqs oN8C7nWlafECqrJvhrad9Wo5M9LX3azxECOrN+lzzNNcA+iURqg/c2PEX0hk3VLkdi KTDVubjDa+gP367BUPNWkrCxbwgeGaeMojD6DyazJRG9N+uvmlSTWcJuQV5J0CpUFj N7oG/kYlWmMA11XzOshWvV3Ncw0PxtgWAq27+aSPYQy7fDhvgn+b4kw5+lKRHa7ABF 8oGh7eBetNLsyzm7za4lySn2O+8ffql5Bjlvk3tRx5G3fGEBZyLZs5s8qxSDnuwPXV 1ns6BvXTSDfA3PddGUAbXq7eRjNBVcJJESd3cjgiIoyk2AA8rX45DOrLM8RGWb0OLR XkTal2z6mkK4xIIv2Ke3aa8W8bRDpgZi+M5moCl0trwUNlYefAb+M+aMAuarGpLYog Hm4lI3dUF977TOO9f48YQs2wDxhKQTUbGlaDH5FbGF2E4eR9oAo285oG2kh1lfzjR4 y9lpxFDYOv4Jmw6JMW0VvhdKgCIv3cyMcyOwrvmSfVQ1egwz6U3wShDOMcdTQeCG8D Wr0Rq/DcP3Mx/+EGPDaPEkcrmT7HiSU5ad8EZxwuLSXlPyi4iOFZQ+mYu//uDI8YKt Q4jSKl9qpTuQP2exCJ29L9vs= X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on wolfsden X-Spam-Level: X-Spam-Status: No, score=-3.1 required=5.0 tests=ALL_TRUSTED,BAYES_00, DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,URIBL_BLOCKED autolearn=ham autolearn_force=no version=3.4.6 Received: from localhost (unknown [128.0.188.242]) by wolfsden.cz (Postfix) with ESMTPSA id 08C763190B7; Fri, 28 Feb 2025 01:29:51 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=wolfsden.cz; s=mail; t=1740706191; bh=TRZmN97Rb9yJsWhlwhf9Y5GLPMDspPJV2BTWgSbCwW0=; h=From:To:Cc:Subject:In-Reply-To:References:Date; b=AZHeztNjRWxWLgi24s4XZFDCicRXijOr7voFxjfcRUIXg2fZf+H/dxX0KXRKEtwqs oN8C7nWlafECqrJvhrad9Wo5M9LX3azxECOrN+lzzNNcA+iURqg/c2PEX0hk3VLkdi KTDVubjDa+gP367BUPNWkrCxbwgeGaeMojD6DyazJRG9N+uvmlSTWcJuQV5J0CpUFj N7oG/kYlWmMA11XzOshWvV3Ncw0PxtgWAq27+aSPYQy7fDhvgn+b4kw5+lKRHa7ABF 8oGh7eBetNLsyzm7za4lySn2O+8ffql5Bjlvk3tRx5G3fGEBZyLZs5s8qxSDnuwPXV 1ns6BvXTSDfA3PddGUAbXq7eRjNBVcJJESd3cjgiIoyk2AA8rX45DOrLM8RGWb0OLR XkTal2z6mkK4xIIv2Ke3aa8W8bRDpgZi+M5moCl0trwUNlYefAb+M+aMAuarGpLYog Hm4lI3dUF977TOO9f48YQs2wDxhKQTUbGlaDH5FbGF2E4eR9oAo285oG2kh1lfzjR4 y9lpxFDYOv4Jmw6JMW0VvhdKgCIv3cyMcyOwrvmSfVQ1egwz6U3wShDOMcdTQeCG8D Wr0Rq/DcP3Mx/+EGPDaPEkcrmT7HiSU5ad8EZxwuLSXlPyi4iOFZQ+mYu//uDI8YKt Q4jSKl9qpTuQP2exCJ29L9vs= From: Tomas Volf <~@wolfsden.cz> To: Ludovic =?utf-8?Q?Court=C3=A8s?= Subject: Re: bug#76516: [shepherd] Timer not executed In-Reply-To: <875xkx3tm5.fsf@gnu.org> ("Ludovic =?utf-8?Q?Court=C3=A8s=22'?= =?utf-8?Q?s?= message of "Wed, 26 Feb 2025 11:09:22 +0100") References: <87y0xw1fmz.fsf@wolfsden.cz> <87cyf7tiro.fsf@gnu.org> <874j0jtijs.fsf@gnu.org> <87jz9f16yt.fsf@wolfsden.cz> <87h64jrosm.fsf@gnu.org> <87bjurymtv.fsf@wolfsden.cz> <875xkx3tm5.fsf@gnu.org> Date: Fri, 28 Feb 2025 02:29:50 +0100 Message-ID: <87senyq2k1.fsf@wolfsden.cz> User-Agent: Gnus/5.13 (Gnus v5.13) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Spam-Score: 0.0 (/) X-Debbugs-Envelope-To: 76516 Cc: 76516@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -1.0 (-) Ludovic Court=C3=A8s writes: > Hi, > > Tomas Volf <~@wolfsden.cz> skribis: > >> I have no idea how Shepherd works internally (and much less how Fibers >> work), so maybe this comment is completely off, but this seems >> suspicious. Should this lambda not get the wake up time as an argument, >> instead of calling get-internal-real-time to get the "now"? > > Yes, it would probably be nicer, but it wouldn=E2=80=99t make much of a > difference here (and it=E2=80=99s not related to the bug: the bug shows t= hat we > sleep longer than asked for). I am not sure this is correct. What the bug shows is that the callback is called later then expected. We do not know how long the sleep was. Am I missing something? > >> Is there a way to enable logging of the events? So we would know when >> fibers decided the timer is up, and when the lambda was called? > > There=E2=80=99s no logging at the Fibers level; all we have is logging by > shepherd itself. > >> PS: Looking into timer.scm, I see this comment >> >> ;; Reached when resuming from sleep state: we slept >> ;; significantly more than the requested number of seconds. To >> ;; avoid triggering every timer when resuming from sleep state, >> ;; sleep again to remain in sync. >> >> Not sure I would call 2 (or even the 10) a "significantly more". :) If I >> expect the cron to sleep for 86400 seconds, 10 more seems... minor. >> >> Maybe (I did not put too much though into this and the numbers are >> completely thumb-sucked), the "overslept" could be if the sleep was >> longer by more than 10% of the timer period, clipped to be at least 2, >> and at most 30 minutes? > > Yeah, though there=E2=80=99s no reason for sleeps to drift this much, it= =E2=80=99s a > pretty fundamental assumption. Does not seem to hold in this particular case (at least for the lower bound). =C2=AF\_(=E3=83=84)_/=C2=AF > Maybe this: > > (define max-delay > ;; Time after which we consider that we missed the deadline. Tolerat= e a > ;; slight drift, which can happen occasionally. > (max (min (/ seconds 10.) 120) 2)) That should work, yeah. At least as a temporary measure. :) Few additional data-points: The timers I have scheduled for almost 24h in the future fired exactly on time. As for the kerberos-log-in-refresh timer, twice it fired within the 2 seconds (12:00:01), once outside (12:00:02). I was thinking about this some more, and the right solution here probably is to use netlink to listen for ACPI events, the same way acpid does. That should provide reliable information about the suspend and resume events. Tomas --=20 There are only two hard things in Computer Science: cache invalidation, naming things and off-by-one errors. From debbugs-submit-bounces@debbugs.gnu.org Sat Mar 01 12:26:03 2025 Received: (at 76516) by debbugs.gnu.org; 1 Mar 2025 17:26:04 +0000 Received: from localhost ([127.0.0.1]:42745 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1toQbD-0004QD-Gl for submit@debbugs.gnu.org; Sat, 01 Mar 2025 12:26:03 -0500 Received: from eggs.gnu.org ([2001:470:142:3::10]:34812) by debbugs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.84_2) (envelope-from ) id 1toQbA-0004PH-GG for 76516@debbugs.gnu.org; Sat, 01 Mar 2025 12:26:01 -0500 Received: from fencepost.gnu.org ([2001:470:142:3::e]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1toQb3-0000f4-32; Sat, 01 Mar 2025 12:25:54 -0500 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-Version:Date:References:In-Reply-To:Subject:To: From; bh=mKxni7D3UQSqSYkNKvl399WaFbHRZ6GioBlMt9IOZW4=; b=iiOPDKUVphToytu0ulc+ vuhby75EXZFPK7bSXR3jAh/f8d2oK78x1dxR675lNlt3/KlZtIuv9JMbrrB06HXY+zA9KvZ7ZB1zW yDfpmAXXy1h4W5icFnMWVQmu2+cfNgC3/IPBwCn4184EJpOG/hteqiRIBsSvjTf6OSD3naZAhZJpF b/MG//xjuuwBcE/xm4k2dQYQrAtzQk3+aygTZb6xkSr+5NvogjmEh+QFjINCJytSKjORXlHmIZUY4 f8oov7S/L+Hd9pqW+6UFy7Z63e693w3uJhdh7chpNz8TxXHwGF75pdnjN5y+bHfN3Xrwa+gscv3HM Hw0iI+poDs3zjA==; From: =?utf-8?Q?Ludovic_Court=C3=A8s?= To: Tomas Volf <~@wolfsden.cz> Subject: Re: bug#76516: [shepherd] Timer not executed In-Reply-To: <87senyq2k1.fsf@wolfsden.cz> (Tomas Volf's message of "Fri, 28 Feb 2025 02:29:50 +0100") References: <87y0xw1fmz.fsf@wolfsden.cz> <87cyf7tiro.fsf@gnu.org> <874j0jtijs.fsf@gnu.org> <87jz9f16yt.fsf@wolfsden.cz> <87h64jrosm.fsf@gnu.org> <87bjurymtv.fsf@wolfsden.cz> <875xkx3tm5.fsf@gnu.org> <87senyq2k1.fsf@wolfsden.cz> Date: Sat, 01 Mar 2025 18:25:33 +0100 Message-ID: <87ldtok6ia.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 76516 Cc: 76516@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) Hi, Tomas Volf <~@wolfsden.cz> skribis: >>> I have no idea how Shepherd works internally (and much less how Fibers >>> work), so maybe this comment is completely off, but this seems >>> suspicious. Should this lambda not get the wake up time as an argument, >>> instead of calling get-internal-real-time to get the "now"? >> >> Yes, it would probably be nicer, but it wouldn=E2=80=99t make much of a >> difference here (and it=E2=80=99s not related to the bug: the bug shows = that we >> sleep longer than asked for). > > I am not sure this is correct. What the bug shows is that the callback > is called later then expected. We do not know how long the sleep was. > Am I missing something? The bug is that it slept longer than expected, not that it was late, if you see what I mean. >> Maybe this: >> >> (define max-delay >> ;; Time after which we consider that we missed the deadline. Tolera= te a >> ;; slight drift, which can happen occasionally. >> (max (min (/ seconds 10.) 120) 2)) > > That should work, yeah. At least as a temporary measure. :) Heh, agreed. Pushed as 7a7b4e16f9697c4822b7693e63cc4ba0ace134a2. > Few additional data-points: The timers I have scheduled for almost 24h > in the future fired exactly on time. As for the kerberos-log-in-refresh > timer, twice it fired within the 2 seconds (12:00:01), once outside > (12:00:02). OK. > I was thinking about this some more, and the right solution here > probably is to use netlink to listen for ACPI events, the same way acpid > does. That should provide reliable information about the suspend and > resume events. Sounds like a good idea (though it=E2=80=99s a bit annoying to depend on guile-netlink and low-level details). Another thing I had in mind was to use an elogind hook so that shepherd would know when we=E2=80=99re suspending; this is necessary for other things such as locking LUKS devices on suspend. But that=E2=80=99s a change for 1= .1.x. Thanks, Ludo=E2=80=99. From debbugs-submit-bounces@debbugs.gnu.org Sat Mar 01 12:26:09 2025 Received: (at control) by debbugs.gnu.org; 1 Mar 2025 17:26:09 +0000 Received: from localhost ([127.0.0.1]:42749 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1toQbI-0004Qt-V9 for submit@debbugs.gnu.org; Sat, 01 Mar 2025 12:26:09 -0500 Received: from eggs.gnu.org ([2001:470:142:3::10]:37696) by debbugs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.84_2) (envelope-from ) id 1toQbG-0004Pm-BN for control@debbugs.gnu.org; Sat, 01 Mar 2025 12:26:06 -0500 Received: from fencepost.gnu.org ([2001:470:142:3::e]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1toQbB-0000fZ-1t for control@debbugs.gnu.org; Sat, 01 Mar 2025 12:26:01 -0500 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=gnu.org; s=fencepost-gnu-org; h=MIME-version:Subject:From:To:Date:in-reply-to: references; bh=IkNjczUthusITcHYLTb29IClaqtpbVsdXcK0+E/JJLs=; b=fOgHmI8P2L99eC DzEZm7ZP36KqtUyt0pOIZTKXii7ppHPgBGB606Zyju1EQFM+d1hmveEqM06sz+qhmzH71iotaKy7N qXMmxT+EU8ZLWMHJbn6rAUNnBHJVnMr2pRGeJgB2Qr/UMoi1YY1bze79/oiNAzwfgvWpoDt7xo1aj zDMrK5GxygqGjVoOz/u/kUR48cJLbnjaXUV8jHoVOfX9gqubwsIZb657/07xJ4OIj/NxrsDAEL+nH t8Epjnvr8MMwqomGWdTttH+5nsGcgEyh8dUEZ06FvFsHx3/vP4fV0b/D79KRWU6dKhXumVcybgh14 eXma2EWVHy3zFtNZkdtQ==; Date: Sat, 01 Mar 2025 18:25:59 +0100 Message-Id: <87jz98k6hk.fsf@gnu.org> To: control@debbugs.gnu.org From: =?utf-8?Q?Ludovic_Court=C3=A8s?= Subject: control message for bug #76516 MIME-version: 1.0 Content-type: text/plain; charset=utf-8 Content-Transfer-Encoding: 8bit X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: control X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) close 76516 quit From debbugs-submit-bounces@debbugs.gnu.org Sat Mar 01 18:37:10 2025 Received: (at 76516) by debbugs.gnu.org; 1 Mar 2025 23:37:10 +0000 Received: from localhost ([127.0.0.1]:46639 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1toWOL-0003Ur-Ub for submit@debbugs.gnu.org; Sat, 01 Mar 2025 18:37:10 -0500 Received: from wolfsden.cz ([37.205.8.62]:41500) by debbugs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.84_2) (envelope-from <~@wolfsden.cz>) id 1toWOH-0003UB-S8 for 76516@debbugs.gnu.org; Sat, 01 Mar 2025 18:37:07 -0500 Received: by wolfsden.cz (Postfix, from userid 104) id 416CD353BE4; Sat, 1 Mar 2025 23:37:04 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=wolfsden.cz; s=mail; t=1740872224; bh=rB91QOVtOhP8fw2CYXuh3zZhrkIUIoBK41b02o+VTfI=; h=From:To:Cc:Subject:In-Reply-To:References:Date; b=x5/jzNZhk2xOWYRY4NHA0qLqhmFzAEZ+9WyOF0PD53kI+j6gfMII/CBYAt2tVSUQm ZWCNB4Ozzi1UmsYchC8iCjfhPWJ9ETSnAtQ8QMOnvKxhONVnFpHqW2iEYL/y2WCeuB GDl3DS+yCGfIfPsjbAmn5wX3WLByEijBmMRhfys/BdGeQH9Sv+xOkMMBemIwbo/gDP owPaH7VCwKxp8hicb9SrM92Ez4jSvJv4vxjXxQnCsBOAqlzdB7td2IBKxqXZMmPyVh 2TqBeTJfp39S8h4OJizAP4hxZRBLZZc672ccO1OvJVbGpOgDB5I+cgaDHVoV9Fiyb7 iYrBoLcATthOqnA8xw2HbYRfrAXvamsyfkUxLB4heRxOn8HavRWbQCcqNp5NB51kus KKtf3j0BHQDhJuADdoqmAort3uHCPeYSBccoIBCvEUgKMIrZmLR1Y2OooX2zbSPV9c yNZHCe75kIfCHc/lOmTk/nZLwHyTnnRD9/cX8NDpIAr/4GQsy+sRQAqLJr15gFX4N8 6h0JmqhfmBT76rCUZPv9fU1k2YcNy4DtnvzIh2pPeO85l9g62Z6DpZo2VKkKbwFtLI km81CeANIBLWLexjmQGK8k1dEsUZywL+CquH7ptthh5kaZC7r007QZbpngT/DYka6V qq6EnzkIXezqCvXTh6IEDuLA= X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on wolfsden X-Spam-Level: X-Spam-Status: No, score=-3.1 required=5.0 tests=ALL_TRUSTED,BAYES_00, DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,URIBL_BLOCKED autolearn=unavailable autolearn_force=no version=3.4.6 Received: from localhost (unknown [128.0.188.242]) by wolfsden.cz (Postfix) with ESMTPSA id 8420A354EAF; Sat, 1 Mar 2025 23:37:02 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=wolfsden.cz; s=mail; t=1740872222; bh=rB91QOVtOhP8fw2CYXuh3zZhrkIUIoBK41b02o+VTfI=; h=From:To:Cc:Subject:In-Reply-To:References:Date; b=xvi/PeZ73NnfCgpiKTQL11ha8iHkBdNqqHPYoEOmkPRnxKGLA/KII/S9ATOfHSWBC VcmEgCPEt9Wzw21StrTCKPNbelXvMCNSFCGLHs4acbVYlPyf49+UZixL/So9D6ud+i +x4f8uzLBwpP58gHsfj9sH6gMecgl/6lP4kY11S+3rskK0eTANGraNTeCKl4O4XJTy pT4mL4oIyiunX2XLulQdMJxeEJxxMR9+sqZNZpP3glXGjY1v+8+pjRws41kr12tU97 6rxSK+LFLvGZSJ6WgXhMwIAIpTNIkXbdlZDl9YG8ivLu0Tpsu3nUrpPOjRtlObLt5I LxgqyI0D7+RPATXrS0PWzhZPA9jZf+f8+h+MqJ4XOzvnuM+eWC8316FzSyB9nQf7my RYaAutogasO7svol1X3hGuC3XGJBXSKtATh8BnMXGixRhUWNS5ZZMX4aEmHn8zAZvi OWEHonCpgD49RMkBeIQZRPxh91zHLdG4/77lfiyg5DwTaA5CyZAnR286AiTU9Se87W +BeprF4H+yc2bN66FRZ7cxTtC8C5CbY/SJJjfujunvlxkFxFyRCh/+EbgSk+szxokY 336+uX5+tIOoSWBXt8aN6tYPUhnzswt5r32dV7Rab4Xm+2VbQRv63GoSm+7bssEL9z I20MX4T59RRAUz7JAd4Ubk/0= From: Tomas Volf <~@wolfsden.cz> To: Ludovic =?utf-8?Q?Court=C3=A8s?= Subject: Re: bug#76516: [shepherd] Timer not executed In-Reply-To: <87ldtok6ia.fsf@gnu.org> ("Ludovic =?utf-8?Q?Court=C3=A8s=22'?= =?utf-8?Q?s?= message of "Sat, 01 Mar 2025 18:25:33 +0100") References: <87y0xw1fmz.fsf@wolfsden.cz> <87cyf7tiro.fsf@gnu.org> <874j0jtijs.fsf@gnu.org> <87jz9f16yt.fsf@wolfsden.cz> <87h64jrosm.fsf@gnu.org> <87bjurymtv.fsf@wolfsden.cz> <875xkx3tm5.fsf@gnu.org> <87senyq2k1.fsf@wolfsden.cz> <87ldtok6ia.fsf@gnu.org> Date: Sun, 02 Mar 2025 00:37:01 +0100 Message-ID: <87ldtonx0i.fsf@wolfsden.cz> User-Agent: Gnus/5.13 (Gnus v5.13) MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" X-Spam-Score: 0.0 (/) X-Debbugs-Envelope-To: 76516 Cc: 76516@debbugs.gnu.org X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -1.0 (-) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Ludovic Court=C3=A8s writes: > [..] > > Another thing I had in mind was to use an elogind hook so that shepherd > would know when we=E2=80=99re suspending; this is necessary for other thi= ngs > such as locking LUKS devices on suspend. But that=E2=80=99s a change for= 1.1.x. I see two possible problem here (both solvable). 1. AFAICT shepherd currently does not depend on elogind at all. Having it as a run-time dependency might be fine on Guix (assuming we move elogind into %base-services), but could be annoying on foreign distributions, especially from non-root user's point of view. 2. How will the hook know what all processes it should let know? There is no global registry of all running shepherd processes no? Though I am sure both of these are solvable. Have a nice day (and thanks for the fix :) ), Tomas =2D-=20 There are only two hard things in Computer Science: cache invalidation, naming things and off-by-one errors. --=-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQJCBAEBCgAsFiEEt4NJs4wUfTYpiGikL7/ufbZ/wakFAmfDmh0OHH5Ad29sZnNk ZW4uY3oACgkQL7/ufbZ/walWsA//d0cl5VZY40lIkozTwHIg0MI+qPSkl98TVrtg yYuiKlvplCZenfDhK57eEVK2G4EDSYububZIGTkYoX0+WFeR1iLmzLt4zGLMBZ1K pK3S99uqBbCUbYuRL5oXH+myKHDOJgW8NcqafIFDiS/8ORzsxyaU/Mv50Ql4e/PQ wh/tFOC2pvrVUmLGSeqWn6kAamdigb23mAOw4TUJ0rQxV0s6gnZrYV4dGR5sP1Vh UsbTg0sSfLQDn3aCd3Uka1BcrFZFHXgYcPs6vqdMm8hTWiwakJIV3Vkl70fe9Rcp UE/wBKerd7riGO82xNhTa7c8Rj0HBWi1/lEueuzF2fhLpTXIkcznUvQ2DASTIRsN y6HIIkIfrBE7dPb0cD5+THLYCSWarRbQ18RYxRNzs6B74t/aVNH9fxr4zwliy3Kq ndGu4YLGCdSMGFQOlL5mdbsvSrpwruOPS15eAXvjRbWCR9c+Hb3VvIq+7q13JERU 4DFu3Ljr+7xY7USKW0S2hgWx9cXd2O8dT6jeUsNyOvefRlrz8KUSjIYJs1Jqv4Go WRSO2Ls+hzx7jj2hMT1b9bQ6PBxBf6M0+iAZmqsz5tSS8mtJyw7tbT/Pzyyunu8+ 7wH51lKAV3khonl+tDnA0MvPaZGTN/oDomzhPynPiKp6+zkDPsvZSobPGU42QIfL VF4oVo4= =wisB -----END PGP SIGNATURE----- --=-=-=-- From unknown Fri Aug 08 23:32:17 2025 Received: (at fakecontrol) by fakecontrolmessage; To: internal_control@debbugs.gnu.org From: Debbugs Internal Request Subject: Internal Control Message-Id: bug archived. Date: Sun, 30 Mar 2025 11:24:18 +0000 User-Agent: Fakemail v42.6.9 # This is a fake control message. # # The action: # bug archived. thanks # This fakemail brought to you by your local debbugs # administrator