[Freeswitch-users] strange errors when using mod_python

[hkalyoncu]

hello,

im doing dynamic routing with mod_python.
my python script returns a dialplan after checking db record in terms of
destination number.

the problem is:
although python script returns correct result, freeswitch cannot process
returned dialplan and gives strange errors. This is not happening in all
calls but i can say 3-4 out of 10 calls drop like this.

i rebuilt freeswitch with latest repository but there is no change.   

here is a sample output from console(sorry for censored fields):

2011-03-11 14:20:49.073690 [INFO] mod_dialplan_xml.c:331 Processing
xxxxxxxxxxxx ->xxxxxxxxxxxx in context context_3
2011-03-11 14:20:49.074747 [NOTICE] mod_python.c:118 Invoking py module: dp
2011-03-11 14:20:49.074747 [DEBUG] mod_python.c:188 Call python script
2011-03-11 14:20:49.074747 [INFO] switch_cpp.cpp:1197 calling number :
xxxxxxxxxx
2011-03-11 14:20:49.074747 [INFO] switch_cpp.cpp:1197 called number :
xxxxxxxxxx
2011-03-11 14:20:49.075833 [DEBUG] mod_python.c:191 Finished calling python
script
Dialplan: sofia/sipinterface_4/xxxxxxxxxxxx at xxx.22.9.195 parsing
[context_3->generated] continue=false
Dialplan: sofia/sipinterface_4/xxxxxxxxxxxx at xxx.22.9.195 Absolute Condition
[generated]
Dialplan: sofia/sipinterface_4/xxxxxxxxxxxx at xxx.22.9.195 Action answer()
Dialplan: sofia/sipinterface_4/xxxxxxxxxxxx at xxx.22.9.195 Action
bridge(sofia/sipinterface_5/xxxxxxxxxx at 10.10.1.5:5060)
Dialplan: sofia/sipinterface_4/xxxxxxxxxxxx at xxx.22.9.195 Action ()
2011-03-11 14:20:49.075833 [DEBUG] switch_core_state_machine.c:119
(sofia/sipinterface_4/xxxxxxxxxxx at xxx.22.9.195) State Change CS_ROUTING ->
CS_EXECUTE
2011-03-11 14:20:49.075833 [DEBUG] switch_core_session.c:1116 Send signal
sofia/sipinterface_4/xxxxxxxxxxx at xxx.22.9.195 [BREAK]
2011-03-11 14:20:49.075833 [DEBUG] switch_core_state_machine.c:359
(sofia/sipinterface_4/xxxxxxxxxxx at xxx.22.9.195) State ROUTING going to sleep
2011-03-11 14:20:49.075833 [DEBUG] switch_core_state_machine.c:320
(sofia/sipinterface_4/xxxxxxxxxxx at xxx.22.9.195) Running State Change
CS_EXECUTE
2011-03-11 14:20:49.075833 [DEBUG] switch_core_state_machine.c:366
(sofia/sipinterface_4/xxxxxxxxxxx at xxx.22.9.195) State EXECUTE
2011-03-11 14:20:49.075833 [DEBUG] mod_sofia.c:240
sofia/sipinterface_4/xxxxxxxxxxxxx at xxx.22.9.195 SOFIA EXECUTE
2011-03-11 14:20:49.075833 [DEBUG] switch_core_state_machine.c:157
sofia/sipinterface_4/xxxxxxxxxx at xxx.22.9.195 Standard EXECUTE
EXECUTE sofia/sipinterface_4/xxxxxxxxxxx at xxx.22.9.195 answer()
2011-03-11 14:20:49.075833 [DEBUG] sofia_glue.c:2990 AUDIO RTP
[sofia/sipinterface_4/xxxxxxxxxxxx at xxx.22.9.195] 10.xxx.xxx.xxx port 31882
-> xxx.xxx.xxx.xxx port 35892 codec: 18 ms: 20
2011-03-11 14:20:49.075833 [DEBUG] switch_rtp.c:1623 Starting timer [soft]
160 bytes per 20ms
2011-03-11 14:20:49.076915 [DEBUG] sofia_glue.c:3245 Set 2833 dtmf send
payload to 101
2011-03-11 14:20:49.076915 [DEBUG] sofia_glue.c:3250 Set 2833 dtmf receive
payload to 101
2011-03-11 14:20:49.076915 [DEBUG] mod_sofia.c:681 Local SDP
sofia/sipinterface_4/xxxxxxxxxxx at xxx.22.9.195:
v=0
o=FreeSWITCH 1299814167 1299814168 IN IP4 10.xxx.xxx.xxx
s=FreeSWITCH
c=IN IP4 10.xxx.xxx.xxx
t=0 0
m=audio 31882 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

