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

start-stop-daemon: truncate log file for stdout. #110

Merged
merged 1 commit into from
Jan 20, 2023
Merged

Conversation

DentonGentry
Copy link
Contributor

@DentonGentry DentonGentry commented Jan 19, 2023

The initial part of that file can be useful if tailscaled is crashing or has other failures during startup. We don't want to keep the disk from hibernating by writing to it after startup.

Fixes tailscale/tailscale#7007

Signed-off-by: Denton Gentry [email protected]

@bradfitz
Copy link
Member

Had we done this earlier, we would've never had any evidence from users about how that SIGILL bug was crashing. Or one of those earlier tun crashes.

I think we want to keep the first N bytes of the output or something, to see how it started up (tun mode, dns mode, early panics, etc). But that implies we should do it in tailscaled/Go code rather than globally here?

@@ -31,7 +31,7 @@ fi
start_daemon() {
local ts=$(date --iso-8601=second)
echo "${ts} Starting ${SERVICE_NAME} with: ${SERVICE_COMMAND}" >${LOG_FILE}
STATE_DIRECTORY=${PKGVAR} ${SERVICE_COMMAND} >>${LOG_FILE} 2>&1 &
STATE_DIRECTORY=${PKGVAR} ${SERVICE_COMMAND} >/dev/null 2>&1 &
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

can you get pipe through sed '1,200p;d' in here (per tip from @creachadair) so we only print the first 200 lines and then discard the rest? then we still see start-up messages.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Still working on this, something isn't right. No output from tailscaled is being written to the file.

dgentry@dsm7:/var$ cat  /var/packages/Tailscale/var/tailscaled.stdout.log
2023-01-19T18:18:55-08:00 Starting tailscale with: /volume1/@appstore/Tailscale/bin/tailscaled --state=/volume1/@appdata/Tailscale/tailscaled.state --socket=/volume1/@appdata/Tailscale/tailscaled.sock --port=41641 --tun=userspace-networking
dgentry@dsm7:/var$ wc -l  /var/packages/Tailscale/var/tailscaled.stdout.log
1 /var/packages/Tailscale/var/tailscaled.stdout.log
dgentry@dsm7:/var$

It is GNU sed, not busybox or something weird, and sed '1,200p;d' on a text file does print the first 200 lines.

dgentry@dsm7:/var$ /bin/sed --version
/bin/sed (GNU sed) 4.5
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <https://gnu.org/licenses/gpl.html>.

@DentonGentry DentonGentry force-pushed the logfile branch 3 times, most recently from 4503a4d to 5cc3c38 Compare January 20, 2023 02:15
@DentonGentry DentonGentry changed the title start-stop-daemon: don't write stdout to a file. start-stop-daemon: truncate log file for stdout. Jan 20, 2023
@@ -31,7 +31,7 @@ fi
start_daemon() {
local ts=$(date --iso-8601=second)
echo "${ts} Starting ${SERVICE_NAME} with: ${SERVICE_COMMAND}" >${LOG_FILE}
STATE_DIRECTORY=${PKGVAR} ${SERVICE_COMMAND} >>${LOG_FILE} 2>&1 &
STATE_DIRECTORY=${PKGVAR} ${SERVICE_COMMAND} | sed '1,200p;d' >>${LOG_FILE} 2>&1 &
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

do you need the 2>&1 first before the pipe?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That does change the behavior, now it writes 93 lines to the file. Then it get stuck mid-line.

dgentry@dsm7:/$ cat  /var/packages/Tailscale/var/tailscaled.stdout.log
2023-01-19T19:43:58-08:00 Starting tailscale with: /volume1/@appstore/Tailscale/bin/tailscaled --state=/volume1/@appdata/Tailscale/tailscaled.state --socket=/volume1/@appdata/Tailscale/tailscaled.sock --port=41641 --tun=userspace-networking
...
wgengine: Reconfig: configuring userspace WireGuard config (with 1/29 peers)
magicsock: disco: node [jB1VP] d:f8349dfff17e6c4f now using 10.1.10.240:62625
Accept: ICMPv4{100.100.165.16:0 > 100.70.216.3:0} 84 icmp ok
Accept: TCP{100.100.165.16:49834 > 100.70.216.3:5000} 64 tcp ok
Accept: TCP{100.100.165.16:49835 > 100.70.216.3:5000} 64 tcp ok
Accept: TCP{100.100.165.16:49834 > 100.70.216.3:5000} 40 tcp non-syn
Accept: TCP{100.100.165.16:49839 > 100.70.216.3:5000} 40 tcp non-syn
Accept: TCP{100.100.165.16:49836 > 100.70.216.3:5000} 40 tcp non-syn
Accept: TCP{100.100.165.16:49834 > 100.70.216.3:5000} 52 tcp non-syn
Accept: TCP{100.100.165.16:49836dgentry@dsm7:/$

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Paging @creachadair and @raggi for sed/shell help 😂

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

oh, I bet it's buffered and waiting to flush.

I bet that midline is on some 1K/4K boundary.

Try sed -u to turn off some buffering?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

FWIW, I confirmed that both DSM6 and DSM7 have GNU sed with -u, if that's an uncommon thing (no clue)

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

sed -u works much better, new log lines appear in roughly real time and the file stops growing at 201 lines — one line of the "Starting tailscale ..." echo, then 200 lines from tailscaled.

@DentonGentry DentonGentry force-pushed the logfile branch 2 times, most recently from e23787f to 0351052 Compare January 20, 2023 04:48
@@ -31,7 +31,7 @@ fi
start_daemon() {
local ts=$(date --iso-8601=second)
echo "${ts} Starting ${SERVICE_NAME} with: ${SERVICE_COMMAND}" >${LOG_FILE}
STATE_DIRECTORY=${PKGVAR} ${SERVICE_COMMAND} >>${LOG_FILE} 2>&1 &
STATE_DIRECTORY=${PKGVAR} ${SERVICE_COMMAND} 2>&1 | sed -u '1,200p;d' >>${LOG_FILE} &
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

maybe we should make line 201 say it's explicitly truncated, so people don't think it's hung or something?

$ (echo one; echo two; echo three; echo four; echo five) | sed '1,3 p; 4 s,.*,[further tailscaled logs suppressed], p; d'
one
two
three
[further tailscaled logs suppressed]

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

The initial part of that file can be useful if tailscaled
is crashing or has other failures during startup. We don't
want to keep the disk from hibernating by writing to it after
startup.

Fixes tailscale/tailscale#7007

Signed-off-by: Denton Gentry <[email protected]>
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 this pull request may close these issues.

Hibernation not working on Synology with tailscale
2 participants