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

fix(util): syslog output contains duplicated timestamp #2292

Merged
merged 1 commit into from
Aug 1, 2024

Conversation

mrl5
Copy link
Contributor

@mrl5 mrl5 commented Jul 19, 2024

Describe your changes

journalctl
- Jul 19 14:41:01 rpi /usr/bin/netbird[614]: 2024-07-19T14:41:01+02:00 ERRO %!s(<nil>): error while handling message of Peer [key: REDACTED] error: [wrongly addressed message REDACTED]
- Jul 19 21:53:03 rpi /usr/bin/netbird[614]: 2024-07-19T21:53:03+02:00 WARN %!s(<nil>): disconnected from the Signal service but will retry silently. Reason: rpc error: code = Internal desc = server closed the stream without sending trailers
- Jul 19 21:53:04 rpi /usr/bin/netbird[614]: 2024-07-19T21:53:04+02:00 INFO %!s(<nil>): connected to the Signal Service stream
- Jul 19 22:24:10 rpi /usr/bin/netbird[614]: 2024-07-19T22:24:10+02:00 WARN [error: read udp 192.168.1.11:48398->9.9.9.9:53: i/o timeout, upstream: 9.9.9.9:53] %!s(<nil>): got an error while connecting to upstream
+ Jul 19 14:41:01 rpi /usr/bin/netbird[614]: error while handling message of Peer [key: REDACTED] error: [wrongly addressed message REDACTED]
+ Jul 19 21:53:03 rpi /usr/bin/netbird[614]: disconnected from the Signal service but will retry silently. Reason: rpc error: code = Internal desc = server closed the stream without sending trailers
+ Jul 19 21:53:04 rpi /usr/bin/netbird[614]: connected to the Signal Service stream
+ Jul 19 22:24:10 rpi /usr/bin/netbird[614]: [error: read udp 192.168.1.11:48398->9.9.9.9:53: i/o timeout, upstream: 9.9.9.9:53] got an error while connecting to upstream

please notice that although log level is no longer present in the syslog message it is still respected by syslog logger, so the log levels are not lost:

journalctl -p 3
- Jul 19 14:41:01 rpi /usr/bin/netbird[614]: 2024-07-19T14:41:01+02:00 ERRO %!s(<nil>): error while handling message of Peer [key: REDACTED] error: [wrongly addressed message REDACTED]
+ Jul 19 14:41:01 rpi /usr/bin/netbird[614]: error while handling message of Peer [key: REDACTED] error: [wrongly addressed message REDACTED]

Issue ticket number and link

this is a follow-up of #2259

Checklist

  • Is it a bug fix
  • Is a typo/documentation fix
  • Is a feature enhancement
  • It is a refactor
  • Created tests that fail without the change (if possible)
  • Extended the README / documentation, if necessary

// SetSyslogFormatter set the text formatter for given logger.
func SetSyslogFormatter(logger *logrus.Logger) {
logger.Formatter = NewSyslogFormatter()
logger.ReportCaller = true
Copy link
Contributor Author

Choose a reason for hiding this comment

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

I'm not logging caller but I left true here because otherwise it crashes with

panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x20 pc=0x4e0ca3]

@mrl5 mrl5 force-pushed the fix-syslog-format branch 2 times, most recently from c4e501a to 660f627 Compare July 20, 2024 05:34
@@ -35,8 +35,11 @@ func InitLog(logLevel string, logPath string) error {
AddSyslogHook()
}

//nolint:gocritic
Copy link
Contributor Author

Choose a reason for hiding this comment

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

ifElseChain: rewrite if-else to switch statement (gocritic)

hmm I'm not sure how switch-case can be used here - I always thought that you can apply it for the same variable which seams not be a case here. I decided to selectively disable linter here

```console
journalctl
```
```diff
- Jul 19 14:41:01 rpi /usr/bin/netbird[614]: 2024-07-19T14:41:01+02:00 ERRO %!s(<nil>): error while handling message of Peer [key: REDACTED] error: [wrongly addressed message REDACTED]
- Jul 19 21:53:03 rpi /usr/bin/netbird[614]: 2024-07-19T21:53:03+02:00 WARN %!s(<nil>): disconnected from the Signal service but will retry silently. Reason: rpc error: code = Internal desc = server closed the stream without sending trailers
- Jul 19 21:53:04 rpi /usr/bin/netbird[614]: 2024-07-19T21:53:04+02:00 INFO %!s(<nil>): connected to the Signal Service stream
- Jul 19 22:24:10 rpi /usr/bin/netbird[614]: 2024-07-19T22:24:10+02:00 WARN [error: read udp 192.168.1.11:48398->9.9.9.9:53: i/o timeout, upstream: 9.9.9.9:53] %!s(<nil>): got an error while connecting to upstream
+ Jul 19 14:41:01 rpi /usr/bin/netbird[614]: error while handling message of Peer [key: REDACTED] error: [wrongly addressed message REDACTED]
+ Jul 19 21:53:03 rpi /usr/bin/netbird[614]: disconnected from the Signal service but will retry silently. Reason: rpc error: code = Internal desc = server closed the stream without sending trailers
+ Jul 19 21:53:04 rpi /usr/bin/netbird[614]: connected to the Signal Service stream
+ Jul 19 22:24:10 rpi /usr/bin/netbird[614]: [error: read udp 192.168.1.11:48398->9.9.9.9:53: i/o timeout, upstream: 9.9.9.9:53] got an error while connecting to upstream
```

please notice that although log level is no longer present in the syslog
message it is still respected by syslog logger, so the log levels are
not lost:
```console
journalctl -p 3
```
```diff
- Jul 19 14:41:01 rpi /usr/bin/netbird[614]: 2024-07-19T14:41:01+02:00 ERRO %!s(<nil>): error while handling message of Peer [key: REDACTED] error: [wrongly addressed message REDACTED]
+ Jul 19 14:41:01 rpi /usr/bin/netbird[614]: error while handling message of Peer [key: REDACTED] error: [wrongly addressed message REDACTED]
```
@mrl5 mrl5 force-pushed the fix-syslog-format branch from 660f627 to 8586641 Compare July 20, 2024 05:55
Copy link
Contributor Author

Choose a reason for hiding this comment

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

I've added it because my IDE was constantly using spaces not tabs ;) I can exclude it if you don't want it commited

@lixmal lixmal merged commit 24e031a into netbirdio:main Aug 1, 2024
21 checks passed
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.

2 participants