Rsyslog 4.4.2 TCP Hangup??

General discussions here

Moderator: rgerhards

Rsyslog 4.4.2 TCP Hangup??

Postby dustorobusto » Mon Mar 08, 2010 2:41 pm

I can't be the first one to have this issue, but I am not having much luck finding the right thread. I am encrypting rsyslog traffic with a gnutls setup, which works great for anywhere from 20min to 3-4 days. Eventually, the TCP connections seem to start hanging. I read in one thread that it is an inherent problem with GNUTLS?? Is this true? Or is there a way to solve this besides converting to an STUNNEL setup? Here is what my server ends up doing (over and over) in debug mode.. (I am using all Ubuntu servers and clients) Eventually this process consumes the memory and crashes the service. When I restart it seems to do some clean-up processes and then the service starts fine but eventually has the same problem.

Code: Select all


New connect on NSD 0x25ef380.
1050.666029845:imtcp.c: hasRcvInBuffer on nsd 0x25ef5e0: pszRcvBuf (nil), lenRcvBuf 0
1050.666039278:imtcp.c: hasRcvInBuffer on nsd 0x25eab60: pszRcvBuf (nil), lenRcvBuf 0
1050.666048115:imtcp.c: hasRcvInBuffer on nsd 0x25f0540: pszRcvBuf 0x25f0650, lenRcvBuf 89
1050.666056856:imtcp.c: hasRcvInBuffer on nsd 0x25cb090: pszRcvBuf 0x25fa890, lenRcvBuf 107
1050.666065701:imtcp.c: hasRcvInBuffer on nsd 0x25cd4e0: pszRcvBuf 0x26020a0, lenRcvBuf -1
1050.666074456:imtcp.c: hasRcvInBuffer on nsd 0x25f02c0: pszRcvBuf 0x260c980, lenRcvBuf -1
1050.666083408:imtcp.c: hasRcvInBuffer on nsd 0x25f44f0: pszRcvBuf 0x2615730, lenRcvBuf -1
1050.666092129:imtcp.c: hasRcvInBuffer on nsd 0x25efda0: pszRcvBuf 0x261f850, lenRcvBuf -1
1050.666100923:imtcp.c: hasRcvInBuffer on nsd 0x26186d0: pszRcvBuf 0x2628e10, lenRcvBuf -1
1050.666109738:imtcp.c: hasRcvInBuffer on nsd 0x26235f0: pszRcvBuf 0x2632b60, lenRcvBuf -1
1050.666118489:imtcp.c: hasRcvInBuffer on nsd 0x262b030: pszRcvBuf 0x263c390, lenRcvBuf -1
1050.666127304:imtcp.c: hasRcvInBuffer on nsd 0x262cbb0: pszRcvBuf 0x2645f70, lenRcvBuf -1
1050.666136740:imtcp.c: hasRcvInBuffer on nsd 0x25ef5e0: pszRcvBuf (nil), lenRcvBuf 0
1050.666144877:imtcp.c: New connect on NSD 0x25f0470.
1050.666158657:imtcp.c: hasRcvInBuffer on nsd 0x25eab60: pszRcvBuf (nil), lenRcvBuf 0
1050.666167192:imtcp.c: New connect on NSD 0x25ef380.
1050.666185215:imtcp.c: hasRcvInBuffer on nsd 0x25ef5e0: pszRcvBuf (nil), lenRcvBuf 0
1050.666194634:imtcp.c: hasRcvInBuffer on nsd 0x25eab60: pszRcvBuf (nil), lenRcvBuf 0
1050.666203344:imtcp.c: hasRcvInBuffer on nsd 0x25f0540: pszRcvBuf 0x25f0650, lenRcvBuf 89
1050.666212030:imtcp.c: hasRcvInBuffer on nsd 0x25cb090: pszRcvBuf 0x25fa890, lenRcvBuf 107
1050.666220817:imtcp.c: hasRcvInBuffer on nsd 0x25cd4e0: pszRcvBuf 0x26020a0, lenRcvBuf -1
1050.666229549:imtcp.c: hasRcvInBuffer on nsd 0x25f02c0: pszRcvBuf 0x260c980, lenRcvBuf -1
1050.666238288:imtcp.c: hasRcvInBuffer on nsd 0x25f44f0: pszRcvBuf 0x2615730, lenRcvBuf -1
1050.666247025:imtcp.c: hasRcvInBuffer on nsd 0x25efda0: pszRcvBuf 0x261f850, lenRcvBuf -1
1050.666255734:imtcp.c: hasRcvInBuffer on nsd 0x26186d0: pszRcvBuf 0x2628e10, lenRcvBuf -1
1050.666264661:imtcp.c: hasRcvInBuffer on nsd 0x26235f0: pszRcvBuf 0x2632b60, lenRcvBuf -1
1050.666273408:imtcp.c: hasRcvInBuffer on nsd 0x262b030: pszRcvBuf 0x263c390, lenRcvBuf -1
1050.666282223:imtcp.c: hasRcvInBuffer on nsd 0x262cbb0: pszRcvBuf 0x2645f70, lenRcvBuf -1
1050.666291587:imtcp.c: hasRcvInBuffer on nsd 0x25ef5e0: pszRcvBuf (nil), lenRcvBuf 0
1050.666299640:imtcp.c: New connect on NSD 0x25f0470.



