[GH-ISSUE #40] Checking one specific log file on the client make the harvester to reconnect without any error message #31

New issue

Closed

opened 2026-02-26 05:31:07 +03:00 by kerem · 2 comments

kerem commented

2026-02-26 05:31:07 +03:00

Owner

Originally created by @huafu on GitHub (Sep 30, 2012).
Original GitHub issue: https://github.com/NarrativeScience-old/log.io/issues/40

To help understand my explanation here is a little definitions:

Server 1 (S1)
- Log.io server (LS1)
- Log.io harvester (LH1)
Server 2 (S2)
- Log.io harvester (LS2)

So I have on server S1 with locally running one harvester LH1 and one Log.io server LS1, and another server S2 with an harvester LH2. There isn't a lot of data since I'm just trying Log.io. Everything works perfectly in the client interface, except ONE log file on S2. When I check this log file, I see that I checked it ([Sun Sep 30 2012 10:23:38] INFO: Enabling log file: stream_sc_serv) but immediately after the S2 representative pannel with the list of log files on the left disappear and reappear with everything unchecked and colors changed.
If I don't check it, I see the little dot flashing (I have no more than 2 messages per second in this log file) indicating that there are new messages in this log file (when there are), but as soon as I check it to display the messages in a "Stream", it reloads the section attached to that harvester LH2 on S2, unchecking everything and not allowing me to see any message of course.

The other log files for the save server are working as expected.

Here are some example log lines from that log file (labelled stream_sc_serv in the harvester) making the harvester to reconnect:

2012-09-30 10:40:57     E       msg:[DST 64.12.243.203:63127 sid=1] Socket error while waiting to send data. err=Broken pipe(32)
2012-09-30 10:40:57     I       msg:[DST 64.12.243.203:63127 sid=1] SHOUTcast 1 client connection closed (1 seconds) [Bytes: 65536] Agent: `SHOUTcast Metadata Puller'
2012-09-30 10:40:58     E       msg:[DST 90.84.144.127:15742 sid=1] Timeout waiting to send data (1348994458 1348994428[30] )
2012-09-30 10:40:58     I       msg:[DST 90.84.144.127:15742 sid=1] SHOUTcast 1 client connection closed (42 seconds) [Bytes: 78184] Agent: `NSPlayer/4.1.0.3925'
2012-09-30 10:41:05     I       msg:[DST 205.188.202.172:43734 sid=1] SHOUTcast 1 client connection accepted. SHOUTcast Metadata Puller
2012-09-30 10:41:06     I       msg:[DST 64.12.243.206:4343 sid=1] SHOUTcast 1 client connection accepted. SHOUTcast Metadata Puller
2012-09-30 10:41:06     E       msg:[DST 205.188.202.172:43734 sid=1] Socket error while waiting to send data. err=Broken pipe(32)
2012-09-30 10:41:06     I       msg:[DST 205.188.202.172:43734 sid=1] SHOUTcast 1 client connection closed (1 seconds) [Bytes: 73728] Agent: `SHOUTcast Metadata Puller'
2012-09-30 10:41:06     E       msg:[DST 64.12.243.206:4343 sid=1] Socket error while waiting to send data. err=Broken pipe(32)
2012-09-30 10:41:06     I       msg:[DST 64.12.243.206:4343 sid=1] SHOUTcast 1 client connection closed (0 seconds) [Bytes: 73307] Agent: `SHOUTcast Metadata Puller'
2012-09-30 10:41:15     I       msg:[DST 62.35.11.205:52920 sid=1] SHOUTcast 1 client connection accepted. NSPlayer/4.1.0.3925
2012-09-30 10:41:18     I       msg:[DST 197.251.131.62:50320 sid=1] SHOUTcast 1 client connection accepted. TuneIn Radio
2012-09-30 10:41:26     I       msg:[DST 64.12.243.206:5418 sid=1] SHOUTcast 1 client connection accepted. SHOUTcast Metadata Puller
2012-09-30 10:41:26     E       msg:[DST 62.35.11.205:52920 sid=1] Socket error while waiting to send data. err=Broken pipe(32)
2012-09-30 10:41:26     I       msg:[DST 62.35.11.205:52920 sid=1] SHOUTcast 1 client connection closed (11 seconds) [Bytes: 432950] Agent: `NSPlayer/4.1.0.3925'
2012-09-30 10:41:27     E       msg:[DST 64.12.243.206:5418 sid=1] Socket error while waiting to send data. err=Broken pipe(32)
2012-09-30 10:41:27     I       msg:[DST 64.12.243.206:5418 sid=1] SHOUTcast 1 client connection closed (1 seconds) [Bytes: 73728] Agent: `SHOUTcast Metadata Puller'

And here are the log lines of the harvester responsible to harvest this stream_sc_serv file (and others):

[Sun Sep 30 2012 10:22:30] INFO: Received server heartbeat
[Sun Sep 30 2012 10:22:50] INFO: Received server heartbeat
[Sun Sep 30 2012 10:23:09] INFO: Watching 5 log files,  sent 6 log messages.
[Sun Sep 30 2012 10:23:10] INFO: Received server heartbeat
[Sun Sep 30 2012 10:23:20] INFO: Enabling log file: stream_sc_trans
[Sun Sep 30 2012 10:23:30] INFO: Received server heartbeat
[Sun Sep 30 2012 10:23:34] INFO: Watching: /var/log/log.io/harvester.log (logio_harvester)
[Sun Sep 30 2012 10:23:34] INFO: Watching: /var/log/fail2ban.log (system_fail2ban)
[Sun Sep 30 2012 10:23:34] INFO: Watching: /var/log/auth.log (system_auth)
[Sun Sep 30 2012 10:23:34] INFO: Watching: /home/webradio/log/sc_serv.log (stream_sc_serv)
[Sun Sep 30 2012 10:23:34] INFO: Watching: /home/webradio/log/sc_trans.log (stream_sc_trans)
[Sun Sep 30 2012 10:23:34] INFO: Connected to server, sending announcement...
[Sun Sep 30 2012 10:23:38] INFO: Enabling log file: stream_sc_serv
[Sun Sep 30 2012 10:23:40] INFO: Watching: /var/log/log.io/harvester.log (logio_harvester)
[Sun Sep 30 2012 10:23:40] INFO: Watching: /var/log/fail2ban.log (system_fail2ban)
[Sun Sep 30 2012 10:23:40] INFO: Watching: /var/log/auth.log (system_auth)
[Sun Sep 30 2012 10:23:40] INFO: Watching: /home/webradio/log/sc_serv.log (stream_sc_serv)
[Sun Sep 30 2012 10:23:40] INFO: Watching: /home/webradio/log/sc_trans.log (stream_sc_trans)
[Sun Sep 30 2012 10:23:40] INFO: Connected to server, sending announcement...
[Sun Sep 30 2012 10:23:50] INFO: Received server heartbeat

Originally created by @huafu on GitHub (Sep 30, 2012). Original GitHub issue: https://github.com/NarrativeScience-old/log.io/issues/40 To help understand my explanation here is a little definitions: - Server 1 (S1) - Log.io server (LS1) - Log.io harvester (LH1) - Server 2 (S2) - Log.io harvester (LS2) So I have on server S1 with locally running one harvester LH1 and one Log.io server LS1, and another server S2 with an harvester LH2. There isn't a lot of data since I'm just trying Log.io. Everything works perfectly in the client interface, except ONE log file on S2. When I check this log file, I see that I checked it ([Sun Sep 30 2012 10:23:38] INFO: Enabling log file: stream_sc_serv) but immediately after the S2 representative pannel with the list of log files on the left disappear and reappear with everything unchecked and colors changed. If I don't check it, I see the little dot flashing (I have no more than 2 messages per second in this log file) indicating that there are new messages in this log file (when there are), but as soon as I check it to display the messages in a "Stream", it reloads the section attached to that harvester LH2 on S2, unchecking everything and not allowing me to see any message of course. The other log files for the save server are working as expected. Here are some example log lines from that log file (labelled stream_sc_serv in the harvester) making the harvester to reconnect: ``` 2012-09-30 10:40:57 E msg:[DST 64.12.243.203:63127 sid=1] Socket error while waiting to send data. err=Broken pipe(32) 2012-09-30 10:40:57 I msg:[DST 64.12.243.203:63127 sid=1] SHOUTcast 1 client connection closed (1 seconds) [Bytes: 65536] Agent: `SHOUTcast Metadata Puller' 2012-09-30 10:40:58 E msg:[DST 90.84.144.127:15742 sid=1] Timeout waiting to send data (1348994458 1348994428[30] ) 2012-09-30 10:40:58 I msg:[DST 90.84.144.127:15742 sid=1] SHOUTcast 1 client connection closed (42 seconds) [Bytes: 78184] Agent: `NSPlayer/4.1.0.3925' 2012-09-30 10:41:05 I msg:[DST 205.188.202.172:43734 sid=1] SHOUTcast 1 client connection accepted. SHOUTcast Metadata Puller 2012-09-30 10:41:06 I msg:[DST 64.12.243.206:4343 sid=1] SHOUTcast 1 client connection accepted. SHOUTcast Metadata Puller 2012-09-30 10:41:06 E msg:[DST 205.188.202.172:43734 sid=1] Socket error while waiting to send data. err=Broken pipe(32) 2012-09-30 10:41:06 I msg:[DST 205.188.202.172:43734 sid=1] SHOUTcast 1 client connection closed (1 seconds) [Bytes: 73728] Agent: `SHOUTcast Metadata Puller' 2012-09-30 10:41:06 E msg:[DST 64.12.243.206:4343 sid=1] Socket error while waiting to send data. err=Broken pipe(32) 2012-09-30 10:41:06 I msg:[DST 64.12.243.206:4343 sid=1] SHOUTcast 1 client connection closed (0 seconds) [Bytes: 73307] Agent: `SHOUTcast Metadata Puller' 2012-09-30 10:41:15 I msg:[DST 62.35.11.205:52920 sid=1] SHOUTcast 1 client connection accepted. NSPlayer/4.1.0.3925 2012-09-30 10:41:18 I msg:[DST 197.251.131.62:50320 sid=1] SHOUTcast 1 client connection accepted. TuneIn Radio 2012-09-30 10:41:26 I msg:[DST 64.12.243.206:5418 sid=1] SHOUTcast 1 client connection accepted. SHOUTcast Metadata Puller 2012-09-30 10:41:26 E msg:[DST 62.35.11.205:52920 sid=1] Socket error while waiting to send data. err=Broken pipe(32) 2012-09-30 10:41:26 I msg:[DST 62.35.11.205:52920 sid=1] SHOUTcast 1 client connection closed (11 seconds) [Bytes: 432950] Agent: `NSPlayer/4.1.0.3925' 2012-09-30 10:41:27 E msg:[DST 64.12.243.206:5418 sid=1] Socket error while waiting to send data. err=Broken pipe(32) 2012-09-30 10:41:27 I msg:[DST 64.12.243.206:5418 sid=1] SHOUTcast 1 client connection closed (1 seconds) [Bytes: 73728] Agent: `SHOUTcast Metadata Puller' ``` And here are the log lines of the harvester responsible to harvest this stream_sc_serv file (and others): ``` [Sun Sep 30 2012 10:22:30] INFO: Received server heartbeat [Sun Sep 30 2012 10:22:50] INFO: Received server heartbeat [Sun Sep 30 2012 10:23:09] INFO: Watching 5 log files, sent 6 log messages. [Sun Sep 30 2012 10:23:10] INFO: Received server heartbeat [Sun Sep 30 2012 10:23:20] INFO: Enabling log file: stream_sc_trans [Sun Sep 30 2012 10:23:30] INFO: Received server heartbeat [Sun Sep 30 2012 10:23:34] INFO: Watching: /var/log/log.io/harvester.log (logio_harvester) [Sun Sep 30 2012 10:23:34] INFO: Watching: /var/log/fail2ban.log (system_fail2ban) [Sun Sep 30 2012 10:23:34] INFO: Watching: /var/log/auth.log (system_auth) [Sun Sep 30 2012 10:23:34] INFO: Watching: /home/webradio/log/sc_serv.log (stream_sc_serv) [Sun Sep 30 2012 10:23:34] INFO: Watching: /home/webradio/log/sc_trans.log (stream_sc_trans) [Sun Sep 30 2012 10:23:34] INFO: Connected to server, sending announcement... [Sun Sep 30 2012 10:23:38] INFO: Enabling log file: stream_sc_serv [Sun Sep 30 2012 10:23:40] INFO: Watching: /var/log/log.io/harvester.log (logio_harvester) [Sun Sep 30 2012 10:23:40] INFO: Watching: /var/log/fail2ban.log (system_fail2ban) [Sun Sep 30 2012 10:23:40] INFO: Watching: /var/log/auth.log (system_auth) [Sun Sep 30 2012 10:23:40] INFO: Watching: /home/webradio/log/sc_serv.log (stream_sc_serv) [Sun Sep 30 2012 10:23:40] INFO: Watching: /home/webradio/log/sc_trans.log (stream_sc_trans) [Sun Sep 30 2012 10:23:40] INFO: Connected to server, sending announcement... [Sun Sep 30 2012 10:23:50] INFO: Received server heartbeat ```

kerem closed this issue

2026-02-26 05:31:07 +03:00

kerem commented

2026-02-26 05:31:07 +03:00

Author

Owner

@Coopeh commented on GitHub (Jan 22, 2013):

Just to throw my hat in, I'm seeing the exact same problem today. Was fine when I first installed it all yesterday.

@Coopeh commented on GitHub (Jan 22, 2013): Just to throw my hat in, I'm seeing the exact same problem today. Was fine when I first installed it all yesterday.

kerem commented

2026-02-26 05:31:07 +03:00

Author

Owner

@msmathers commented on GitHub (Feb 21, 2013):

v0.3.0 has a completely rewritten harvester/server/client stack, so this should no longer apply. Feel free to reopen if it continues to happen in v0.3.0.

@msmathers commented on GitHub (Feb 21, 2013): v0.3.0 has a completely rewritten harvester/server/client stack, so this should no longer apply. Feel free to reopen if it continues to happen in v0.3.0.