Mantis Bugtracker

Viewing Issue Simple Details Jump to Notes ] View Advanced ] Issue History ] Print ]
ID Category Severity Reproducibility Date Submitted Last Update
0000339 [Yate - Yet Another Telephony Engine] module minor always 2013-04-18 14:43 2013-04-19 13:44
Reporter asymetrixs View Status public  
Assigned To paulc
Priority normal Resolution open  
Status assigned   Product Version 4.x
Summary 0000339: JS: (dtmf) handler does not work when routing script hangs in loop
Description Right after a message like this

<yrtp:INFO> YRTPWrapper::gotDTMF('6') [0x7ff4ec01aab0]

the DTMF handler should write something like that

VALUE: 6 on chan XYZ

but that does not work when JS hangs in the loop, but it does when there is no loop.
Additional Information SCRIPT:

function onDTMF(message)
{
        Engine.debug("VALUE: " + message.text + " on chan " + message.id);
}

Message.install(onDTMF, "chan.dtmf", 40);

if(message.direction == 'incoming')
{
        Channel.callTo("dbwave/play//tmp/voice.wav");

        Engine.debug("IN JAVASCRIPT ROUTING SCRIPT");

        while (true)
        {
                var db = new Message("database");
                db.account = "dbmain";
                db.query = "SELECT pg_sleep(3);";

                db.dispatch();

                Engine.debug("Waiting");
        }

        Engine.debug("end");
}



================================================================

OUTPUT:

Yate engine is initialized and starting up on ubuntu
<INFO> Creating new message dispatching thread (0 running)
<sip:INFO> 'udp:0.0.0.0:5060' received 922 bytes SIP message from 172.16.1.29:56802 [0xb602a0]
------
INVITE sip:492XXXXXXXXX@172.16.1.23;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 172.16.1.29:56802;branch=z9hG4bK-d8754z-854e8c44d22eb6a0-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:4915XXXXXXXXXX@172.16.1.29:56802;transport=UDP>
To: <sip:492XXXXXXXXX@172.16.1.23;transport=UDP>
From: <sip:4915XXXXXXXXXX@172.16.1.23;transport=UDP>;tag=30909f66
Call-ID: YjEzZmIyNTg0OTYwMzMyMTAwZmE5MDc2NTdhZmQ3OTE.
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
Content-Type: application/sdp
Supported: replaces, norefersub, extended-refer, X-cisco-serviceuri
User-Agent: Zoiper r16950
Allow-Events: presence, kpml
Content-Length: 238

v=0
o=Z 0 0 IN IP4 172.16.1.29
s=Z
c=IN IP4 172.16.1.29
t=0 0
m=audio 41468 RTP/AVP 3 110 98 8 0 101
a=rtpmap:110 speex/8000
a=rtpmap:98 iLBC/8000
a=fmtp:98 mode=20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
------
<sip:INFO> 'udp:0.0.0.0:5060' sending code 100 0x7ff4e0000960 to 172.16.1.29:56802 [0xb602a0]
------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 172.16.1.29:56802;branch=z9hG4bK-d8754z-854e8c44d22eb6a0-1---d8754z-;rport=56802;received=172.16.1.29
From: <sip:4915XXXXXXXXXX@172.16.1.23;transport=UDP>;tag=30909f66
To: <sip:492XXXXXXXXX@172.16.1.23;transport=UDP>
Call-ID: YjEzZmIyNTg0OTYwMzMyMTAwZmE5MDc2NTdhZmQ3OTE.
CSeq: 1 INVITE
Server: YATE/4.3.1
Content-Length: 0