Anyhelp is much appreciated. If you need more info let me know...I do manage another Fedora based network that uses rsyslog/TLS and it works great!!! However, there are a lot less logs over there.

-Dustin Rogers
dustorobusto
Avarage
 
Posts: 11
Joined: Sun Mar 07, 2010 11:50 pm

Professional Services Information

  • Custom written rsyslog.conf?
  • Maintenance Contract?
  • Installation support?

Re: Rsyslog 4.4.2 TCP Hangup??

Postby petersabaini » Mon Mar 15, 2010 2:33 pm

I think I have a similar problem. Randomly (more with more intense usage) rsyslog seems to hang. I also use TLS transport. When running the rsyslog server in debug mode I get this (among a lot of other output):

Code: Select all
9403.977373539:f75c4b90: wtpAdviseMaxWorkers signals busy
9403.977388893:f5dc1b90: hasRcvInBuffer on nsd 0x80cda90: pszRcvBuf 0x818fef0, lenRcvBuf -1
9403.977405096:f75c4b90: action 1 queue: EnqueueMsg advised worker start
9403.977426113:f5dc1b90: --------<NSDSEL_PTCP> calling select, active fds (max 11):
9403.977447000:f7dc5b90: action 1 queue: entry deleted, state 0, size now 0 entries
9403.977462157:f75c4b90: main Q:Reg/w0: worker IDLE, waiting for work.
9403.977479449:f5dc1b90: 6
9403.977498751:f7dc5b90:  vs-syslog.telbiomed.at
9403.977511554:f5dc1b90: 7
9403.977530281:f7dc5b90:  vs-syslog.telbiomed.at:10514/tcp
9403.977543066:f5dc1b90: 8 9 10 11
9403.977704645:f7dc5b90: TCP sent 166 bytes, requested 166
9403.977719380:f7dc5b90: action 1 queue:Reg/w0: worker IDLE, waiting for work.
9403.990873224:f5dc1b90: hasRcvInBuffer on nsd 0x80d2938: pszRcvBuf (nil), lenRcvBuf 0
9403.990886104:f5dc1b90: hasRcvInBuffer on nsd 0x80c9850: pszRcvBuf 0x8116fb0, lenRcvBuf -1
9403.990897423:f5dc1b90: hasRcvInBuffer on nsd 0x80c7e30: pszRcvBuf 0x815b7e8, lenRcvBuf -1
9403.990913113:f5dc1b90: hasRcvInBuffer on nsd 0x811a478: pszRcvBuf 0x81377d0, lenRcvBuf -1
9403.990924463:f5dc1b90: hasRcvInBuffer on nsd 0x80c95e0: pszRcvBuf 0x8166fa0, lenRcvBuf -1
9403.990935063:f5dc1b90: netstream 0x80d1fc0 with new data
9403.990959310:f5dc1b90: GnuTLS receive requires a retry (this most probably is OK and no error condition)
9403.990971069:f5dc1b90: gtlsRecordRecv return. nsd 0x80c95e0, iRet -2100, lenRcvd -28, lenRcvBuf -1, ptrRcvBuf 183
9403.990980949:f5dc1b90: gtlsRcv return. nsd 0x80c95e0, iRet -2100, lenRcvBuf -1, ptrRcvBuf 183
9403.990998481:f5dc1b90: hasRcvInBuffer on nsd 0x80d2938: pszRcvBuf (nil), lenRcvBuf 0
9403.991032338:f5dc1b90: hasRcvInBuffer on nsd 0x80c9850: pszRcvBuf 0x8116fb0, lenRcvBuf -1
9403.991044185:f5dc1b90: hasRcvInBuffer on nsd 0x80c7e30: pszRcvBuf 0x815b7e8, lenRcvBuf -1
9403.991055030:f5dc1b90: hasRcvInBuffer on nsd 0x811a478: pszRcvBuf 0x81377d0, lenRcvBuf -1
9403.991076652:f5dc1b90: hasRcvInBuffer on nsd 0x80c95e0: pszRcvBuf 0x8166fa0, lenRcvBuf -1
9403.991087897:f5dc1b90: hasRcvInBuffer on nsd 0x80cda90: pszRcvBuf 0x818fef0, lenRcvBuf -1
9403.991098677:f5dc1b90: --------<NSDSEL_PTCP> calling select, active fds (max 11): 6 7 8 9 10 11
9403.991130486:f5dc1b90: hasRcvInBuffer on nsd 0x80d2938: pszRcvBuf (nil), lenRcvBuf 0
9403.991141519:f5dc1b90: hasRcvInBuffer on nsd 0x80c9850: pszRcvBuf 0x8116fb0, lenRcvBuf -1
9403.991152266:f5dc1b90: hasRcvInBuffer on nsd 0x80c7e30: pszRcvBuf 0x815b7e8, lenRcvBuf -1
9403.991162466:f5dc1b90: hasRcvInBuffer on nsd 0x811a478: pszRcvBuf 0x81377d0, lenRcvBuf -1
9403.991173055:f5dc1b90: hasRcvInBuffer on nsd 0x80c95e0: pszRcvBuf 0x8166fa0, lenRcvBuf -1
9403.991182308:f5dc1b90: GnuTLS requested retry of 2 operation - executing
9403.991190140:f5dc1b90: retrying gtls recv, nsd: 0x80c95e0
9403.991523404:f5dc1b90: gtlsRecordRecv return. nsd 0x80c95e0, iRet 0, lenRcvd 4688, lenRcvBuf 4688, ptrRcvBuf 0
9403.991534851:f5dc1b90: hasRcvInBuffer on nsd 0x80cda90: pszRcvBuf 0x818fef0, lenRcvBuf -1
9403.991553438:f5dc1b90: hasRcvInBuffer on nsd 0x80d2938: pszRcvBuf (nil), lenRcvBuf 0
9403.991565060:f5dc1b90: hasRcvInBuffer on nsd 0x80c9850: pszRcvBuf 0x8116fb0, lenRcvBuf -1
9403.991586402:f5dc1b90: hasRcvInBuffer on nsd 0x811a478: pszRcvBuf 0x81377d0, lenRcvBuf -1
9403.991597070:f5dc1b90: hasRcvInBuffer on nsd 0x80c95e0: pszRcvBuf 0x8166fa0, lenRcvBuf 4688
9403.991607775:f5dc1b90: hasRcvInBuffer on nsd 0x80cda90: pszRcvBuf 0x818fef0, lenRcvBuf -1
9403.991631129:f5dc1b90: hasRcvInBuffer on nsd 0x80d2938: pszRcvBuf (nil), lenRcvBuf 0
9403.991641601:f5dc1b90: New connect on NSD 0x80d24b0.
9403.991674838:f5dc1b90: hasRcvInBuffer on nsd 0x80d2938: pszRcvBuf (nil), lenRcvBuf 0
9403.991686333:f5dc1b90: hasRcvInBuffer on nsd 0x80c9850: pszRcvBuf 0x8116fb0, lenRcvBuf -1
9403.991697320:f5dc1b90: hasRcvInBuffer on nsd 0x80c7e30: pszRcvBuf 0x815b7e8, lenRcvBuf -1
9403.991707630:f5dc1b90: hasRcvInBuffer on nsd 0x811a478: pszRcvBuf 0x81377d0, lenRcvBuf -1
9403.991717872:f5dc1b90: hasRcvInBuffer on nsd 0x80c95e0: pszRcvBuf 0x8166fa0, lenRcvBuf 4688
9403.991728557:f5dc1b90: hasRcvInBuffer on nsd 0x80cda90: pszRcvBuf 0x818fef0, lenRcvBuf -1
9403.991739225:f5dc1b90: hasRcvInBuffer on nsd 0x80d2938: pszRcvBuf (nil), lenRcvBuf 0
9403.991749094:f5dc1b90: New connect on NSD 0x80d24b0.
9403.991772079:f5dc1b90: hasRcvInBuffer on nsd 0x80d2938: pszRcvBuf (nil), lenRcvBuf 0
9403.991783309:f5dc1b90: hasRcvInBuffer on nsd 0x80c9850: pszRcvBuf 0x8116fb0, lenRcvBuf -1
9403.991794259:f5dc1b90: hasRcvInBuffer on nsd 0x80c7e30: pszRcvBuf 0x815b7e8, lenRcvBuf -1
9403.991804603:f5dc1b90: hasRcvInBuffer on nsd 0x811a478: pszRcvBuf 0x81377d0, lenRcvBuf -1
9403.991815276:f5dc1b90: hasRcvInBuffer on nsd 0x80c95e0: pszRcvBuf 0x8166fa0, lenRcvBuf 4688
9403.991826075:f5dc1b90: hasRcvInBuffer on nsd 0x80cda90: pszRcvBuf 0x818fef0, lenRcvBuf -1
9403.991836743:f5dc1b90: hasRcvInBuffer on nsd 0x80d2938: pszRcvBuf (nil), lenRcvBuf 0
9403.991846578:f5dc1b90: New connect on NSD 0x80d24b0.
9403.991868712:f5dc1b90: hasRcvInBuffer on nsd 0x80d2938: pszRcvBuf (nil), lenRcvBuf 0
9403.991879922:f5dc1b90: hasRcvInBuffer on nsd 0x80c9850: pszRcvBuf 0x8116fb0, lenRcvBuf -1
9403.991890717:f5dc1b90: hasRcvInBuffer on nsd 0x80c7e30: pszRcvBuf 0x815b7e8, lenRcvBuf -1
9403.991901146:f5dc1b90: hasRcvInBuffer on nsd 0x811a478: pszRcvBuf 0x81377d0, lenRcvBuf -1
9403.991911541:f5dc1b90: hasRcvInBuffer on nsd 0x80c95e0: pszRcvBuf 0x8166fa0, lenRcvBuf 4688
9403.991922199:f5dc1b90: hasRcvInBuffer on nsd 0x80cda90: pszRcvBuf 0x818fef0, lenRcvBuf -1
9403.991932806:f5dc1b90: hasRcvInBuffer on nsd 0x80d2938: pszRcvBuf (nil), lenRcvBuf 0
9403.991942526:f5dc1b90: New connect on NSD 0x80d24b0.
9403.991964485:f5dc1b90: hasRcvInBuffer on nsd 0x80d2938: pszRcvBuf (nil), lenRcvBuf 0
9403.991975703:f5dc1b90: hasRcvInBuffer on nsd 0x80c9850: pszRcvBuf 0x8116fb0, lenRcvBuf -1
9403.991986702:f5dc1b90: hasRcvInBuffer on nsd 0x80c7e30: pszRcvBuf 0x815b7e8, lenRcvBuf -1
9403.991996882:f5dc1b90: hasRcvInBuffer on nsd 0x811a478: pszRcvBuf 0x81377d0, lenRcvBuf -1
9403.992007604:f5dc1b90: hasRcvInBuffer on nsd 0x80c95e0: pszRcvBuf 0x8166fa0, lenRcvBuf 4688
9403.992018359:f5dc1b90: hasRcvInBuffer on nsd 0x80cda90: pszRcvBuf 0x818fef0, lenRcvBuf -1
9403.992029102:f5dc1b90: hasRcvInBuffer on nsd 0x80d2938: pszRcvBuf (nil), lenRcvBuf 0
9403.992038941:f5dc1b90: New connect on NSD 0x80d24b0.


