Modify

Opened 5 years ago

Last modified 20 months ago

#13861 reopened defect

remote syslogging not starting up correctly

Reported by: russell@… Owned by: developers
Priority: normal Milestone: Chaos Calmer 15.05
Component: packages Version: Trunk
Keywords: Cc:

Description

Recent versions of openwrt (persisting in r37268) remote syslogging is not functioning correctly or as before. In /etc/config/system:

[...]
option log_ip   70.102.34.162
option log_port 514
option log_proto udp
[...]

This is apparently related to the conversion to procd. /etc/init.d/log starts and the logread process seems to be started with the correct options:

# hexdump -C < /proc/$(cat /var/run/logread.1.pid)/cmdline
00000000  2f 73 62 69 6e 2f 6c 6f  67 72 65 61 64 00 2d 66  |/sbin/logread.-f|
00000010  00 2d 72 00 37 30 2e 31  30 32 2e 33 34 2e 31 36  |.-r.70.102.34.16|
00000020  32 00 35 31 34 00 2d 70  00 2f 76 61 72 2f 72 75  |2.514.-p./var/ru|
00000030  6e 2f 6c 6f 67 72 65 61  64 2e 31 2e 70 69 64 00  |n/logread.1.pid.|
00000040  2d 75 00                                          |-u.|
00000043

However, messages do not arrive at the remote host where syslog messages are supposed to be sent, at least not until a /etc/init.d/log restart

Attachments (0)

Change History (18)

comment:1 Changed 5 years ago by blogic

can you observe the same behaviour with tcp ?

the udp support for logging is rather new, i will review the code to see if i made an error

comment:2 Changed 5 years ago by john@…

I have exactly the same problem as russell@. My configuration is practically identical.
The only real difference between us is the I use the default protocol (which I believe is TCP).
equipment WNDR3700v2 running r37207.

hexdump -C < /proc/$(cat /var/run/logread.1.pid)/cmdline
00000000  2f 73 62 69 6e 2f 6c 6f  67 72 65 61 64 00 2d 66  |/sbin/logread.-f|
00000010  00 2d 72 00 31 39 32 2e  31 36 38 2e 33 30 2e 31  |.-r.192.168.30.1|
00000020  36 00 35 31 34 00 2d 70  00 2f 76 61 72 2f 72 75  |6.514.-p./var/ru|
00000030  6e 2f 6c 6f 67 72 65 61  64 2e 31 2e 70 69 64 00  |n/logread.1.pid.|
00000040

comment:3 Changed 5 years ago by anonymous

That should read "difference between us is the IP address,"

comment:4 Changed 5 years ago by blogic

  • Resolution set to fixed
  • Status changed from new to closed

[37313] should fix the issue, please retest current trunk and reopen the ticket if the bug is still there

comment:5 Changed 5 years ago by russell@…

  • Resolution fixed deleted
  • Status changed from closed to reopened

Still seeing this bug for UDP at least (don't have a TCP server to test against)

comment:6 Changed 5 years ago by russell@…

... still seeing in r37350

comment:7 Changed 5 years ago by russell@…

See two strace's of the initial (failing) logread:

https://iris.personaltelco.net/~russell/strace-logread.1149

and the succeeding restarted logread:

https://iris.personaltelco.net/~russell/strace-logread.1464

I've diff'd them, but so far have not spotted the problem yet.

comment:8 Changed 5 years ago by russell@…

Retried today on r37493, still not working on ar71xx-generic-wzr-600dhp on boot (works on /etc/init.d/log restart), but was surprised to see that ar71xx-generic-ubnt-airrouter worked on boot! WTF? As of last week, alix2 was showing the same non-workingness on boot. Running tcpdump upstream from the router shows that there is no UDP syslog traffic during boot, but there is on log restart. Blogic, please resurface and help fix this!

comment:9 follow-up: Changed 5 years ago by cat@…

connect() only happens near the end of initial (failing) logread.1149:
connect(2, {sa_family=AF_INET, sin_port=htons(514), sin_addr=inet_addr("70.102.34.162")}, 16) = 0

On the other hand, even the working logread only calls send once:
send(3, "<24>Jul 15 14:40:25 logread[1464]: Logread connected to 70.102.3"..., 75, MSG_NOSIGNAL) = 75

Do you consistently see all log messages for the working case, or only "logread connected"? I would look through the logread sources and figure out why connect() gets called so late.

comment:10 in reply to: ↑ 9 Changed 5 years ago by russell@…

Replying to cat@…:

connect() only happens near the end of initial (failing) logread.1149:
connect(2, {sa_family=AF_INET, sin_port=htons(514), sin_addr=inet_addr("70.102.34.162")}, 16) = 0

On the other hand, even the working logread only calls send once:
send(3, "<24>Jul 15 14:40:25 logread[1464]: Logread connected to 70.102.3"..., 75, MSG_NOSIGNAL) = 75

Do you consistently see all log messages for the working case, or only "logread connected"? I would look through the logread sources and figure out why connect() gets called so late.

Once I restart it, it seems to work normally.

comment:11 Changed 4 years ago by towolf@…

Still present on trunk as of today.

comment:12 Changed 4 years ago by russell@…

The problem is on the ubus side, not the network side. Here is some selected gdb output:

print ctx->sock (from follow_log) (failing) =>

{cb = 0x7702ebb8 <ubus_handle_data>,  fd = 0, eof = true, error = true, registered = false, flags = 0 '\000'}

(restarted/succeeding) =>

{cb = 0x7769ebb8 <ubus_handle_data>, fd = 0, eof = false, error = false, registered = true, flags = 9 '\t'}

For some reason, logread is getting an end-of-file (etc) when launched during boot, but not when restarted.

comment:13 follow-up: Changed 4 years ago by john@…

I added the following line to my rc.local and it seems to have solved the problem.

/sbin/logread -f -u -r 192.168.n.n 514 -p /var/run/logread.1.pid &

comment:14 in reply to: ↑ 13 Changed 4 years ago by russell@…

Replying to john@…:

I added the following line to my rc.local and it seems to have solved the problem. [...]

That's more of a band-aid than a solution, but okay.

comment:15 Changed 4 years ago by russell@…

This appears to have been fixed in some changes around r37799. Thanks jow!

comment:16 Changed 4 years ago by anonymous

not fixed yet

comment:17 Changed 2 years ago by tuttle@…

I still see the bug.

comment:18 Changed 20 months ago by anonymous

Same here

Add Comment

Modify Ticket

Action
as reopened .
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.