View Issue Details

IDProjectCategoryView StatusLast Update
0004366unrealircdpublic2015-07-19 17:46
ReportersyzopAssigned Tosyzop 
PrioritynormalSeveritymajorReproducibilityhave not tried
Status resolvedResolutionfixed 
Product Version3.4-alpha3 
Target VersionFixed in Version3.4-beta2 
Summary0004366: listener gone, logging stopped
DescriptionHm not sure. Strange random issue... may need some attention.

Port was suddenly closed (like the listener stopped working).
Similarly: *** Notice -- WARNING: Unable to write to '/home/irc/unrealircd/logs/ircd.log': Broken pipe. This warning will not re-appear for at least 5 minutes.

Rather unusual error, "Broken pipe", for a log file.

I'm just reporting it here, in case others see it, amd/or so I can try to reproduce later.
TagsNo tags attached.
3rd party modules

Activities

syzop

2015-06-27 09:12

administrator   ~0018417

I think I just had it again. Nothing was logged but I was able to start a 2nd ircd instance that bound to 2 out of the 5 listeners that should have been taken by the 1st (an ircd launched yesterday). So apparently 2 out of 5 were closed by the old ircd.

Better add some debugging code for this... or something... it's bad.

syzop

2015-06-27 09:12

administrator   ~0018418

marking as confirmed, even though it's only me & random.

syzop

2015-06-27 10:09

administrator   ~0018419

Ah, I did have one port that didn't bind on boot (that was correct, it is in use by something else). Maybe that will confuse things further up?

It's closing the wrong fd somewhere I think, anyway. Seeing how it affected both logging and TCP/IP sockets.

syzop

2015-07-12 20:06

administrator   ~0018481

Hmmm.. haven't nailed this one yet. Played a bit with an unbound port, rehashing and stuff, but no problem.

I did find a close() for non-existant FD caused by nenolod's code, but I actually don't think that was the cause.

syzop

2015-07-12 21:23

administrator   ~0018482

More fun:

[20:31:35] -maintest.test.net- *** Connecting to stats.test.net[127.0.0.1].
[20:31:35] -maintest.test.net- Exiting ssl client stats.test.net[@127.0.0.1.0]: SSL_connect(): Internal OpenSSL error or protocol error
[20:31:35] -maintest.test.net- Lost connection to stats.test.net[127.0.0.1]: SSL_connect(): Internal OpenSSL error or protocol error
[20:31:36] -maintest.test.net- *** Notice -- [BUG] trying to close fd #11 in fd table, but this FD isn't reported open
[20:32:03] * Disconnected
[20:32:04] * Connect retry #1 192.168.5.220 (5667)

(playing with 'openssl s_server -accept 5555 -cert server.cert.pem -key server.key.pem' on the other side)

syzop

2015-07-16 21:43

administrator   ~0018508

Last edited: 2015-07-18 19:09

View 2 revisions

[21:35:31] -maintest.test.net- *** Notice -- No response from services.test.net[127.0.0.1], closing link
[21:35:31] -maintest.test.net- *** Notice -- WARNING: Unable to write to '/home/syzop/unrealircd/logs/ircd.log': Broken pipe. This warning will not re-appear for at least 5 minutes.

lsof shows the log file is no longer open.

I did have a gdb session attached at that time, though... maybe related.


^^ yeah broken pipe log file error may be unrelated. I can cause that with gdb easily.

syzop

2015-07-18 19:08

administrator   ~0018511

Last edited: 2015-07-18 19:09

View 2 revisions

Had it again. no valgrind, no gdb... booted ircd, tried to link in another ircd (this link was incoming), auth failed, fixed the link block on the other side, then had 'connection refused' -- huh? yeah... the listener was gone again. nothing in logs.

Bad.

NOTE: This is with all the abort() code in fd_.... enabled.

syzop

2015-07-18 19:30

administrator   ~0018512

Just had no logging.. was caused by the mass close fd code. I've removed it now. it was doing a close(3), so fd 3 was later suddenly a socket (possibly from c-ares.. not important), and then it was write()'ing logs to that fd which triggered the 'broken pipe'. Makes more sense for a socket, that error :D

syzop

2015-07-19 17:46

administrator   ~0018517

I *hope* this is fixed now.

Issue History

Date Modified Username Field Change
2015-06-19 22:04 syzop New Issue
2015-06-27 09:12 syzop Note Added: 0018417
2015-06-27 09:12 syzop Note Added: 0018418
2015-06-27 09:12 syzop Assigned To => syzop
2015-06-27 09:12 syzop Status new => confirmed
2015-06-27 10:09 syzop Note Added: 0018419
2015-07-12 20:06 syzop Note Added: 0018481
2015-07-12 21:23 syzop Note Added: 0018482
2015-07-16 21:43 syzop Note Added: 0018508
2015-07-18 19:08 syzop Note Added: 0018511
2015-07-18 19:09 syzop Note Edited: 0018508 View Revisions
2015-07-18 19:09 syzop Note Edited: 0018511 View Revisions
2015-07-18 19:30 syzop Note Added: 0018512
2015-07-19 17:46 syzop Note Added: 0018517
2015-07-19 17:46 syzop Status confirmed => resolved
2015-07-19 17:46 syzop Fixed in Version => 3.4-beta2
2015-07-19 17:46 syzop Resolution open => fixed