After this rsyslog seems to spin, ie. the last part (New connect on NSD ... ) is repeated over and over until stopped.
petersabaini
Avarage
 
Posts: 12
Joined: Tue Nov 10, 2009 10:02 pm

Re: Rsyslog 4.4.2 TCP Hangup??

Postby petersabaini » Tue Mar 16, 2010 9:24 am

Postscript: what particularly caught my eye is the line

Code: Select all
9403.990959310:f5dc1b90: GnuTLS receive requires a retry (this most probably is OK and no error condition)


Its the only time this message occurs in the log. Maybe in this case the retry indeed is problematic?
petersabaini
Avarage
 
Posts: 12
Joined: Tue Nov 10, 2009 10:02 pm

Re: Rsyslog 4.4.2 TCP Hangup??

Postby dustorobusto » Wed Mar 17, 2010 3:17 pm

Yes, I recieve the "error probably okay" also sometimes.
Does your server eat up all of the CPU and RAM until it crashes also? I believe (during this process) that I still recieve logs, but there is no record displayed on the console. I used the 'ulimit -s 512' command and that shortens the stack size, so individual processes will take less RAM, but eventually it still eats it all up and crashes the server.
From what I read, I am pretty sure this is a problem with the way GNUTLS presents the certificates. I just would like verification before I move on to another secure rsyslog (or other I suppose) solution.
dustorobusto
Avarage
 
Posts: 11
Joined: Sun Mar 07, 2010 11:50 pm

Re: Rsyslog 4.4.2 TCP Hangup??

Postby petersabaini » Wed Mar 17, 2010 3:56 pm

On my machine it just spins, ie. does not leak memory.

This bit repeating all the time:

Code: Select all
1050.666048115:imtcp.c: hasRcvInBuffer on nsd 0x25f0540: pszRcvBuf 0x25f0650, lenRcvBuf 89
1050.666056856:imtcp.c: hasRcvInBuffer on nsd 0x25cb090: pszRcvBuf 0x25fa890, lenRcvBuf 107
1050.666065701:imtcp.c: hasRcvInBuffer on nsd 0x25cd4e0: pszRcvBuf 0x26020a0, lenRcvBuf -1
1050.666074456:imtcp.c: hasRcvInBuffer on nsd 0x25f02c0: pszRcvBuf 0x260c980, lenRcvBuf -1
1050.666083408:imtcp.c: hasRcvInBuffer on nsd 0x25f44f0: pszRcvBuf 0x2615730, lenRcvBuf -1
1050.666092129:imtcp.c: hasRcvInBuffer on nsd 0x25efda0: pszRcvBuf 0x261f850, lenRcvBuf -1
1050.666100923:imtcp.c: hasRcvInBuffer on nsd 0x26186d0: pszRcvBuf 0x2628e10, lenRcvBuf -1
1050.666109738:imtcp.c: hasRcvInBuffer on nsd 0x26235f0: pszRcvBuf 0x2632b60, lenRcvBuf -1
1050.666118489:imtcp.c: hasRcvInBuffer on nsd 0x262b030: pszRcvBuf 0x263c390, lenRcvBuf -1
1050.666127304:imtcp.c: hasRcvInBuffer on nsd 0x262cbb0: pszRcvBuf 0x2645f70, lenRcvBuf -1


looks like rsyslog is trying to empty buffers but fails to do so. Maybe the underlying connection is broken but rsyslog does not notice or something like that.
petersabaini
Avarage
 
Posts: 12
Joined: Tue Nov 10, 2009 10:02 pm

Re: Rsyslog 4.4.2 TCP Hangup??

Postby dustorobusto » Sat Mar 20, 2010 2:19 pm

Now that I have observed more, I do not think it is crashing the server. Instead, I think it was crashing the sshd session that I was running rsyslog (in debug mode), by pushing too much data through it and to my console at home. I have it running in the background right now, but I have a feeling it is getting caught in the loop still, I just can't see it.
dustorobusto
Avarage
 
Posts: 11
Joined: Sun Mar 07, 2010 11:50 pm

Re: Rsyslog 4.4.2 TCP Hangup??

Postby petersabaini » Tue Mar 23, 2010 10:40 am

I guess I'm seeing the behaviour fixed by this: http://git.adiscon.com/?p=rsyslog.git;a ... f76c020792

A newer rsyslog did not exhibit the symptoms I've seen (so far).
petersabaini
Avarage
 
Posts: 12
Joined: Tue Nov 10, 2009 10:02 pm

Re: Rsyslog 4.4.2 TCP Hangup??

Postby dustorobusto » Wed Apr 14, 2010 3:28 am

Okay...been a little while...but basically I had to try this patch out. The patch didn't seem to apply with the 'patch' command, so I just copy/pasted it in near line 1325. I could see what they are trying to do, and it should work, but when I execute the daemon, I ended up in one of those same loops that we were seeing before. I figured...well...maybe I will upgrade the server to rsyslog 5.2, which I did, compiled with gnutls enabled, and all...

