Mantis Bugtracker

Viewing Issue Simple Details Jump to Notes ] View Advanced ] Issue History ] Print ]
ID Category Severity Reproducibility Date Submitted Last Update
0000394 [Yate - Yet Another Telephony Engine] engine major always 2015-03-31 20:27 2015-04-01 05:52
Reporter farzan View Status public  
Assigned To
Priority normal Resolution open  
Status new   Product Version SVN
Summary 0000394: PRI Incoming call hangs up with "wrong-state-message" after being handled by IVR using libyateivr.php
Description While using extmodule to build an IVR it fails with a wrong-state-message. Note that I'm using DAHDI and link4 in debug trace is a PRI-CPE trunk.
Additional Information
regexroute.conf:
^9999.=external/nodata/ivr.php

ivr.php:
Contents of ivr.php is exactly same as ivrsample.php available online (https://github.com/shimaore/yate/blob/master/share/scripts/ivrsample.php) [^]

Debug info taken from rmanager:
20150331123515.670215 <sig/4:CALL> Incoming call from=88880000 to=99990000 tr
unk=link4 sigcall=0xb750a5d0 [0xb690e218]
20150331123515.676150 <INFO> Could not classify call from '88880000', wasted 7
 usec
20150331123515.676956 <INFO> Routing call to '99990000' in context 'default' vi
a 'external/nodata/ivr.php' in 111 usec
20150331123515.677621 <ALL> ExtModChan::ExtModChan(1) [0xb6910950]
20150331123515.677854 <ALL> ExtModReceiver::ExtModReceiver("ivr.php","(null)")
 [0xb6910a90]
20150331123515.694169 <INFO> Launched External Script '/usr/local/share/yate/scr
ipts/ivr.php' ''
IVR::InitIVR()
ivr1::OnEnter('')
ivr1: Found table operation 'output'
ivr1: Entered 1st IVR
ivr2::OnEnter('')
IVR: Requested unknown IVR 'nosuch'
ivr2::OnEvent(incoming 'call.execute')
ivr2::OnMessage('call.execute')
ivr2::OnExecute()
ivr1::OnUnhandled(incoming 'call.execute')
ivr1::OnMessage('call.execute')
ivr1::OnExecute()
ivr1: Found table operation 'answered'
20150331123516.400997 <ExtModReceiver:ALL> Install 'chan.dtmf', prio 100 filter:
 'targetid'='ivr/1097285034551a9484615867.27115734' ok
20150331123516.401067 <ExtModReceiver:ALL> Install 'chan.notify', prio 100 filte
r: 'targetid'='ivr/1097285034551a9484615867.27115734' ok
20150331123516.401332 <cdrbuild:INFO> Got message 'call.answered' for untracked
id 'ivr/1097285034551a9484615867.27115734'
20150331123516.401467 <sig/4:CALL> Call answered [0xb690e218]
20150331123516.401558 <link4/B:NOTE> ZapCircuit(5). Unable to send unknown event
 23 [0x8e1d490]
20150331123516.401594 <link4/Q931:ALL> Call(0,908). State 'CallPresent' --> 'Con
nectReq' [0xb750a5d0]
ivr2::OnEvent(setlocal 'id')
ivr2::OnSetting('id','ivr/1097285034551a9484615867.27115734',true)
ivr1::OnUnhandled(setlocal 'id')
ivr2::OnEvent(installed 'chan.dtmf')
ivr1::OnUnhandled(installed 'chan.dtmf')
ivr2::OnEvent(installed 'chan.notify')
ivr1::OnUnhandled(installed 'chan.notify')
20150331123516.411664 <link4/Q931:ALL> Call(0,908). State 'ConnectReq' --> 'Call
Present' [0xb750a5d0]
[b]20150331123516.411690 <link4/Q931:ALL> Call(0,908). State 'CallPresent' --> 'Inc
omingProceeding' [0xb750a5d0]
20150331123516.438394 <link4/Q931:ALL> Call(0,908). State 'IncomingProceeding' -
-> 'Null' [0xb750a5d0]
20150331123516.438850 <sig/4:CALL> Call hangup. Reason: 'wrong-state-message' [0
xb690e218][/b]
20150331123516.438919 <ALL> ExtModChan::disconnected() 'wrong-state-message' [0x
b6910950]
20150331123516.438940 >>> ExtModChan::~ExtModChan() [0xb6910950]
20150331123516.438956 <ALL> ExtModReceiver::die() pid=7329 dead=no [0xb6910a90
]
20150331123516.438974 <ALL> ExtModReceiver::die() waiting for pid=7329 to die
[0xb6910a90]
20150331123516.447434 <INFO> ExtModReceiver::die() pid=7329 did not exit? [0xb
6910a90]
20150331123516.452002 <ExtModule:WARN> Read error 9 on 0x8e081d8 [0xb6910a90]
20150331123516.452284 <WARN> Process 7329 has not exited on closing stdin - we
'll kill it
20150331123516.453685 <<< ExtModChan::~ExtModChan()
20150331123516.453777 <sig/4:CALL> Call destroyed. Reason: 'wrong-state-message'
. No signalling call [0xb690e218]
20150331123516.453811 <link4/Q931:ALL> Call(0,908) destroyed with reason 'wrong-
state-message' [0xb750a5d0]
20150331123516.454481 <ALL> ExtModReceiver::~ExtModReceiver() pid=0 [0xb6910a90]
20150331123516.454614 <ALL> ExtModReceiver::die() pid=0 dead=yes [0xb6910a90]
Tags No tags attached.
Attached Files

- Relationships

-  Notes
(0000598)
farzan (reporter)
2015-04-01 05:52

I think there's something wrong with how Q931 messages are handled. Following lines show that engine is sending CallProceeding after ConnectReq and that is why terminating exchange is complaining by sending a Status message with cause of Message unfit for call state. I've tried to reproduce the issue many times. approx. 1 out of 5 retries, problem vanishes! Of course this is an average, actual success and failure rate is very random and has no specific pattern.

20150401024648.597059 <link4/Q931:ALL> Call(0,1368). State 'ConnectReq' --> 'Cal
lPresent' [0x833f748]
20150401024648.597072 <link4/Q931:ALL> Call(0,1368). State 'CallPresent' --> 'In
comingProceeding' [0x833f748]
20150401024648.613793 <link4/Q931:ALL> Call(0,1368). State 'IncomingProceeding'
--> 'Null' [0x833f748]

- Issue History
Date Modified Username Field Change
2015-03-31 20:27 farzan New Issue
2015-04-01 05:52 farzan Note Added: 0000598


Copyright © 2000 - 2008 Mantis Group
Powered by Mantis Bugtracker