------
<sip/1:ALL> YateSIPConnection::YateSIPConnection(0x7ff4e00011e0,0x7ff4d801fca0) [0x7ff4e0001a00]
<sip/1:ALL> NAT address is '(null)' [0x7ff4e0001a00]
<INFO> Could not classify call from '4915XXXXXXXXXX', wasted 7 usec
<sip/1:ALL> NAT address is '(null)' [0x7ff4e0001a00]
<wave:INFO> Play from wave file '/tmp/voice.wav'
<wave/1:ALL> WaveChan::WaveChan(play) [0x7ff4ec017b60]
<wave:ALL> WaveSource::WaveSource("/tmp/voice.wav",0x7ff4ec017b60) [0x7ff4ec017dd0]
<MILD> .wav not supported yet, assuming raw signed linear
<sip/1:NOTE> Answering now call sip/1 because we have no targetid [0x7ff4e0001a00]
<yrtp:ALL> RTP/AVP message received
<yrtp:INFO> Guessed local IP '172.16.1.23' for remote '172.16.1.29'
<yrtp:ALL> YRTPWrapper::YRTPWrapper('172.16.1.23',0x7ff4e0001a00,'audio',bidir,0x7ff4ec01a140,false) [0x7ff4ec01aab0]
<yrtp:ALL> YRTPWrapper::setupRTP("172.16.1.23",true) [0x7ff4ec01aab0]
<yrtp:INFO> Session 'yrtp/934572097' 0x7ff4ec01ac20 bound to 172.16.1.23:30020 +RTCP [0x7ff4ec01aab0]
<javascript:NOTE> Channel 'sip/1' already assisted!
<yrtp:ALL> YRTPSource::YRTPSource(0x7ff4ec01aab0) [0x7ff4ec01af90]
<yrtp:ALL> YRTPConsumer::YRTPConsumer(0x7ff4ec01aab0) [0x7ff4ec01b0e0]
<INFO> DataTranslator::attachChain [0x7ff4ec017dd0] 'slin' -> [0x7ff4ec01b0e0] '(null)' not possible
<yrtp:ALL> YRTPWrapper::setupSRTP(false) [0x7ff4ec01aab0]
<sip:INFO> 'udp:0.0.0.0:5060' sending code 200 0x7ff4ec019660 to 172.16.1.29:56802 [0xb602a0]
------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.16.1.29:56802;branch=z9hG4bK-d8754z-854e8c44d22eb6a0-1---d8754z-;rport=56802;received=172.16.1.29
From: <sip:4915XXXXXXXXXX@172.16.1.23;transport=UDP>;tag=30909f66
To: <sip:492XXXXXXXXX@172.16.1.23;transport=UDP>;tag=1205248606
Call-ID: YjEzZmIyNTg0OTYwMzMyMTAwZmE5MDc2NTdhZmQ3OTE.
CSeq: 1 INVITE
Server: YATE/4.3.1
Contact: <sip:492XXXXXXXXX@172.16.1.23:5060>
Allow: ACK, INVITE, BYE, CANCEL, REGISTER, REFER, OPTIONS, INFO
Content-Type: application/sdp
Content-Length: 314

v=0
o=yate 1366285151 1366285151 IN IP4 172.16.1.23
s=SIP Call
c=IN IP4 172.16.1.23
t=0 0
m=audio 30020 RTP/AVP 3 110 98 8 0 101
a=rtpmap:3 GSM/8000
a=rtpmap:110 SPEEX/8000
a=rtpmap:98 iLBC/8000
a=fmtp:98 mode=20
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=ptime:20
------
<sip:INFO> 'udp:0.0.0.0:5060' received 469 bytes SIP message from 172.16.1.29:56802 [0xb602a0]
------
ACK sip:492XXXXXXXXX@172.16.1.23:5060 SIP/2.0
Via: SIP/2.0/UDP 172.16.1.29:56802;branch=z9hG4bK-d8754z-0c52c31f4b4c9fe2-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:4915XXXXXXXXXX@172.16.1.29:56802;transport=UDP>
To: <sip:492XXXXXXXXX@172.16.1.23;transport=UDP>;tag=1205248606
From: <sip:4915XXXXXXXXXX@172.16.1.23;transport=UDP>;tag=30909f66
Call-ID: YjEzZmIyNTg0OTYwMzMyMTAwZmE5MDc2NTdhZmQ3OTE.
CSeq: 1 ACK
User-Agent: Zoiper r16950
Content-Length: 0