Now it has been running kinda stable as 5.2, but at certain points it does actually eat up all of the memory and puts the cpu usage up to %100, even though the CPU idle actually sits at about %50, which is probably due to the SMP. I can show screenshots of the 'out of memory' logs that get sent right before the rsyslog service crashes and restarts, and I can show the top readout while it is happening if you wish. Very intermittent problem though. (It is nice not having the 'loop-type' lockup, but I don't like the memory lock up because it really slows all of the server processes!)

I explained to one of my colleagues and he said maybe it is because all of my clients are running 4.4.2, and that maybe I should apply the patch to every client. So that is my question...should I be applying the patch to all of the clients? (or just upgrade the clients also to 5.2? (takes more time)) Would either of these solutions work??

Thank you for your time,
-Dustin Rogers
P.S. I loaded the mysql module finally and I think it is awesome.
dustorobusto
Avarage
 
Posts: 11
Joined: Sun Mar 07, 2010 11:50 pm

Re: Rsyslog 4.4.2 TCP Hangup??

Postby dustorobusto » Thu Apr 15, 2010 3:52 am

Here is the top readout of the process eating all of the ram and one CPU core...

Code: Select all
top - 21:50:09 up 2 days, 14:15,  1 user,  load average: 1.05, 1.02, 0.91
Tasks: 110 total,   1 running, 109 sleeping,   0 stopped,   0 zombie
Cpu(s): 23.8%us, 25.1%sy,  0.0%ni, 49.1%id,  0.8%wa,  0.0%hi,  1.2%si,  0.0%st
Mem:   4058400k total,  3157680k used,   900720k free,    10148k buffers
Swap:        0k total,        0k used,        0k free,    46336k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
16002 root      20   0 2909m 2.7g 2380 S  100 69.9  43:43.57 rsyslogd


It is still logging itself, but logs from the other clients have stopped.
dustorobusto
Avarage
 
Posts: 11
Joined: Sun Mar 07, 2010 11:50 pm

Re: Rsyslog 4.4.2 TCP Hangup??

Postby petersabaini » Thu Apr 22, 2010 12:21 pm

I haven't had much time to devote to this, but after some trying I was able to also get the newer rsyslog (5.2) to hang. Hangs occured when executing from two clients some variation of:

Code: Select all
% python
[...]
>>> import syslog, time
>>> for i in xrange(100000):
...     syslog.syslog(("testmessage no. %s" % i) + "filler " * 1000)
...     time.sleep(0.02)


Ie. sending a stream of large messages

Interestingly, instead of just spinning it now also eats up all memory till it gets OOM'ed
petersabaini
Avarage
 
Posts: 12
Joined: Tue Nov 10, 2009 10:02 pm

Re: Rsyslog 4.4.2 TCP Hangup??

Postby petersabaini » Thu Apr 22, 2010 12:57 pm

petersabaini wrote:... the newer rsyslog (5.2) to hang. Hangs occured when executing from two clients some variation of:


Correction: rsyslog version 5.4.0
petersabaini
Avarage
 
Posts: 12
Joined: Tue Nov 10, 2009 10:02 pm

Re: Rsyslog 4.4.2 TCP Hangup??

Postby dustorobusto » Sat Apr 24, 2010 3:35 pm

I can't understand that code. I think you are saying that two different clients are trying to send large amounts of messages at the same time...I know it is weak, but I am going to write a quick cron job to restart the server service every four hours or so. Just to workaround the hang-up to some degree. Let me know if you have a better suggestion.
dustorobusto
Avarage
 
Posts: 11
Joined: Sun Mar 07, 2010 11:50 pm

Re: Rsyslog 4.4.2 TCP Hangup??

Postby mstanisl » Mon May 24, 2010 6:02 pm

I have been having the same issue with GNUTLS enabled. I've tried *many* versions of rsyslog, built my own packages on native systems with different libraries and architectures... same results. Sometimes everything will be fine for a few minutes, other times, hours... other times, just seconds. The debug buffer will fill-up with the content below as everyone else has seen. I'm beginning to think an SSL tunnel may have to be used. I love the other features of rsyslog, but this is really keeping the software from being truly production ready for a company that cares about transport security.

Does *anyone* have a fix yet?

5732.661990000:40800940: regular consumer finished, iret=0, szlog 0 sz phys 1
5732.662006000:40800940: XXX: enqueueing data element 0 of 1
5732.662023000:40800940: we deleted 1 objects and enqueued 0 objects
5732.662040000:40800940: delete batch from store, new sizes: log 0, phys 0
5732.662057000:40800940: regular consumer finished, iret=4, szlog 0 sz phys 0
5732.662074000:40800940: main Q:Reg/w0: worker IDLE, waiting for work.
5732.677303000:42003940: hasRcvInBuffer on nsd 0x6c0e40: pszRcvBuf (nil), lenRcvBuf 0
5732.677329000:42003940: hasRcvInBuffer on nsd 0x6bd3e0: pszRcvBuf 0x6c2070, lenRcvBuf -1
5732.677347000:42003940: hasRcvInBuffer on nsd 0x6c73b0: pszRcvBuf 0x6cbdd0, lenRcvBuf -1
5732.677364000:42003940: hasRcvInBuffer on nsd 0x6821a0: pszRcvBuf 0x6d5ec0, lenRcvBuf -1
5732.677381000:42003940: netstream 0x6c4720 with new data
5732.677411000:42003940: GnuTLS receive requires a retry (this most probably is OK and no error condition)
5732.677429000:42003940: gtlsRecordRecv return. nsd 0x6821a0, iRet -2100, lenRcvd -28, lenRcvBuf -1, ptrRcvBuf 70
5732.677446000:42003940: gtlsRcv return. nsd 0x6821a0, iRet -2100, lenRcvBuf -1, ptrRcvBuf 70
5732.677469000:42003940: hasRcvInBuffer on nsd 0x6c0e40: pszRcvBuf (nil), lenRcvBuf 0
5732.677486000:42003940: hasRcvInBuffer on nsd 0x6bd3e0: pszRcvBuf 0x6c2070, lenRcvBuf -1
5732.677503000:42003940: hasRcvInBuffer on nsd 0x6c73b0: pszRcvBuf 0x6cbdd0, lenRcvBuf -1
5732.677520000:42003940: hasRcvInBuffer on nsd 0x6821a0: pszRcvBuf 0x6d5ec0, lenRcvBuf -1
5732.677538000:42003940: hasRcvInBuffer on nsd 0x6c5fa0: pszRcvBuf 0x6dfcb0, lenRcvBuf -1
5732.677555000:42003940: hasRcvInBuffer on nsd 0x6e94b0: pszRcvBuf 0x6eb180, lenRcvBuf -1
5732.677572000:42003940: hasRcvInBuffer on nsd 0x6ef770: pszRcvBuf 0x6f7c70, lenRcvBuf -1
5732.677589000:42003940: --------<NSDSEL_PTCP> calling select, active fds (max 29): 10 11 15 18 21 28 29
5732.679047000:42003940: hasRcvInBuffer on nsd 0x6c0e40: pszRcvBuf (nil), lenRcvBuf 0
5732.679066000:42003940: hasRcvInBuffer on nsd 0x6bd3e0: pszRcvBuf 0x6c2070, lenRcvBuf -1
5732.679083000:42003940: hasRcvInBuffer on nsd 0x6c73b0: pszRcvBuf 0x6cbdd0, lenRcvBuf -1
5732.679101000:42003940: hasRcvInBuffer on nsd 0x6821a0: pszRcvBuf 0x6d5ec0, lenRcvBuf -1
5732.679122000:42003940: GnuTLS requested retry of 2 operation - executing
5732.679139000:42003940: retrying gtls recv, nsd: 0x6821a0
5732.679226000:42003940: gtlsRecordRecv return. nsd 0x6821a0, iRet 0, lenRcvd 70, lenRcvBuf 70, ptrRcvBuf 0
5732.679245000:42003940: hasRcvInBuffer on nsd 0x6c5fa0: pszRcvBuf 0x6dfcb0, lenRcvBuf -1
5732.679262000:42003940: hasRcvInBuffer on nsd 0x6e94b0: pszRcvBuf 0x6eb180, lenRcvBuf -1
5732.679279000:42003940: hasRcvInBuffer on nsd 0x6ef770: pszRcvBuf 0x6f7c70, lenRcvBuf -1
5732.679301000:42003940: hasRcvInBuffer on nsd 0x6c0e40: pszRcvBuf (nil), lenRcvBuf 0
5732.679319000:42003940: hasRcvInBuffer on nsd 0x6bd3e0: pszRcvBuf 0x6c2070, lenRcvBuf -1
5732.679336000:42003940: hasRcvInBuffer on nsd 0x6c73b0: pszRcvBuf 0x6cbdd0, lenRcvBuf -1
5732.679353000:42003940: hasRcvInBuffer on nsd 0x6821a0: pszRcvBuf 0x6d5ec0, lenRcvBuf 70
5732.679370000:42003940: hasRcvInBuffer on nsd 0x6c5fa0: pszRcvBuf 0x6dfcb0, lenRcvBuf -1
5732.679407000:42003940: hasRcvInBuffer on nsd 0x6e94b0: pszRcvBuf 0x6eb180, lenRcvBuf -1
5732.679424000:42003940: hasRcvInBuffer on nsd 0x6ef770: pszRcvBuf 0x6f7c70, lenRcvBuf -1
5732.679442000:42003940: hasRcvInBuffer on nsd 0x6c0e40: pszRcvBuf (nil), lenRcvBuf 0
5732.679458000:42003940: New connect on NSD 0x6ba750.
5732.679509000:42003940: hasRcvInBuffer on nsd 0x6c0e40: pszRcvBuf (nil), lenRcvBuf 0
5732.679527000:42003940: hasRcvInBuffer on nsd 0x6bd3e0: pszRcvBuf 0x6c2070, lenRcvBuf -1
5732.679547000:42003940: hasRcvInBuffer on nsd 0x6c73b0: pszRcvBuf 0x6cbdd0, lenRcvBuf -1
5732.679564000:42003940: hasRcvInBuffer on nsd 0x6821a0: pszRcvBuf 0x6d5ec0, lenRcvBuf 70
5732.679580000:42003940: hasRcvInBuffer on nsd 0x6c5fa0: pszRcvBuf 0x6dfcb0, lenRcvBuf -1
5732.679612000:42003940: hasRcvInBuffer on nsd 0x6e94b0: pszRcvBuf 0x6eb180, lenRcvBuf -1
5732.679629000:42003940: hasRcvInBuffer on nsd 0x6ef770: pszRcvBuf 0x6f7c70, lenRcvBuf -1
5732.679647000:42003940: hasRcvInBuffer on nsd 0x6c0e40: pszRcvBuf (nil), lenRcvBuf 0
5732.679663000:42003940: New connect on NSD 0x6ba750.
5732.679692000:42003940: hasRcvInBuffer on nsd 0x6c0e40: pszRcvBuf (nil), lenRcvBuf 0
5732.679710000:42003940: hasRcvInBuffer on nsd 0x6bd3e0: pszRcvBuf 0x6c2070, lenRcvBuf -1
5732.679727000:42003940: hasRcvInBuffer on nsd 0x6c73b0: pszRcvBuf 0x6cbdd0, lenRcvBuf -1
5732.679744000:42003940: hasRcvInBuffer on nsd 0x6821a0: pszRcvBuf 0x6d5ec0, lenRcvBuf 70
5732.679761000:42003940: hasRcvInBuffer on nsd 0x6c5fa0: pszRcvBuf 0x6dfcb0, lenRcvBuf -1
5732.679778000:42003940: hasRcvInBuffer on nsd 0x6e94b0: pszRcvBuf 0x6eb180, lenRcvBuf -1
5732.679795000:42003940: hasRcvInBuffer on nsd 0x6ef770: pszRcvBuf 0x6f7c70, lenRcvBuf -1
5732.679812000:42003940: hasRcvInBuffer on nsd 0x6c0e40: pszRcvBuf (nil), lenRcvBuf 0
5732.679840000:42003940: New connect on NSD 0x6ba750.
5732.679869000:42003940: hasRcvInBuffer on nsd 0x6c0e40: pszRcvBuf (nil), lenRcvBuf 0
5732.679886000:42003940: hasRcvInBuffer on nsd 0x6bd3e0: pszRcvBuf 0x6c2070, lenRcvBuf -1
5732.679903000:42003940: hasRcvInBuffer on nsd 0x6c73b0: pszRcvBuf 0x6cbdd0, lenRcvBuf -1
5732.679920000:42003940: hasRcvInBuffer on nsd 0x6821a0: pszRcvBuf 0x6d5ec0, lenRcvBuf 70
5732.679937000:42003940: hasRcvInBuffer on nsd 0x6c5fa0: pszRcvBuf 0x6dfcb0, lenRcvBuf -1
5732.679954000:42003940: hasRcvInBuffer on nsd 0x6e94b0: pszRcvBuf 0x6eb180, lenRcvBuf -1
5732.679971000:42003940: hasRcvInBuffer on nsd 0x6ef770: pszRcvBuf 0x6f7c70, lenRcvBuf -1
5732.679988000:42003940: hasRcvInBuffer on nsd 0x6c0e40: pszRcvBuf (nil), lenRcvBuf 0
5732.680005000:42003940: New connect on NSD 0x6ba750.
5732.680032000:42003940: hasRcvInBuffer on nsd 0x6c0e40: pszRcvBuf (nil), lenRcvBuf 0
5732.680050000:42003940: hasRcvInBuffer on nsd 0x6bd3e0: pszRcvBuf 0x6c2070, lenRcvBuf -1
5732.680067000:42003940: hasRcvInBuffer on nsd 0x6c73b0: pszRcvBuf 0x6cbdd0, lenRcvBuf -1
5732.680084000:42003940: hasRcvInBuffer on nsd 0x6821a0: pszRcvBuf 0x6d5ec0, lenRcvBuf 70
5732.680101000:42003940: hasRcvInBuffer on nsd 0x6c5fa0: pszRcvBuf 0x6dfcb0, lenRcvBuf -1
5732.680118000:42003940: hasRcvInBuffer on nsd 0x6e94b0: pszRcvBuf 0x6eb180, lenRcvBuf -1
5732.680135000:42003940: hasRcvInBuffer on nsd 0x6ef770: pszRcvBuf 0x6f7c70, lenRcvBuf -1
5732.680152000:42003940: hasRcvInBuffer on nsd 0x6c0e40: pszRcvBuf (nil), lenRcvBuf 0
5732.680169000:42003940: New connect on NSD 0x6ba750.
5732.680196000:42003940: hasRcvInBuffer on nsd 0x6c0e40: pszRcvBuf (nil), lenRcvBuf 0
5732.680214000:42003940: hasRcvInBuffer on nsd 0x6bd3e0: pszRcvBuf 0x6c2070, lenRcvBuf -1
5732.680231000:42003940: hasRcvInBuffer on nsd 0x6c73b0: pszRcvBuf 0x6cbdd0, lenRcvBuf -1
5732.680248000:42003940: hasRcvInBuffer on nsd 0x6821a0: pszRcvBuf 0x6d5ec0, lenRcvBuf 70
5732.680265000:42003940: hasRcvInBuffer on nsd 0x6c5fa0: pszRcvBuf 0x6dfcb0, lenRcvBuf -1
5732.680282000:42003940: hasRcvInBuffer on nsd 0x6e94b0: pszRcvBuf 0x6eb180, lenRcvBuf -1
5732.680299000:42003940: hasRcvInBuffer on nsd 0x6ef770: pszRcvBuf 0x6f7c70, lenRcvBuf -1
5732.680316000:42003940: hasRcvInBuffer on nsd 0x6c0e40: pszRcvBuf (nil), lenRcvBuf 0
5732.680344000:42003940: New connect on NSD 0x6ba750.
mstanisl
New
 
Posts: 1
Joined: Mon May 24, 2010 5:57 pm

Re: Rsyslog 4.4.2 TCP Hangup??

Postby dustorobusto » Wed Jun 09, 2010 6:55 am

Not that I know of. I now restart the rsyslog daemon every 1 (or 2, I can't remember) hours with a cron script. In that effort, it only looses upto 59 minutes worth of logs. It never does, in fact, it seems to be fairly stable, with the hourly restart, and must not be getting into buffer trouble very often. This is a weak resolution and I do wish someone had a more solid solution.
Are you using the same versions of rsyslog for client and server? I personally feel that may be the problem. Perhaps a completely native 5.2, or higher, environment would work. I haven't had time to reconfigure all of my clients to do this yet.
dustorobusto
Avarage
 
Posts: 11
Joined: Sun Mar 07, 2010 11:50 pm

Re: Rsyslog 4.4.2 TCP Hangup??

Postby dustorobusto » Thu Jun 17, 2010 3:01 am

I want to stress that this is happening with all versions of rsyslog that I have been trying when encryption with GNUTLS is enabled.
dustorobusto
Avarage
 
Posts: 11
Joined: Sun Mar 07, 2010 11:50 pm

Google Ads


Next

Return to General

Who is online

Users browsing this forum: No registered users and 1 guest

cron