2011-03-11 14:20:49.076915 [DEBUG] switch_core_session.c:709 Send signal
sofia/sipinterface_4/xxxxxxxxxxx at xxx.22.9.195 [BREAK]
2011-03-11 14:20:49.076915 [DEBUG] switch_channel.c:2796
(sofia/sipinterface_4/xxxxxxxxxxxxx at xxx.22.9.195) Callstate Change RINGING
-> ACTIVE
2011-03-11 14:20:49.077991 [NOTICE] mod_dptools.c:929 Channel
[sofia/sipinterface_4/xxxxxxxxxxx at xxx.22.9.195] has been answered
2011-03-11 14:20:49.077991 [DEBUG] sofia.c:4725 Channel
sofia/sipinterface_4/xxxxxxxxxxxx at xxx.22.9.195 entering state
[completed][200]
2011-03-11 14:20:49.077991 [ERR] switch_core_session.c:1918 Invalid
Application .22.9.195 Action
bridge(sofia/sipinterface_5/xxxxxxxxxxxx at 10.10.1.5:5060)

2011-03-11 14:20:49.077991 [DEBUG] switch_channel.c:2546
(sofia/sipinterface_4/xxxxxxxxxxx at xxx.22.9.195) Callstate Change ACTIVE ->
HANGUP
2011-03-11 14:20:49.077991 [NOTICE] switch_core_session.c:1919 Hangup
sofia/sipinterface_4/xxxxxxxxxxx at xxx.22.9.195 [CS_EXECUTE]
[DESTINATION_OUT_OF_ORDER]
2011-03-11 14:20:49.077991 [DEBUG] switch_channel.c:2562 Send signal
sofia/sipinterface_4/xxxxxxxxxxx at xxx.22.9.195 [KILL]
2011-03-11 14:20:49.077991 [DEBUG] switch_core_session.c:1116 Send signal
sofia/sipinterface_4/xxxxxxxxxxx at xxx.22.9.195 [BREAK]
2011-03-11 14:20:49.077991 [DEBUG] switch_core_state_machine.c:366
(sofia/sipinterface_4/xxxxxxxxxxxx at xxx.22.9.195) State EXECUTE going to
sleep
2011-03-11 14:20:49.077991 [DEBUG] switch_core_state_machine.c:320
(sofia/sipinterface_4/xxxxxxxxxxxx at xxx.22.9.195) Running State Change
CS_HANGUP
2011-03-11 14:20:49.077991 [DEBUG] switch_core_state_machine.c:560
(sofia/sipinterface_4/xxxxxxxxxxxx at xxx.22.9.195) State HANGUP
2011-03-11 14:20:49.077991 [DEBUG] mod_sofia.c:457 Channel
sofia/sipinterface_4/xxxxxxxxxxxx at xxx.22.9.195 hanging up, cause:
DESTINATION_OUT_OF_ORDER
2011-03-11 14:20:49.077991 [DEBUG] mod_sofia.c:500 Sending BYE to
sofia/sipinterface_4/xxxxxxxxxxxx at xxx.22.9.195

The text in error message (Invalid Application xxxxx) changes in every call.
i recheck the python script several times, each time  it gives expected xml
output.
But freeswitch somehow cannot get (or process?)  that output.

Any idea? 

--
View this message in context: http://freeswitch-users.2379917.n2.nabble.com/strange-errors-when-using-mod-python-tp6161361p6161361.html
Sent from the freeswitch-users mailing list archive at Nabble.com.