------
<yrtp:ALL> RTP/AVP message received
<yrtp:ALL> Wrapper 0x7ff4ec01aab0 found by CallEndpoint 0x7ff4e0001a00
<yrtp:ALL> YRTPWrapper::startRTP("172.16.1.29",41468) [0x7ff4ec01aab0]
<yrtp:INFO> RTP starting format 'gsm' payload 3 [0x7ff4ec01aab0]
>>> DataTranslator::detachChain(0x7ff4ec017dd0,0x7ff4ec01b0e0)
<<< DataTranslator::detachChain
<ALL> GsmCodec::GsmCodec("slin","gsm",encoding) [0x7ff4e0007980]
<ALL> Created DataTranslator 0x7ff4e0007980 for 'slin' -> 'gsm' by factory 0x7ff50a1430a8 (len=1)
<ALL> DataTranslator::attachChain [0x7ff4ec017dd0] 'slin' -> [0x7ff4ec01b0e0] 'gsm' succeeded
<NOTE> Choosing started 'audio' format 'gsm' [0x7ff4e0008220]
<wave:ALL> WaveSource '(null)' end of data (62604 played) chan=0x7ff4ec017b60 [0x7ff4ec017dd0]
<wave:ALL> WaveSource cleanup, total=62604, chan=(nil) [0x7ff4ec017dd0]
>>> DataTranslator::detachChain(0x7ff4ec017dd0,0x7ff4ec01b0e0)
  >>> DataTranslator::detachChain(0x7ff4ec017dd0,0x7ff4e0007980)
  <<< DataTranslator::detachChain
  <ALL> GsmCodec::~GsmCodec() [0x7ff4e0007980]
<<< DataTranslator::detachChain
<sip/1:ALL> YateSIPConnection::disconnected() '(null)' [0x7ff4e0001a00]
<wave:ALL> WaveSource::~WaveSource() [0x7ff4ec017dd0] total=62604 stamp=31200
<wave:INFO> WaveSource rate=16037 b/s
<wave/1:ALL> WaveChan::~WaveChan() wave/1 [0x7ff4ec017b60]
<NOTE> IN JAVASCRIPT ROUTING SCRIPT
<pgsqldb:ALL> Performing query "SELECT pg_sleep(3);" for 'dbmain'
<MILD> Creating new message dispatching thread (1 running)
<pgsqldb:ALL> Query for 'dbmain.1' returned 1 rows, 1 affected [0xa33f70]
<NOTE> Waiting
<pgsqldb:ALL> Performing query "SELECT pg_sleep(3);" for 'dbmain'
<yrtp:INFO> YRTPWrapper::gotDTMF('5') [0x7ff4ec01aab0]
<pgsqldb:ALL> Query for 'dbmain.1' returned 1 rows, 1 affected [0xa33f70]
<NOTE> Waiting
<pgsqldb:ALL> Performing query "SELECT pg_sleep(3);" for 'dbmain'
<MILD> Creating new message dispatching thread (2 running)
<yrtp:INFO> YRTPWrapper::gotDTMF('6') [0x7ff4ec01aab0]
<yrtp:INFO> YRTPWrapper::gotDTMF('6') [0x7ff4ec01aab0]
<yrtp:INFO> YRTPWrapper::gotDTMF('6') [0x7ff4ec01aab0]
<pgsqldb:ALL> Query for 'dbmain.1' returned 1 rows, 1 affected [0xa33f70]
<NOTE> Waiting
<pgsqldb:ALL> Performing query "SELECT pg_sleep(3);" for 'dbmain'
<MILD> Creating new message dispatching thread (3 running)
<MILD> Creating new message dispatching thread (4 running)
<pgsqldb:ALL> Query for 'dbmain.1' returned 1 rows, 1 affected [0xa33f70]
<NOTE> Waiting
<pgsqldb:ALL> Performing query "SELECT pg_sleep(3);" for 'dbmain'
<sip:INFO> 'udp:0.0.0.0:5060' received 469 bytes SIP message from 172.16.1.29:56802 [0xb602a0]
------
BYE sip:492XXXXXXXXX@172.16.1.23:5060 SIP/2.0
Via: SIP/2.0/UDP 172.16.1.29:56802;branch=z9hG4bK-d8754z-e598e882cf8cdce3-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:4915XXXXXXXXXX@172.16.1.29:56802;transport=UDP>
To: <sip:492XXXXXXXXX@172.16.1.23;transport=UDP>;tag=1205248606
From: <sip:4915XXXXXXXXXX@172.16.1.23;transport=UDP>;tag=30909f66
Call-ID: YjEzZmIyNTg0OTYwMzMyMTAwZmE5MDc2NTdhZmQ3OTE.
CSeq: 2 BYE
User-Agent: Zoiper r16950
Content-Length: 0

