Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SIGHUP only properly handled once; subsequent times kill lightningd #4240

Closed
ZmnSCPxj opened this issue Dec 2, 2020 · 2 comments · Fixed by #4243
Closed

SIGHUP only properly handled once; subsequent times kill lightningd #4240

ZmnSCPxj opened this issue Dec 2, 2020 · 2 comments · Fixed by #4243

Comments

@ZmnSCPxj
Copy link
Collaborator

ZmnSCPxj commented Dec 2, 2020

I have my lightningd on logrotate with a killall -s SIGHUP lightningd. The logrotate is set up to rotate once a day at midnight. lightningd does the log rotation correctly on SIGHUP once, but the second one kills it.

Nov 28 11:24:09 server systemd[1]: Starting C-Lightning Daemon...
Nov 28 11:24:19 server systemd[1]: Started C-Lightning Daemon.
Nov 30 00:00:14 server systemd[1]: lightningd.service: Main process exited, code=killed, status=1/HUP
Nov 30 00:00:14 server systemd[1]: lightningd.service: Succeeded.
Nov 30 00:00:44 server systemd[1]: lightningd.service: Service RestartSec=30s expired, scheduling restart.
Nov 30 00:00:44 server systemd[1]: lightningd.service: Scheduled restart job, restart counter is at 1.
Nov 30 00:00:44 server systemd[1]: Stopped C-Lightning Daemon.
Nov 30 00:00:44 server systemd[1]: Starting C-Lightning Daemon...
Nov 30 00:00:51 server systemd[1]: Started C-Lightning Daemon.
Dec 02 00:00:07 server systemd[1]: lightningd.service: Main process exited, code=killed, status=1/HUP
Dec 02 00:00:07 server systemd[1]: lightningd.service: Succeeded.
Dec 02 00:00:37 server systemd[1]: lightningd.service: Service RestartSec=30s expired, scheduling restart.
Dec 02 00:00:37 server systemd[1]: lightningd.service: Scheduled restart job, restart counter is at 2.
Dec 02 00:00:37 server systemd[1]: Stopped C-Lightning Daemon.
Dec 02 00:00:37 server systemd[1]: Starting C-Lightning Daemon...
Dec 02 00:00:42 server systemd[1]: Started C-Lightning Daemon.

Looking at the logs, at the top of the log of odd-numbered days:

2020-12-01T00:00:09.445Z INFO    lightningd: Started log due to SIGHUP

But on logs of even-numbered days:

2020-12-02T00:00:38.204Z INFO    connectd: Static Tor service onion address: "<secret>.onion:9735,127.0.0.1:9735" bound from extern port 9735
2020-12-02T00:00:38.357Z INFO    plugin-bcli: bitcoin-cli initialized and connected to bitcoind.
2020-12-02T00:00:42.320Z INFO    lightningd: --------------------------------------------------
2020-12-02T00:00:42.320Z INFO    lightningd: Server started with public key <secret>, alias <secret> (color #<secret>) and lightningd 0.9.2

Version is the 0.9.2 release, unmodified.

@ZmnSCPxj
Copy link
Collaborator Author

ZmnSCPxj commented Dec 2, 2020

SIGHUP handling is set up here:

lightning/lightningd/log.c

Lines 643 to 648 in 66b2bb9

memset(&act, 0, sizeof(act));
act.sa_handler = handle_sighup;
act.sa_flags = SA_RESETHAND;
if (sigaction(SIGHUP, &act, NULL) != 0)
err(1, "Setting up SIGHUP handler");

What is particularly strange is the use of RESETHAND flag:

act.sa_flags = SA_RESETHAND;

According to https://www.man7.org/linux/man-pages/man2/sigaction.2.html

       SA_RESETHAND
              Restore the signal action to the default upon entry to the
              signal handler.  This flag is meaningful only when establish‐
              ing a signal handler.  SA_ONESHOT is an obsolete, nonstandard
              synonym for this flag.

"Restore the signal action to the default" means that the signal handler is removed, then replaced with the default action. In the case of SIGHUP, that means the default behavior --- killing the process --- is restored after one use of the SIGHUP signal, which is precisely what I see.

#1847 which introduced this feature, the use of SA_RESETHAND was not commented upon and I could not find any justification for why this flag was used, @rustyrussell @cdecker do you remember?

ZmnSCPxj added a commit to ZmnSCPxj/lightning that referenced this issue Dec 2, 2020
ZmnSCPxj added a commit to ZmnSCPxj/lightning that referenced this issue Dec 2, 2020
@ZmnSCPxj ZmnSCPxj mentioned this issue Dec 2, 2020
ZmnSCPxj added a commit to ZmnSCPxj/lightning that referenced this issue Dec 2, 2020
Fixes: ElementsProject#4240

ChangeLog-Fixed: log: Do not terminate on the second received SIGHUP.
ZmnSCPxj added a commit to ZmnSCPxj/lightning that referenced this issue Dec 2, 2020
ZmnSCPxj added a commit to ZmnSCPxj/lightning that referenced this issue Dec 2, 2020
Fixes: ElementsProject#4240

ChangeLog-Fixed: log: Do not terminate on the second received SIGHUP.
rustyrussell pushed a commit that referenced this issue Dec 2, 2020
Fixes: #4240

ChangeLog-Fixed: log: Do not terminate on the second received SIGHUP.
vibhaa pushed a commit to spider-pcn/lightning that referenced this issue Mar 24, 2021
vibhaa pushed a commit to spider-pcn/lightning that referenced this issue Mar 24, 2021
Fixes: ElementsProject#4240

ChangeLog-Fixed: log: Do not terminate on the second received SIGHUP.
@SimonVrouwe
Copy link
Collaborator

I have my lightningd on logrotate with a killall -s SIGHUP lightningd

For those wondering (like myself) why lightningd keeps writing to the old logfile after rotation by logrotate.
logrotate doesn't send the HANGUP signal by default and you need to specify this in a postrotate script in the particular logrotate config file. For example something like this:

/var/lib/lightningd/bitcoin/lightning.log {
        size 1G
        dateext
        rotate 100

        # Send SIGHUP to daemon pid to reopen logfile
        postrotate
           /bin/kill -HUP `cat /run/lightningd/lightningd.pid 2>/dev/null` 2> /dev/null || true
        endscript
}

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants