Yate Community Forum

Yate server => Yate bugs => Topic started by: feredi on May 20, 2015, 03:44:31 AM

Title: How to find out which child is unresponsive?
Post by: feredi on May 20, 2015, 03:44:31 AM
I get Supervisor: killing unresponsive child 13463 in yate's log and then suddenly yate is restarted afterwards.
How can I find out which component is causing this bug? No further information is included in Yate's log. A partial log of when the error occurred is found below:

Note: Debug level is already set to maximum value of 10

Code: [Select]
.
.
.
20150520053739.989086 <ss7snm:INFO> RST (label=4-25-5:1-56-7:0): Traffic test-prohibited to dest=1-57-1 [0x9a28880]
ivr1: Got 0 in state pin
20150520053740.067325 <wave:ALL> WaveSource::WaveSource("-",0xb4181ce0) [0xb41908b0]
20150520053740.067529 >>> DataTranslator::detachChain(0xb41701c8,0xb46ae7c0)
20150520053740.067574 <<< DataTranslator::detachChain
20150520053740.067598 >>> DataTranslator::detachChain(0xb41701c8,0xb41998d8)
20150520053740.067624   >>> DataTranslator::detachChain(0xb41701c8,0xb417a900)
20150520053740.067648     >>> DataTranslator::detachChain(0xb41701c8,0xb41539e8)
20150520053740.067671     <<< DataTranslator::detachChain
20150520053740.067706   <<< DataTranslator::detachChain
20150520053740.067734 <<< DataTranslator::detachChain
20150520053740.068008 <ALL> Created DataTranslator 0xb41539e8 for 'slin' -> 'alaw' by factory 0x620a94 (len=1)
20150520053740.068056 <ALL> DataTranslator::attachChain [0xb41908b0] 'slin' -> [0xb46ae7c0] 'alaw' succeeded
20150520053740.068088 <ALL> Created DataTranslator 0xb416e5e0 for 'slin' -> '2*slin' by factory 0x620ae0 (len=1)
20150520053740.068123 <ALL> DataTranslator::attachChain [0xb41908b0] 'slin' -> [0xb41998d8] '2*slin' succeeded
20150520053740.068193 <wave:ALL> WaveSource::~WaveSource() [0xb41701c8] total=20160 stamp=20000
20150520053740.068221 <wave:INFO> WaveSource rate=2040 b/s
ivr1: Got 8 in state pin
ivr1: NULL
ivr1: Engine worked
ivr1: User validated
ivr1::SetState('sig/15998', currencyPlay')
Supervisor: killing unresponsive child 13463
ivr1: Found table operation 'play'
Yate (2518) is starting Wed May 20 10:07:41 2015
20150520053742.144443 <ALL> Plugin::Plugin("openssl",true) [0x3337a0]
Loaded module OpenSSL - based on OpenSSL 1.0.1e-fips 11 Feb 2013
20150520053742.218544 <ALL> Plugin::Plugin("wave",false) [0x377740]
Loaded module WaveFile
.
.
.

Any help is highly appreciated
Title: Re: How to find out which child is unresponsive?
Post by: Monica Tepelus on May 21, 2015, 07:09:43 AM
Hi,

Usually you have more clues in the log. Please upload a bigger log and specify how many external scripts you are running and of what type. Problems usually indicate a bug in the external script.
Title: Re: How to find out which child is unresponsive?
Post by: feredi on May 21, 2015, 08:41:33 AM
Hi Monica,

Thanks for your reply.

A more complete log is included below. Some unfamiliar logs you see are those added to source code by me and I forgot to remove them later ;-) those like (Connecting peersssssssssssss or Here is ToneDetectHandler coming in action  :D). If you need more log just let me know and I'll attach a more complete log file.
I only have a php script running which is acting as an IVR. It's written based on ivr-sample.php available on internet. (https://github.com/shimaore/yate/blob/master/share/scripts/ivrsample.php). Of course I have made a few changes on it to customize it for my needs. So you think this php script is causing the problem? Do you have any idea how can I find out which piece of its code is doing something wrong? As you can see its debugging is turned on. The last thing this php script had done before the crash occurred was ivr1::SetState('sig/15998', currencyPlay') which is simply assigning currencyPlay to a global variable and the next thing done after an unresponsive child being detected by Yate was ivr1: Found table operation 'play' which is when a file is going to be played to caller.

Code: [Select]
ivr1: Got 5 in state pin
20150520053735.845277 <link4/Q931:ALL> Call(0,1036) direction=incoming TEI=0 [0x9a46290]
20150520053735.848725 <link4/Q931:ALL> Call(0,1036). State 'Null' --> 'CallPresent' [0x9a46290]
20150520053735.849069 <link4/B:ALL> ZapCircuit(19). IOCTL(SetLinear) failed on channel 112 (param=0). 22: Invalid argument [0x9a37d58]
20150520053735.849132 <link4/B:NOTE> ZapCircuit(19). IOCTL(SetToneDetect) failed on channel 112 (param=3). 38: Function not implemented [0x9a37d58]
20150520053735.849506 <sig/16010:CALL> Incoming call from=6893413514 to=684340 trunk=link4 sigcall=0x9a46290 [0xb46c8900]
20150520053735.858808 <INFO> Could not classify call from '6893413514', wasted 95 usec
20150520053735.859084 <cdrbuild:INFO> Got message 'call.route' for untracked id 'sig/16010'
20150520053735.859467 <INFO> Routing call to '684340' in context 'default' via 'dumb/' in 201 usec
ivr1: Got 5 in state pin
ivr1: Got 9 in state validuser
ivr1: array shifted arg: wave/play/ dumbid=dumb/10613 callid=sig/16001
ivr1::OnEOF('sig/16001')
ivr1: Got 6 in state pin
20150520053736.406776 <wave:ALL> WaveSource::WaveSource("-",0xb4193500) [0xb41943d0]
20150520053736.407073 >>> DataTranslator::detachChain(0xb3f18510,0xb46b61b8)
20150520053736.407123 <<< DataTranslator::detachChain
20150520053736.407145 >>> DataTranslator::detachChain(0xb3f18510,0xb419a238)
20150520053736.407169   >>> DataTranslator::detachChain(0xb3f18510,0xb3f16300)
20150520053736.407199     >>> DataTranslator::detachChain(0xb3f18510,0xb3f17a50)
20150520053736.407219     <<< DataTranslator::detachChain
20150520053736.407255   <<< DataTranslator::detachChain
20150520053736.407307 <<< DataTranslator::detachChain
20150520053736.407363 <ALL> Created DataTranslator 0xb4194498 for 'slin' -> 'alaw' by factory 0x620a94 (len=1)
20150520053736.407399 <ALL> DataTranslator::attachChain [0xb41943d0] 'slin' -> [0xb46b61b8] 'alaw' succeeded
20150520053736.407429 <ALL> Created DataTranslator 0xb4166e48 for 'slin' -> '2*slin' by factory 0x620ae0 (len=1)
20150520053736.407459 <ALL> DataTranslator::attachChain [0xb41943d0] 'slin' -> [0xb419a238] '2*slin' succeeded
20150520053736.407496 <wave:ALL> WaveSource::~WaveSource() [0xb3f18510] total=20160 stamp=20000
20150520053736.407527 <wave:INFO> WaveSource rate=2401 b/s
ivr1: Got 3 in state pin
ivr1: Got 9 in state pin
20150520053736.763099 <prepaidcard:TEST> Call duration is 303375 micro-seconds cic(941). Price=3166.666667, PinID=103730, CallType=Mobile, Rate=625.000000
ivr1: Got 6 in state pin
ivr1: array shifted arg: wave/play/ dumbid=dumb/10614 callid=sig/16002
ivr1::OnEOF('sig/16002')
ivr1::OnDispatch('chan.attach')
ivr1: Call found!!!!!!
ivr1::SetState('sig/16005', pin')
ivr1: Found table operation 'play'
ivr1: array shifted arg: wave/play//pin.alaw dumbid=dumb/10616 callid=sig/16005
20150520053737.469703 <ToneDetectHandler:MILD> Here is ToneDetectHandler coming in action...
20150520053737.469748 <ToneDetectHandler:ALL> Name: id Value: sig/16005
20150520053737.469781 <ToneDetectHandler:ALL> Name: module Value: sig
20150520053737.469803 <ToneDetectHandler:ALL> Name: status Value: incoming
20150520053737.469822 <ToneDetectHandler:ALL> Name: address Value: link4/12
20150520053737.469841 <ToneDetectHandler:ALL> Name: billid Value: 1431994764-10589
20150520053737.469862 <ToneDetectHandler:ALL> Name: peerid Value: dumb/10616
20150520053737.469883 <ToneDetectHandler:ALL> Name: answered Value: false
20150520053737.469906 <ToneDetectHandler:ALL> Name: direction Value: incoming
20150520053737.469925 <ToneDetectHandler:ALL> Name: handlers Value: ToneDetectHandler:90
20150520053737.470321 <ToneDetectHandler:MILD> Here is ToneDetectHandler coming in action...
20150520053737.470358 <ToneDetectHandler:ALL> Name: id Value: dumb/10616
20150520053737.470380 <ToneDetectHandler:ALL> Name: module Value: dumb
20150520053737.470422 <ToneDetectHandler:ALL> Name: status Value: outgoing
20150520053737.470442 <ToneDetectHandler:ALL> Name: billid Value: 1431994764-10589
20150520053737.470464 <ToneDetectHandler:ALL> Name: peerid Value: sig/16005
20150520053737.470485 <ToneDetectHandler:ALL> Name: answered Value: false
20150520053737.470506 <ToneDetectHandler:ALL> Name: direction Value: outgoing
20150520053737.470526 <ToneDetectHandler:ALL> Name: handlers Value: ToneDetectHandler:90
20150520053737.572047 <WARN> Connecting peersssssssssssss. reason: (null)
20150520053737.572357 <tonedetect:ALL> ToneConsumer::ToneConsumer(dumb/10621,'tone/mixed/dtmf') [0xb419b678]
20150520053737.572545 <link4/Q931:ALL> Call(0,1036). State 'CallPresent' --> 'IncomingProceeding' [0x9a46290]
20150520053737.572841 <tonedetect:ALL> ToneConsumer::ToneConsumer(sig/16010,'tone/mixed/dtmf') [0xb419bc20]
20150520053737.572953 <sig/16010:CALL> Call ringing [0xb46c8900]
20150520053737.573021 <link4/B:NOTE> ZapCircuit(19). Unable to send unknown event 2 [0x9a3cdb8]
20150520053737.573079 <link4/Q931:ALL> Call(0,1036). State 'IncomingProceeding' --> 'CallReceived' [0x9a46290]
20150520053737.573145 <link4/Q931:TEST> sendEvent::sendAlerting
ivr1: Got 2 in state pin
ivr1: Got 9 in state pin
20150520053737.810754 <link4/Q931:ALL> Call(0,1021). State 'CallReceived' --> 'DisconnectIndication' [0x9a5bc68]
20150520053737.810928 <sig/16005:CALL> Call hangup. Reason: 'normal' [0xb46c4560]
20150520053737.811027 <link4/Q931:ALL> Call(0,1021). State 'DisconnectIndication' --> 'ReleaseReq' [0x9a5bc68]
20150520053737.811214 <ALL> DumbChannel::disconnected() 'normal'
20150520053737.811335 <sig/16005:CALL> Call destroyed. Reason: 'normal'. No signalling call  [0xb46c4560]
20150520053737.811376 <tonedetect:ALL> ToneConsumer::~ToneConsumer [0xb419a720]
20150520053737.832106 <link4/Q931:ALL> Call(0,1021). State 'ReleaseReq' --> 'Null' [0x9a5bc68]
20150520053737.833822 <link4/Q931:ALL> Call(0,1021) destroyed with reason '(null)' [0x9a5bc68]
ivr1: Got 5 in state pin
ivr1::OnDispatch('chan.attach')
ivr1: Got 1 in state validuser
ivr1: Got 0 in state pin
ivr1: Call found!!!!!!
ivr1::SetState('sig/16006', pin')
ivr1: Found table operation 'play'
ivr1: array shifted arg: wave/play//pin.alaw dumbid=dumb/10617 callid=sig/16006
20150520053738.630568 <ToneDetectHandler:MILD> Here is ToneDetectHandler coming in action...
20150520053738.630612 <ToneDetectHandler:ALL> Name: id Value: dumb/10617
20150520053738.630645 <ToneDetectHandler:ALL> Name: module Value: dumb
20150520053738.630666 <ToneDetectHandler:ALL> Name: status Value: outgoing
20150520053738.630686 <ToneDetectHandler:ALL> Name: billid Value: 1431994764-10590
20150520053738.630705 <ToneDetectHandler:ALL> Name: peerid Value: sig/16006
20150520053738.630719 <ToneDetectHandler:ALL> Name: answered Value: false
20150520053738.630732 <ToneDetectHandler:ALL> Name: direction Value: outgoing
20150520053738.630752 <ToneDetectHandler:ALL> Name: handlers Value: ToneDetectHandler:90
20150520053738.636591 <ToneDetectHandler:MILD> Here is ToneDetectHandler coming in action...
20150520053738.636646 <ToneDetectHandler:ALL> Name: id Value: sig/16006
20150520053738.636668 <ToneDetectHandler:ALL> Name: module Value: sig
20150520053738.636690 <ToneDetectHandler:ALL> Name: status Value: incoming
20150520053738.636710 <ToneDetectHandler:ALL> Name: address Value: link4/14
20150520053738.636731 <ToneDetectHandler:ALL> Name: billid Value: 1431994764-10590
20150520053738.636752 <ToneDetectHandler:ALL> Name: peerid Value: dumb/10617
20150520053738.636772 <ToneDetectHandler:ALL> Name: answered Value: false
20150520053738.636795 <ToneDetectHandler:ALL> Name: direction Value: incoming
20150520053738.636815 <ToneDetectHandler:ALL> Name: handlers Value: ToneDetectHandler:90
ivr1: Call found!!!!!!
ivr1::SetState('sig/16007', pin')
ivr1: Found table operation 'play'
ivr1: array shifted arg: wave/play//pin.alaw dumbid=dumb/10618 callid=sig/16007
20150520053739.054177 <ToneDetectHandler:MILD> Here is ToneDetectHandler coming in action...
20150520053739.054263 <ToneDetectHandler:ALL> Name: id Value: sig/16007
20150520053739.054289 <ToneDetectHandler:ALL> Name: module Value: sig
20150520053739.054312 <ToneDetectHandler:ALL> Name: status Value: incoming
20150520053739.054333 <ToneDetectHandler:ALL> Name: address Value: link4/15
20150520053739.054354 <ToneDetectHandler:ALL> Name: billid Value: 1431994764-10591
20150520053739.054367 <ToneDetectHandler:ALL> Name: peerid Value: dumb/10618
20150520053739.054410 <ToneDetectHandler:ALL> Name: answered Value: false
20150520053739.054431 <ToneDetectHandler:ALL> Name: direction Value: incoming
20150520053739.054452 <ToneDetectHandler:ALL> Name: handlers Value: ToneDetectHandler:90
20150520053739.054625 <sig/16007:CALL> Call destroyed. Reason: 'normal'. No signalling call  [0xb46c7f08]
20150520053739.054694 <tonedetect:ALL> ToneConsumer::~ToneConsumer [0xb4198e78]
20150520053739.055072 <wave:ALL> WaveSource::WaveSource("/pin.alaw",0xb4179da0) [0xb4198f90]
20150520053739.055325 <ALL> DataTranslator::attachChain [0xb4198f90] 'alaw' -> [0xb46c0fc8] 'alaw' succeeded
20150520053739.055426 <ALL> Created DataTranslator 0xb4199170 for 'alaw' -> '2*slin' by factory 0x98de128 (len=2)
20150520053739.055465 <ALL> DataTranslator::attachChain [0xb4198f90] 'alaw' -> [0xb4185658] '2*slin' succeeded
20150520053739.056338 <ToneDetectHandler:MILD> Here is ToneDetectHandler coming in action...
20150520053739.056416 <ToneDetectHandler:ALL> Name: id Value: dumb/10618
20150520053739.056443 <ToneDetectHandler:ALL> Name: module Value: dumb
20150520053739.056464 <ToneDetectHandler:ALL> Name: status Value: outgoing
20150520053739.056485 <ToneDetectHandler:ALL> Name: billid Value: 1431994764-10591
20150520053739.056507 <ToneDetectHandler:ALL> Name: peerid Value: sig/16007
20150520053739.056528 <ToneDetectHandler:ALL> Name: answered Value: false
20150520053739.056548 <ToneDetectHandler:ALL> Name: direction Value: outgoing
20150520053739.056570 <ToneDetectHandler:ALL> Name: handlers Value: ToneDetectHandler:90
ivr1: Got 2 in state pin
ivr1: Got 0 in state pin
20150520053739.263983 <wave:ALL> WaveSource::WaveSource("/sounds/Numbering/7.alaw",0xb4180cd0) [0xb419c558]
20150520053739.264282 >>> DataTranslator::detachChain(0xb4193040,0xb46c6b08)
20150520053739.264342 <<< DataTranslator::detachChain
20150520053739.264365 >>> DataTranslator::detachChain(0xb4193040,0xb4165f68)
20150520053739.264388   >>> DataTranslator::detachChain(0xb4193040,0xb418bab0)
20150520053739.264412     >>> DataTranslator::detachChain(0xb4193040,0xb416e3d8)
20150520053739.264434     <<< DataTranslator::detachChain
20150520053739.264467   <<< DataTranslator::detachChain
20150520053739.264494 <<< DataTranslator::detachChain
20150520053739.264522 <ALL> DataTranslator::attachChain [0xb419c558] 'alaw' -> [0xb46c6b08] 'alaw' succeeded
20150520053739.264581 <ALL> Created DataTranslator 0xb418bab0 for 'alaw' -> '2*slin' by factory 0x98de128 (len=2)
20150520053739.264619 <ALL> DataTranslator::attachChain [0xb419c558] 'alaw' -> [0xb4165f68] '2*slin' succeeded
20150520053739.264644 <wave:ALL> WaveSource::~WaveSource() [0xb4193040] total=6400 stamp=6240
20150520053739.264670 <wave:INFO> WaveSource rate=748 b/s
ivr1: Got 0 in state pin
20150520053739.366509 <wave:ALL> WaveSource::WaveSource("-",0xb41768c0) [0xb419c620]
20150520053739.366749 >>> DataTranslator::detachChain(0xb417ec20,0xb46abf00)
20150520053739.367013 <<< DataTranslator::detachChain
20150520053739.367039 >>> DataTranslator::detachChain(0xb417ec20,0xb416bf88)
20150520053739.367065   >>> DataTranslator::detachChain(0xb417ec20,0xb4174400)
20150520053739.367089     >>> DataTranslator::detachChain(0xb417ec20,0xb418a6d8)
20150520053739.367110     <<< DataTranslator::detachChain
20150520053739.367164   <<< DataTranslator::detachChain
20150520053739.367197 <<< DataTranslator::detachChain
20150520053739.367252 <ALL> Created DataTranslator 0xb418a6d8 for 'slin' -> 'alaw' by factory 0x620a94 (len=1)
20150520053739.367292 <ALL> DataTranslator::attachChain [0xb419c620] 'slin' -> [0xb46abf00] 'alaw' succeeded
20150520053739.367326 <ALL> Created DataTranslator 0xb4174400 for 'slin' -> '2*slin' by factory 0x620ae0 (len=1)
20150520053739.367360 <ALL> DataTranslator::attachChain [0xb419c620] 'slin' -> [0xb416bf88] '2*slin' succeeded
20150520053739.367386 <wave:ALL> WaveSource::~WaveSource() [0xb417ec20] total=20160 stamp=20000
20150520053739.367412 <wave:INFO> WaveSource rate=1746 b/s
ivr1: Got 0 in state pin
20150520053739.554476 <sig/16003:CALL> Call answered [0xb46c4368]
20150520053739.554630 <ALL> Created DataTranslator 0xb4199ea0 for 'alaw' -> '2*slin' by factory 0x98de128 (len=2)
20150520053739.554674 <ALL> DataTranslator::attachChain [0xb46c0dc0] 'alaw' -> [0xb4191dc8] '2*slin' succeeded
20150520053739.554708 <link4/B:NOTE> ZapCircuit(10). Unable to send unknown event 23 [0x9a3ace8]
20150520053739.554886 <link4/Q931:ALL> Call(0,1018). State 'CallReceived' --> 'CallPresent' [0x9a5d960]
20150520053739.554933 <link4/Q931:ALL> Call(0,1018). State 'CallPresent' --> 'ConnectReq' [0x9a5d960]
20150520053739.613288 <link4/Q931:ALL> Call(0,1018). State 'ConnectReq' --> 'Active' [0x9a5d960]
ivr1: Got 0 in state pin
20150520053739.678138 <link4/Q931:ALL> Call(0,1045) direction=incoming TEI=0 [0x9a5bc68]
20150520053739.680716 <link4/Q931:ALL> Call(0,1045). State 'Null' --> 'CallPresent' [0x9a5bc68]
20150520053739.681204 <link4/B:ALL> ZapCircuit(21). IOCTL(SetLinear) failed on channel 114 (param=0). 22: Invalid argument [0x9a37d58]
20150520053739.681260 <link4/B:NOTE> ZapCircuit(21). IOCTL(SetToneDetect) failed on channel 114 (param=3). 38: Function not implemented [0x9a37d58]
20150520053739.681593 <sig/16011:CALL> Incoming call from=6893413550 to=684340 trunk=link4 sigcall=0x9a5bc68 [0xb46c4560]
20150520053739.687852 <INFO> Could not classify call from '6893413550', wasted 87 usec
20150520053739.688086 <cdrbuild:INFO> Got message 'call.route' for untracked id 'sig/16011'
20150520053739.688484 <INFO> Routing call to '684340' in context 'default' via 'dumb/' in 236 usec
20150520053739.772978 <wave:ALL> WaveSource 'sig/15979' end of data (4160 played) chan=0xb4180cd0 [0xb419c558]
20150520053739.773221 <wave:ALL> WaveSource cleanup, total=4160, chan=(nil) [0xb419c558]
ivr1: Got 6 in state validuser
ivr1: Got 5 in state pin
ivr1::OnDispatch('chan.attach')
20150520053739.938773 <wave:ALL> WaveSource::WaveSource("/dialtone.alaw",0xb4184b68) [0xb419cc20]
20150520053739.939073 >>> DataTranslator::detachChain(0xb41908b0,0xb46c2270)
20150520053739.939121   >>> DataTranslator::detachChain(0xb41908b0,0xb4172868)
20150520053739.939146   <<< DataTranslator::detachChain
20150520053739.939180 <<< DataTranslator::detachChain
20150520053739.939203 >>> DataTranslator::detachChain(0xb41908b0,0xb4173060)
20150520053739.939228   >>> DataTranslator::detachChain(0xb41908b0,0xb417d950)
20150520053739.939250   <<< DataTranslator::detachChain
20150520053739.939272 <<< DataTranslator::detachChain
20150520053739.939298 <ALL> DataTranslator::attachChain [0xb419cc20] 'alaw' -> [0xb46c2270] 'alaw' succeeded
20150520053739.939358 <ALL> Created DataTranslator 0xb417d950 for 'alaw' -> '2*slin' by factory 0x98de128 (len=2)
20150520053739.939417 <ALL> DataTranslator::attachChain [0xb419cc20] 'alaw' -> [0xb4173060] '2*slin' succeeded
20150520053739.953888 <wave:ALL> WaveSource cleanup, total=34080, chan=(nil) [0xb41908b0]
20150520053739.953977 <wave:ALL> WaveSource::~WaveSource() [0xb41908b0] total=34080 stamp=33920
20150520053739.954009 <wave:INFO> WaveSource rate=7999 b/s
20150520053739.988953 <ss7snm:INFO> Received 3 bytes message (0xb4694fc8) on linkset1:0
-----
RST [label=4-25-5:1-56-7:0]
  pointcodetype='ITU'
  destination='1-57-1'
-----
20150520053739.989086 <ss7snm:INFO> RST (label=4-25-5:1-56-7:0): Traffic test-prohibited to dest=1-57-1 [0x9a28880]
ivr1: Got 0 in state pin
20150520053740.067325 <wave:ALL> WaveSource::WaveSource("-",0xb4181ce0) [0xb41908b0]
20150520053740.067529 >>> DataTranslator::detachChain(0xb41701c8,0xb46ae7c0)
20150520053740.067574 <<< DataTranslator::detachChain
20150520053740.067598 >>> DataTranslator::detachChain(0xb41701c8,0xb41998d8)
20150520053740.067624   >>> DataTranslator::detachChain(0xb41701c8,0xb417a900)
20150520053740.067648     >>> DataTranslator::detachChain(0xb41701c8,0xb41539e8)
20150520053740.067671     <<< DataTranslator::detachChain
20150520053740.067706   <<< DataTranslator::detachChain
20150520053740.067734 <<< DataTranslator::detachChain
20150520053740.068008 <ALL> Created DataTranslator 0xb41539e8 for 'slin' -> 'alaw' by factory 0x620a94 (len=1)
20150520053740.068056 <ALL> DataTranslator::attachChain [0xb41908b0] 'slin' -> [0xb46ae7c0] 'alaw' succeeded
20150520053740.068088 <ALL> Created DataTranslator 0xb416e5e0 for 'slin' -> '2*slin' by factory 0x620ae0 (len=1)
20150520053740.068123 <ALL> DataTranslator::attachChain [0xb41908b0] 'slin' -> [0xb41998d8] '2*slin' succeeded
20150520053740.068193 <wave:ALL> WaveSource::~WaveSource() [0xb41701c8] total=20160 stamp=20000
20150520053740.068221 <wave:INFO> WaveSource rate=2040 b/s
ivr1: Got 8 in state pin
ivr1: NULL
ivr1: Engine worked
ivr1: User validated
ivr1::SetState('sig/15998', currencyPlay')
Supervisor: killing unresponsive child 13463
ivr1: Found table operation 'play'
Yate (2518) is starting Wed May 20 10:07:41 2015
20150520053742.144443 <ALL> Plugin::Plugin("openssl",true) [0x3337a0]
Loaded module OpenSSL - based on OpenSSL 1.0.1e-fips 11 Feb 2013
20150520053742.218544 <ALL> Plugin::Plugin("wave",false) [0x377740]
Loaded module WaveFile
20150520053742.265070 <ALL> Plugin::Plugin("cdrfile",true) [0x92f3a0]
Loaded module CdrFile
20150520053742.326627 <ALL> Plugin::Plugin("zlibcompress",true) [0xfc7a20]
Loaded module ZLib - using zlib library version 1.2.3
20150520053742.624306 <ALL> Plugin::Plugin("javascript",true) [0x3cf320]
Loaded module Javascript
20150520053742.685439 <ALL> Plugin::Plugin("fileinfo",false) [0xcd2620]
Loaded module FileInfo
Title: Re: How to find out which child is unresponsive?
Post by: feredi on May 21, 2015, 09:06:43 AM
And it happened again! Log file is attached.
Title: Re: How to find out which child is unresponsive?
Post by: feredi on June 02, 2015, 02:31:53 PM
I had a global array in my PHP code. I changed it to be a class member and solved a few memory leaks in my code and the problem never occurred again so far. Thank you Monica for directing me to the right direction and pointing out the possibility of having a bug in external script.
Title: Re: How to find out which child is unresponsive?
Post by: feredi on August 09, 2015, 07:37:47 AM
Sorry for opening this thread again.

The same script which is now working on my server is showing same symptoms as indicated in above logs on different server. Any idea what could be wrong here?
UPDATE:
Supervisor: killing unresponsive child 29157 is showing up in logs and child 29157 is PID of yate process itself. I used top to get pid. my global script can also be found in top output but it has a different pid. That's why I guess the problem isn't related to external script.

Thanks
Title: Re: How to find out which child is unresponsive?
Post by: Ioana Stanciu on August 10, 2015, 01:18:52 AM
If Yate is waiting for a message to be handled by your script and the message is not handled in reasonable time (10 seconds, as fas as i rememenber), Yate will be restarted by the supervisor. So, although it may see that Yate is unresponsive, the cause could be the script.

Please provide a log and if you started yate with the -C option, look at the core left by the restart and please paste it also.