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

Syslog messages are not properly formatted #285

Closed
3 tasks done
fvanroie opened this issue Jan 24, 2022 · 5 comments
Closed
3 tasks done

Syslog messages are not properly formatted #285

fvanroie opened this issue Jan 24, 2022 · 5 comments
Assignees
Labels
bug Something isn't working done The underlying issue has been fixed
Milestone

Comments

@fvanroie
Copy link
Collaborator

Perform all steps below and tick them with [x]

  • Check the related part of the Documentation
  • Update openHASP to the latest version
  • Reproduce the issue and describe all steps

Describe the bug

As reported by @geiseri in issue: Allow ANSI codes to be disabled for syslog #261 the syslog messages are garbled.

To Reproduce

Configure syslog and watch the output below.

Expected behavior

Properly formed IETF (RFC 5424) / BSD (RFC 3164) syslog messages to be sent.

Screenshots or video

image

@fvanroie fvanroie added the bug Something isn't working label Jan 24, 2022
@fvanroie fvanroie self-assigned this Jan 24, 2022
@fvanroie fvanroie added this to the 0.6.x milestone Jan 24, 2022
fvanroie added a commit that referenced this issue Jan 24, 2022
@fvanroie
Copy link
Collaborator Author

BSD-syslog or legacy-syslog messages look OK now. I don't have setup to test IETF-syslog messages at this moment.
Feel free to test it 😃

@fvanroie fvanroie reopened this Jan 25, 2022
@fvanroie fvanroie added the done The underlying issue has been fixed label Jan 26, 2022
@geiseri
Copy link

geiseri commented Feb 2, 2022

When testing with rsyslog-ng I split the logs by the hostname in the logline. It seems to be okay like 99% of the time, but then randomly I get hostnames with stuff like xt and sometimes a random number. I looked at the contents of one with the hostname of xt and it had the following:

2022-02-02T23:42:24.673151+00:00 xt = 
2022-02-02T23:42:24.703462+00:00 xt = [18:42:24.584][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.val = 0
2022-02-02T23:42:24.721584+00:00 xt = [18:42:24.584][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.val = 0[18:42:24.604][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.text = 
2022-02-02T23:42:24.750760+00:00 xt = [18:42:24.584][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.val = 0[18:42:24.604][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.text = [18:42:24.633][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b2.val = 0
2022-02-02T23:42:24.772555+00:00 xt = [18:42:24.584][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.val = 0[18:42:24.604][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.text = [18:42:24.633][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b2.val = 0[18:42:24.653][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b1.enabled = False
2022-02-02T23:42:24.791641+00:00 xt = [18:42:24.584][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.val = 0[18:42:24.604][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.text = [18:42:24.633][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b2.val = 0[18:42:24.653][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b1.enabled = False[18:42:24.674][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b1.color =
2022-02-02T23:42:24.806179+00:00 xt = [18:42:24.584][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.val = 0[18:42:24.604][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.text = [18:42:24.633][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b2.val = 0[18:42:24.653][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b1.enabled = False[18:42:24.674][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b1.color = [18:42:24.685][65524/114340 42][35220/35272  1] MQTT PUB: p3b1 => {"color":"#ff0000","r":255,"g":0,"b":0}
2022-02-02T23:42:24.827268+00:00 xt = [18:42:24.584][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.val = 0[18:42:24.604][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.text = [18:42:24.633][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b2.val = 0[18:42:24.653][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b1.enabled = False[18:42:24.674][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b1.color = [18:42:24.685][65524/114340 42][35220/35272  1] MQTT PUB: p3b1 => {"color":"#ff0000","r":255,"g":0,"b":0}[18:42:24.707][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.enabled = False
2022-02-02T23:42:24.847796+00:00 xt = [18:42:24.584][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.val = 0[18:42:24.604][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.text = [18:42:24.633][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b2.val = 0[18:42:24.653][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b1.enabled = False[18:42:24.674][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b1.color = [18:42:24.685][65524/114340 42][35220/35272  1] MQTT PUB: p3b1 => {"color":"#ff0000","r":255,"g":0,"b":0}[18:42:24.707][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.enabled = False[18:42:24.727][65524/114004 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.val = 0
2022-02-02T23:42:24.871363+00:00 xt = [18:42:24.584][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.val = 0[18:42:24.604][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.text = [18:42:24.633][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b2.val = 0[18:42:24.653][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b1.enabled = False[18:42:24.674][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b1.color = [18:42:24.685][65524/114340 42][35220/35272  1] MQTT PUB: p3b1 => {"color":"#ff0000","r":255,"g":0,"b":0}[18:42:24.707][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.enabled = False[18:42:24.727][65524/114004 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.val = 0[18:42:24.751][65524/112508 41][35220/35272  1] HTTP: Sent / page to 10.0.5.205
2022-02-02T23:42:24.909428+00:00 xt = [18:42:24.584][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.val = 0[18:42:24.604][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.text = [18:42:24.633][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b2.val = 0[18:42:24.653][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b1.enabled = False[18:42:24.674][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b1.color = [18:42:24.685][65524/114340 42][35220/35272  1] MQTT PUB: p3b1 => {"color":"#ff0000","r":255,"g":0,"b":0}[18:42:24.707][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.enabled = False[18:42:24.727][65524/114004 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.val = 0[18:42:24.751][65524/112508 41][35220/35272  1] HTTP: Sent / page to 10.0.5.205[18:42:24.790][65524/114104 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b4.enabled = False
2022-02-02T23:42:24.933303+00:00 xt = [18:42:24.584][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.val = 0[18:42:24.604][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.text = [18:42:24.633][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b2.val = 0[18:42:24.653][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b1.enabled = False[18:42:24.674][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b1.color = [18:42:24.685][65524/114340 42][35220/35272  1] MQTT PUB: p3b1 => {"color":"#ff0000","r":255,"g":0,"b":0}[18:42:24.707][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.enabled = False[18:42:24.727][65524/114004 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.val = 0[18:42:24.751][65524/112508 41][35220/35272  1] HTTP: Sent / page to 10.0.5.205[18:42:24.790][65524/114104 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b4.enabled = False[18:42:24.811][65524/114104 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b4.val = -1
2022-02-02T23:42:24.985429+00:00 xt = [18:42:24.584][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.val = 0[18:42:24.604][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.text = [18:42:24.633][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b2.val = 0[18:42:24.653][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b1.enabled = False[18:42:24.674][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b1.color = [18:42:24.685][65524/114340 42][35220/35272  1] MQTT PUB: p3b1 => {"color":"#ff0000","r":255,"g":0,"b":0}[18:42:24.707][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.enabled = False[18:42:24.727][65524/114004 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.val = 0[18:42:24.751][65524/112508 41][35220/35272  1] HTTP: Sent / page to 10.0.5.205[18:42:24.790][65524/114104 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b4.enabled = False[18:42:24.811][65524/114104 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b4.val = -1[18:42:24.865][65524/114104 42][35160/35268  1] MQTT RCV: hasp/alarm_clock/command/p1b2.val = 41.5
2022-02-02T23:42:25.006493+00:00 xt = [18:42:24.584][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.val = 0[18:42:24.604][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.text = [18:42:24.633][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b2.val = 0[18:42:24.653][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b1.enabled = False[18:42:24.674][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b1.color = [18:42:24.685][65524/114340 42][35220/35272  1] MQTT PUB: p3b1 => {"color":"#ff0000","r":255,"g":0,"b":0}[18:42:24.707][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.enabled = False[18:42:24.727][65524/114004 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.val = 0[18:42:24.751][65524/112508 41][35220/35272  1] HTTP: Sent / page to 10.0.5.205[18:42:24.790][65524/114104 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b4.enabled = False[18:42:24.811][65524/114104 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b4.val = -1[18:42:24.865][65524/114104 42][35160/35268  1] MQTT RCV: hasp/alarm_clock/command/p1b2.val = 41.5[18:42:24.886][65524/114104 42][35160/35268  1] MQTT RCV: hasp/alarm_clock/command/p1b2.value_str = 41°F
2022-02-02T23:42:25.086314+00:00 xt = [18:42:24.584][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.val = 0[18:42:24.604][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.text = [18:42:24.633][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b2.val = 0[18:42:24.653][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b1.enabled = False[18:42:24.674][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b1.color = [18:42:24.685][65524/114340 42][35220/35272  1] MQTT PUB: p3b1 => {"color":"#ff0000","r":255,"g":0,"b":0}[18:42:24.707][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.enabled = False[18:42:24.727][65524/114004 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.val = 0[18:42:24.751][65524/112508 41][35220/35272  1] HTTP: Sent / page to 10.0.5.205[18:42:24.790][65524/114104 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b4.enabled = False[18:42:24.811][65524/114104 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b4.val = -1[18:42:24.865][65524/114104 42][35160/35268  1] MQTT RCV: hasp/alarm_clock/command/p1b2.val = 41.5[18:42:24.886][65524/114104 42][35160/35268  1] MQTT RCV: hasp/alarm_clock/command/p1b2.value_str = 41°F[18:42:24.964][65524/114104 42][35004/35260  1] MQTT RCV: hasp/alarm_clock/command/p1b3.val = 59.9
2022-02-02T23:42:25.106674+00:00 xt = [18:42:24.584][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.val = 0[18:42:24.604][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p1b12.text = [18:42:24.633][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b2.val = 0[18:42:24.653][65524/114340 42][34812/35104  1] MQTT RCV: hasp/alarm_clock/command/p3b1.enabled = False[18:42:24.674][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b1.color = [18:42:24.685][65524/114340 42][35220/35272  1] MQTT PUB: p3b1 => {"color":"#ff0000","r":255,"g":0,"b":0}[18:42:24.707][65524/114340 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.enabled = False[18:42:24.727][65524/114004 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b3.val = 0[18:42:24.751][65524/112508 41][35220/35272  1] HTTP: Sent / page to 10.0.5.205[18:42:24.790][65524/114104 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b4.enabled = False[18:42:24.811][65524/114104 42][35220/35272  1] MQTT RCV: hasp/alarm_clock/command/p3b4.val = -1[18:42:24.865][65524/114104 42][35160/35268  1] MQTT RCV: hasp/alarm_clock/command/p1b2.val = 41.5[18:42:24.886][65524/114104 42][35160/35268  1] MQTT RCV: hasp/alarm_clock/command/p1b2.value_str = 41°F[18:42:24.964][65524/114104 42][35004/35260  1] MQTT RCV: hasp/alarm_clock/command/p1b3.val = 59.9[18:42:24.986][65524/114104 42][35004/35260  1] MQTT RCV: hasp/alarm_clock/comman

It almost looks like it keeps appending the text and putting out the entire message again.

That being said I see the same thing in the expected log file name:

2022-02-02T23:49:45.417725+00:00 10.0.11.126 nd/p2b66.val = 30.76171875[18:48:45.759][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b72.text = OK 6 ms[18:48:45.788][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b67.val = 58.4423828125[18:48:45.809][65524/114104 42][35220/35664  2] MQTT RCV: hasp/alarm_clock/command/p2b68.val = 52.263671875[18:49:00.008][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p0b1.text = 06:49PM[18:49:45.383][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b61.val = 0.4
2022-02-02T23:49:45.643103+00:00 10.0.11.126 nd/p2b66.val = 30.76171875[18:48:45.759][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b72.text = OK 6 ms[18:48:45.788][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b67.val = 58.4423828125[18:48:45.809][65524/114104 42][35220/35664  2] MQTT RCV: hasp/alarm_clock/command/p2b68.val = 52.263671875[18:49:00.008][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p0b1.text = 06:49PM[18:49:45.383][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b61.val = 0.4[18:49:45.611][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b61.value_str = Cetus 0.4
2022-02-02T23:49:45.698010+00:00 10.0.11.126 nd/p2b66.val = 30.76171875[18:48:45.759][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b72.text = OK 6 ms[18:48:45.788][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b67.val = 58.4423828125[18:48:45.809][65524/114104 42][35220/35664  2] MQTT RCV: hasp/alarm_clock/command/p2b68.val = 52.263671875[18:49:00.008][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p0b1.text = 06:49PM[18:49:45.383][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b61.val = 0.4[18:49:45.611][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b61.value_str = Cetus 0.4[18:49:45.665][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b65.val = 3.931640625
2022-02-02T23:49:45.719081+00:00 10.0.11.126 nd/p2b66.val = 30.76171875[18:48:45.759][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b72.text = OK 6 ms[18:48:45.788][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b67.val = 58.4423828125[18:48:45.809][65524/114104 42][35220/35664  2] MQTT RCV: hasp/alarm_clock/command/p2b68.val = 52.263671875[18:49:00.008][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p0b1.text = 06:49PM[18:49:45.383][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b61.val = 0.4[18:49:45.611][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b61.value_str = Cetus 0.4[18:49:45.665][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b65.val = 3.931640625[18:49:45.687][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b66.val = 23.1376953125
2022-02-02T23:49:45.765032+00:00 10.0.11.126 nd/p2b66.val = 30.76171875[18:48:45.759][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b72.text = OK 6 ms[18:48:45.788][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b67.val = 58.4423828125[18:48:45.809][65524/114104 42][35220/35664  2] MQTT RCV: hasp/alarm_clock/command/p2b68.val = 52.263671875[18:49:00.008][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p0b1.text = 06:49PM[18:49:45.383][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b61.val = 0.4[18:49:45.611][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b61.value_str = Cetus 0.4[18:49:45.665][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b65.val = 3.931640625[18:49:45.687][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b66.val = 23.1376953125[18:49:45.734][65524/114104 42][35220/35664  2] MQTT RCV: hasp/alarm_clock/command/p2b67.val = 31.71484375
2022-02-02T23:49:45.985169+00:00 10.0.11.126 nd/p2b66.val = 30.76171875[18:48:45.759][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b72.text = OK 6 ms[18:48:45.788][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b67.val = 58.4423828125[18:48:45.809][65524/114104 42][35220/35664  2] MQTT RCV: hasp/alarm_clock/command/p2b68.val = 52.263671875[18:49:00.008][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p0b1.text = 06:49PM[18:49:45.383][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b61.val = 0.4[18:49:45.611][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b61.value_str = Cetus 0.4[18:49:45.665][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b65.val = 3.931640625[18:49:45.687][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b66.val = 23.1376953125[18:49:45.734][65524/114104 42][35220/35664  2] MQTT RCV: hasp/alarm_clock/command/p2b67.val = 31.71484375[18:49:45.954][65524/114104 42][35220/35744  2] MQTT RCV: hasp/alarm_clock/command/p2b68.val = 51.6923828125

It's just that in some cases the first part of the line is not the host IP address, it's some random truncated text. So I wonder if there is an underlying issue here with the buffer size.

@fvanroie
Copy link
Collaborator Author

fvanroie commented Mar 2, 2022

There is no real buffer reserved for the syslog messages except for the UDP packet size.
So maybe these messages are overflowing the UDP buffer.... but it's hard to tell without a packet capture.

@geiseri
Copy link

geiseri commented Mar 3, 2022

I will see if I can use wireshark to find something. It smells like somehow the buffer isn't clearing and its concatenating, but it could be like you said and the messages are overflowing a buffer on the rsyslog end.

@fvanroie
Copy link
Collaborator Author

Since this is working 99% of the time I will consider this issue as resolved.
If you can provide some hints to when the 1% of the messages are not properly formatted, feel free to re-open it.

fvanroie pushed a commit that referenced this issue Dec 1, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working done The underlying issue has been fixed
Projects
None yet
Development

No branches or pull requests

2 participants