Mailing List Archive: RSyslog: users

v5-stable (5.8.13) segfault

Index | Next | Previous | View Threaded

bodik at civ

Jun 21, 2012, 2:27 AM

Post #1 of 5 (259 views)
Permalink

v5-stable (5.8.13) segfault

hi,

while current v5-stable (should be 5.8.13) works fine on "client" side, on the
central "server" side it segfaults after few minutes of run with

I'm switching back to 5.8.10 and will try to provide more information asap

-------------
#0 0x00007f2579c7e165 in raise (sig=<value optimized out>) at
../nptl/sysdeps/unix/sysv/linux/raise.c:64
64 ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory.
in ../nptl/sysdeps/unix/sysv/linux/raise.c
(gdb) back
#0 0x00007f2579c7e165 in raise (sig=<value optimized out>) at
../nptl/sysdeps/unix/sysv/linux/raise.c:64
#1 0x00007f2579c80f70 in abort () at abort.c:92
#2 0x0000000000422ca7 in sigsegvHdlr ()
#3 <signal handler called>
#4 0x00007f2579c7e165 in raise (sig=<value optimized out>) at
../nptl/sysdeps/unix/sysv/linux/raise.c:64
#5 0x00007f2579c80f70 in abort () at abort.c:92
#6 0x00007f2579c772b1 in __assert_fail (assertion=0x7f257a3c9fdf
"mutex->__data.__owner == 0", file=<value optimized out>, line=62,
function=0x7f257a3ca0b0 "__pthread_mutex_lock") at assert.c:81
#7 0x00007f257a3c1f4b in __pthread_mutex_lock (mutex=0x7f256f69a700) at
pthread_mutex_lock.c:62
#8 0x000000000042d103 in wtiWorker ()
#9 0x000000000042cc8d in ?? ()
#10 0x00007f257a3bf8ba in start_thread (arg=<value optimized out>) at
pthread_create.c:300
#11 0x00007f2579d1b02d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#12 0x0000000000000000 in ?? ()

bodik
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards

bodik at civ

Jul 11, 2012, 7:24 AM

Post #2 of 5 (220 views)
Permalink

Re: v5-stable (5.8.13) segfault [In reply to]

On 06/21/12 11:27, bodik wrote:
> hi,
>
> while current v5-stable works fine on "client" side, on the
> central "server" side it segfaults after few minutes of run with

hi,

a digged a little deep into it and i think i found a cause. I think that using
plugin pOnSessAccept callback to establish session inside tcp channel can lead
to null pointer dereference at tcpsrv.c:699

this happens only using imgssapi on the server side in v5-stable, imho it is the
only module using pOnSessAccept

Run > SessAccept > imgssapi::pOnSessAccept > OnSessAcceptGSS fails

when session creation fails. (eg ntp timeskew using KDC, network disruptions,
using tcpkill...) tcpsrv.c:SessAccept jums to finalizer, does not add a session
into live sessions (which is fine) and session is destructed (which is maybe
also fine) but after return from Run.SessAccept, is pNewSess directly
dereferenced with

699 CHKiRet(nspoll.Ctl(pPoll, pNewSess->pStrm,

This in not reproducible by any other plugin since imgssapi is the only using
it. but I believe that that can be emulated by custom test plugin within plugin
API testcase ...

Could attached patch solve the issue ? (at least it works fine for me ;)

Thank you
bodik

-----------

tcpsrv.c:SessAccept

440 /* check if we need to call our callback */
441 if(pThis->pOnSessAccept != NULL) {
442 CHKiRet(pThis->pOnSessAccept(pThis, pSess));
443 }
444
445 *ppSess = pSess;
446 if(!pThis->bUsingEPoll)
447 pThis->pSessions[iSess] = pSess;
448 pSess = NULL; /* this is now also handed over */
449
450 finalize_it:
451 if(iRet != RS_RET_OK) {
452 if(pSess != NULL)
453 tcps_sess.Destruct(&pSess);
454 if(pNewStrm != NULL)
455 netstrm.Destruct(&pNewStrm);
456 free(fromHostFQDN);
457 free(fromHostIP);
458 }
459
460 RETiRet;

tcpsrv.c:Run

682 while(1) {
683 localRet = nspoll.Wait(pPoll, -1, &i, &pUsr);
...
696 if(pUsr == pThis->ppLstn) {
697 DBGPRINTF("New connect on NSD %p.\n",
698 SessAccept(pThis, pThis->ppLstnPort[i], &pNewSess,
699 CHKiRet(nspoll.Ctl(pPoll, pNewSess->pStrm,
700 DBGPRINTF("Failed to esablish a new
701 } else {
702 pNewSess = (tcps_sess_t*) pUsr;
703 doReceive(pThis, &pNewSess, pPoll);
704 }
705 }

Attachments:

tcpsrv_onsessaccept.patch (0.82 KB)

rgerhards at hq

Jul 11, 2012, 10:03 AM

Post #3 of 5 (220 views)
Permalink

Re: v5-stable (5.8.13) segfault [In reply to]

Thx, sounds very reasonable, hope to be able to look at it in depth and merge tomorrow. If it's not merged by Monday, please ping me.

Rainer

> -----Original Message-----
> From: rsyslog-bounces [at] lists [mailto:rsyslog-
> bounces [at] lists] On Behalf Of bodik
> Sent: Wednesday, July 11, 2012 4:25 PM
> To: rsyslog-users
> Cc: Daniel Kouril
> Subject: Re: [rsyslog] v5-stable (5.8.13) segfault
>
> On 06/21/12 11:27, bodik wrote:
> > hi,
> >
> > while current v5-stable works fine on "client" side, on the
> > central "server" side it segfaults after few minutes of run with
>
> hi,
>
> a digged a little deep into it and i think i found a cause. I think
> that using
> plugin pOnSessAccept callback to establish session inside tcp channel
> can lead
> to null pointer dereference at tcpsrv.c:699
>
> this happens only using imgssapi on the server side in v5-stable, imho
> it is the
> only module using pOnSessAccept
>
> Run > SessAccept > imgssapi::pOnSessAccept > OnSessAcceptGSS fails
>
> when session creation fails. (eg ntp timeskew using KDC, network
> disruptions,
> using tcpkill...) tcpsrv.c:SessAccept jums to finalizer, does not add a
> session
> into live sessions (which is fine) and session is destructed (which is
> maybe
> also fine) but after return from Run.SessAccept, is pNewSess directly
> dereferenced with
>
> 699 CHKiRet(nspoll.Ctl(pPoll, pNewSess->pStrm,
>
> This in not reproducible by any other plugin since imgssapi is the only
> using
> it. but I believe that that can be emulated by custom test plugin
> within plugin
> API testcase ...
>
> Could attached patch solve the issue ? (at least it works fine for me
> ;)
>
> Thank you
> bodik
>
>
> -----------
>
> tcpsrv.c:SessAccept
>
> 440 /* check if we need to call our callback */
> 441 if(pThis->pOnSessAccept != NULL) {
> 442 CHKiRet(pThis->pOnSessAccept(pThis, pSess));
> 443 }
> 444
> 445 *ppSess = pSess;
> 446 if(!pThis->bUsingEPoll)
> 447 pThis->pSessions[iSess] = pSess;
> 448 pSess = NULL; /* this is now also handed over */
> 449
> 450 finalize_it:
> 451 if(iRet != RS_RET_OK) {
> 452 if(pSess != NULL)
> 453 tcps_sess.Destruct(&pSess);
> 454 if(pNewStrm != NULL)
> 455 netstrm.Destruct(&pNewStrm);
> 456 free(fromHostFQDN);
> 457 free(fromHostIP);
> 458 }
> 459
> 460 RETiRet;
>
>
> tcpsrv.c:Run
>
> 682 while(1) {
> 683 localRet = nspoll.Wait(pPoll, -1, &i, &pUsr);
> ...
> 696 if(pUsr == pThis->ppLstn) {
> 697 DBGPRINTF("New connect on NSD %p.\n",
> 698 SessAccept(pThis, pThis->ppLstnPort[i],
> &pNewSess,
> 699 CHKiRet(nspoll.Ctl(pPoll, pNewSess->pStrm,
> 700 DBGPRINTF("Failed to esablish a new
> 701 } else {
> 702 pNewSess = (tcps_sess_t*) pUsr;
> 703 doReceive(pThis, &pNewSess, pPoll);
> 704 }
> 705 }
>
>
>
>
>

_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards

bodik at civ

Aug 8, 2012, 7:22 AM

Post #4 of 5 (198 views)
Permalink

Re: v5-stable (5.8.13) segfault [In reply to]

Hi,

I did a more testing on this and also on a Yu's patch from

http://lists.adiscon.net/pipermail/rsyslog/2012-July/015259.html

which seems to be a better solution. Checking only !=NULL does not handle other
races like:

Program terminated with signal 11, Segmentation fault.
#0 0x00007fef178cc898 in Run (pThis=0x158d980) at tcpsrv.c:699
699 CHKiRet(nspoll.Ctl(pPoll, pNewSess->pStrm, 0, pNewSess, NSDPOLL_IN,
NSDPOLL_ADD));
(gdb) back
#0 0x00007fef178cc898 in Run (pThis=0x158d980) at tcpsrv.c:699
#1 0x00007fef18a1a6c1 in runInput (pThrd=0x15cb0f0) at imgssapi.c:647
#2 0x0000000000467369 in thrdStarter (arg=0x15cb0f0) at ../threads.c:190
#3 0x00007fef1a2668ca in start_thread (arg=<value optimized out>) at
pthread_create.c:300
#4 0x00007fef19bc192d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#5 0x0000000000000000 in ?? ()
(gdb) p pNewSess
$1 = (tcps_sess_t *) 0x100431370
(gdb) p *pNewSess
Cannot access memory at address 0x100431370

It would be wonderfull to have +CHKiRet(SessAccept in v5-stable someday ...

bodik

On 07/11/12 19:03, Rainer Gerhards wrote:
> Thx, sounds very reasonable, hope to be able to look at it in depth and merge tomorrow. If it's not merged by Monday, please ping me.
>
> Rainer
>
>> -----Original Message-----
>> From: rsyslog-bounces [at] lists [mailto:rsyslog-
>> bounces [at] lists] On Behalf Of bodik
>> Sent: Wednesday, July 11, 2012 4:25 PM
>> To: rsyslog-users
>> Cc: Daniel Kouril
>> Subject: Re: [rsyslog] v5-stable (5.8.13) segfault
>>
>> On 06/21/12 11:27, bodik wrote:
>>> hi,
>>>
>>> while current v5-stable works fine on "client" side, on the
>>> central "server" side it segfaults after few minutes of run with
>>
>> hi,
>>
>> a digged a little deep into it and i think i found a cause. I think
>> that using
>> plugin pOnSessAccept callback to establish session inside tcp channel
>> can lead
>> to null pointer dereference at tcpsrv.c:699
>>
>> this happens only using imgssapi on the server side in v5-stable, imho
>> it is the
>> only module using pOnSessAccept
>>
>> Run > SessAccept > imgssapi::pOnSessAccept > OnSessAcceptGSS fails
>>
>> when session creation fails. (eg ntp timeskew using KDC, network
>> disruptions,
>> using tcpkill...) tcpsrv.c:SessAccept jums to finalizer, does not add a
>> session
>> into live sessions (which is fine) and session is destructed (which is
>> maybe
>> also fine) but after return from Run.SessAccept, is pNewSess directly
>> dereferenced with
>>
>> 699 CHKiRet(nspoll.Ctl(pPoll, pNewSess->pStrm,
>>
>> This in not reproducible by any other plugin since imgssapi is the only
>> using
>> it. but I believe that that can be emulated by custom test plugin
>> within plugin
>> API testcase ...
>>
>> Could attached patch solve the issue ? (at least it works fine for me
>> ;)
>>
>> Thank you
>> bodik
>>
>>
>> -----------
>>
>> tcpsrv.c:SessAccept
>>
>> 440 /* check if we need to call our callback */
>> 441 if(pThis->pOnSessAccept != NULL) {
>> 442 CHKiRet(pThis->pOnSessAccept(pThis, pSess));
>> 443 }
>> 444
>> 445 *ppSess = pSess;
>> 446 if(!pThis->bUsingEPoll)
>> 447 pThis->pSessions[iSess] = pSess;
>> 448 pSess = NULL; /* this is now also handed over */
>> 449
>> 450 finalize_it:
>> 451 if(iRet != RS_RET_OK) {
>> 452 if(pSess != NULL)
>> 453 tcps_sess.Destruct(&pSess);
>> 454 if(pNewStrm != NULL)
>> 455 netstrm.Destruct(&pNewStrm);
>> 456 free(fromHostFQDN);
>> 457 free(fromHostIP);
>> 458 }
>> 459
>> 460 RETiRet;
>>
>>
>> tcpsrv.c:Run
>>
>> 682 while(1) {
>> 683 localRet = nspoll.Wait(pPoll, -1, &i, &pUsr);
>> ...
>> 696 if(pUsr == pThis->ppLstn) {
>> 697 DBGPRINTF("New connect on NSD %p.\n",
>> 698 SessAccept(pThis, pThis->ppLstnPort[i],
>> &pNewSess,
>> 699 CHKiRet(nspoll.Ctl(pPoll, pNewSess->pStrm,
>> 700 DBGPRINTF("Failed to esablish a new
>> 701 } else {
>> 702 pNewSess = (tcps_sess_t*) pUsr;
>> 703 doReceive(pThis, &pNewSess, pPoll);
>> 704 }
>> 705 }
>>
>>
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards

bodik at civ

Aug 9, 2012, 4:05 AM

Post #5 of 5 (196 views)
Permalink

Re: v5-stable (5.8.13) segfault [In reply to]

> http://lists.adiscon.net/pipermail/rsyslog/2012-July/015259.html
>
> which seems to be a better solution.

but that's terminates tcp server because of goto in chkiret ;(

diff -rua a/tcpsrv.c rsyslog.addiscon/tcpsrv.c
--- a/tcpsrv.c 2012-08-09 11:17:37.000000000 +0200
+++ b/tcpsrv.c 2012-08-09 11:20:29.664620491 +0200
@@ -695,9 +695,12 @@

if(pUsr == pThis->ppLstn) {
DBGPRINTF("New connect on NSD %p.\n", pThis->ppLstn[i]);
- SessAccept(pThis, pThis->ppLstnPort[i], &pNewSess,
pThis->ppLstn[i]);
- CHKiRet(nspoll.Ctl(pPoll, pNewSess->pStrm, 0, pNewSess,
NSDPOLL_IN, NSDPOLL_ADD));
- DBGPRINTF("New session created with NSD %p.\n", pNewSess);
+ if( SessAccept(pThis, pThis->ppLstnPort[i], &pNewSess,
pThis->ppLstn[i]) == RS_RET_OK) {
+ DBGPRINTF("New session created with NSD %p.\n",
pNewSess);
+ CHKiRet(nspoll.Ctl(pPoll, pNewSess->pStrm, 0,
pNewSess, NSDPOLL_IN, NSDPOLL_ADD));
+ } else {
+ DBGPRINTF("Failed to establish a new session with
NSD %p.\n", pNewSess);
+ }
} else {
pNewSess = (tcps_sess_t*) pUsr;
doReceive(pThis, &pNewSess, pPoll);

_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards

Index | Next | Previous | View Threaded

Interested in having your list archived? Contact Gossamer Threads