------
<sip:INFO> 'udp:0.0.0.0:5060' sending code 100 0x7ff4e0006360 to 172.16.1.29:56802 [0xb602a0]
------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 172.16.1.29:56802;branch=z9hG4bK-d8754z-e598e882cf8cdce3-1---d8754z-;rport=56802;received=172.16.1.29
From: <sip:4915XXXXXXXXXX@172.16.1.23;transport=UDP>;tag=30909f66
To: <sip:492XXXXXXXXX@172.16.1.23;transport=UDP>;tag=1205248606
Call-ID: YjEzZmIyNTg0OTYwMzMyMTAwZmE5MDc2NTdhZmQ3OTE.
CSeq: 2 BYE
Server: YATE/4.3.1
Content-Length: 0

------
<yrtp:ALL> RTP/AVP message received
<yrtp:ALL> Wrapper 0x7ff4ec01aab0 found by ID 'yrtp/934572097'
<yrtp:INFO> YRTPWrapper::terminate() [0x7ff4ec01aab0]
<yrtp:ALL> YRTPSource::~YRTPSource() [0x7ff4ec01af90] wrapper=0x7ff4ec01aab0 ts=127680
<yrtp:ALL> YRTPConsumer::~YRTPConsumer() [0x7ff4ec01b0e0] wrapper=0x7ff4ec01aab0 ts=31040
<yrtp:ALL> YRTPWrapper::~YRTPWrapper() bidir 'audio' [0x7ff4ec01aab0]
<ALL> Cleaning up RTP 0x7ff4ec01ac20 [0x7ff4ec01aab0]
<sip/1:ALL> YateSIPConnection::hangup() state=3 trans=(nil) error='(null)' code=0 reason='(null)' [0x7ff4e0001a00]
<sip:INFO> 'udp:0.0.0.0:5060' sending code 200 0x7ff4e0008220 to 172.16.1.29:56802 [0xb602a0]
------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.16.1.29:56802;branch=z9hG4bK-d8754z-e598e882cf8cdce3-1---d8754z-;rport=56802;received=172.16.1.29
From: <sip:4915XXXXXXXXXX@172.16.1.23;transport=UDP>;tag=30909f66
To: <sip:492XXXXXXXXX@172.16.1.23;transport=UDP>;tag=1205248606
Call-ID: YjEzZmIyNTg0OTYwMzMyMTAwZmE5MDc2NTdhZmQ3OTE.
CSeq: 2 BYE
P-RTP-Stat: PS=195,OS=6435,PR=807,OR=25703,PL=0
Server: YATE/4.3.1
Allow: ACK, INVITE, BYE, CANCEL, REGISTER, REFER, OPTIONS, INFO
Content-Length: 0

------
<MILD> Creating new message dispatching thread (5 running)
<pgsqldb:ALL> Query for 'dbmain.1' returned 1 rows, 1 affected [0xa33f70]
<NOTE> Waiting
<pgsqldb:ALL> Performing query "SELECT pg_sleep(3);" for 'dbmain'
Tags No tags attached.
Attached Files

- Relationships

-  Notes
(0000520)
paulc (administrator)
2013-04-19 13:17

Because the Javascript language is not multithreaded any message or action in other thread waits until the instance is not in use.

SVN Rev. 5465 (2013-04-12) adds the possibility of unlocking the script while a message is dispatched. The lock is reacquired before execution continues.

However, because of bug 0000336 this is not yet usable in channes instance scripts.

- Issue History
Date Modified Username Field Change
2013-04-18 14:43 asymetrixs New Issue
2013-04-19 13:17 paulc Note Added: 0000520
2013-04-19 13:17 paulc Status new => acknowledged
2013-04-19 13:44 paulc Status acknowledged => assigned
2013-04-19 13:44 paulc Assigned To => paulc


Copyright © 2000 - 2008 Mantis Group
Powered by Mantis Bugtracker