strange errors when using mod_python
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@xxx.22.9.195 parsing [context_3->generated] continue=false Dialplan: sofia/sipinterface_4/xxxxxxxxxxxx@xxx.22.9.195 Absolute Condition [generated] Dialplan: sofia/sipinterface_4/xxxxxxxxxxxx@xxx.22.9.195 Action answer() Dialplan: sofia/sipinterface_4/xxxxxxxxxxxx@xxx.22.9.195 Action bridge(sofia/sipinterface_5/xxxxxxxxxx@10.10.1.5:5060) Dialplan: sofia/sipinterface_4/xxxxxxxxxxxx@xxx.22.9.195 Action () 2011-03-11 14:20:49.075833 [DEBUG] switch_core_state_machine.c:119 (sofia/sipinterface_4/xxxxxxxxxxx@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@xxx.22.9.195 [BREAK] 2011-03-11 14:20:49.075833 [DEBUG] switch_core_state_machine.c:359 (sofia/sipinterface_4/xxxxxxxxxxx@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@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@xxx.22.9.195) State EXECUTE 2011-03-11 14:20:49.075833 [DEBUG] mod_sofia.c:240 sofia/sipinterface_4/xxxxxxxxxxxxx@xxx.22.9.195 SOFIA EXECUTE 2011-03-11 14:20:49.075833 [DEBUG] switch_core_state_machine.c:157 sofia/sipinterface_4/xxxxxxxxxx@xxx.22.9.195 Standard EXECUTE EXECUTE sofia/sipinterface_4/xxxxxxxxxxx@xxx.22.9.195 answer() 2011-03-11 14:20:49.075833 [DEBUG] sofia_glue.c:2990 AUDIO RTP [sofia/sipinterface_4/xxxxxxxxxxxx@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@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@xxx.22.9.195 [BREAK] 2011-03-11 14:20:49.076915 [DEBUG] switch_channel.c:2796 (sofia/sipinterface_4/xxxxxxxxxxxxx@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@xxx.22.9.195] has been answered 2011-03-11 14:20:49.077991 [DEBUG] sofia.c:4725 Channel sofia/sipinterface_4/xxxxxxxxxxxx@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@10.10.1.5:5060) 2011-03-11 14:20:49.077991 [DEBUG] switch_channel.c:2546 (sofia/sipinterface_4/xxxxxxxxxxx@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@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@xxx.22.9.195 [KILL] 2011-03-11 14:20:49.077991 [DEBUG] switch_core_session.c:1116 Send signal sofia/sipinterface_4/xxxxxxxxxxx@xxx.22.9.195 [BREAK] 2011-03-11 14:20:49.077991 [DEBUG] switch_core_state_machine.c:366 (sofia/sipinterface_4/xxxxxxxxxxxx@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@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@xxx.22.9.195) State HANGUP 2011-03-11 14:20:49.077991 [DEBUG] mod_sofia.c:457 Channel sofia/sipinterface_4/xxxxxxxxxxxx@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@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-... Sent from the freeswitch-users mailing list archive at Nabble.com.
This seems suspect; Invalid Application .22.9.195 Action bridge(sofia/sipinterface_5/xxxxxxxxxxxx@10.10.1.5:5060) /Peter -----Ursprungligt meddelande----- Från: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] För hkalyoncu Skickat: den 11 mars 2011 14:03 Till: freeswitch-users@lists.freeswitch.org Ämne: [Freeswitch-users] strange errors when using mod_python 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@xxx.22.9.195 parsing [context_3->generated] continue=false Dialplan: sofia/sipinterface_4/xxxxxxxxxxxx@xxx.22.9.195 Absolute Condition [generated] Dialplan: sofia/sipinterface_4/xxxxxxxxxxxx@xxx.22.9.195 Action answer() Dialplan: sofia/sipinterface_4/xxxxxxxxxxxx@xxx.22.9.195 Action bridge(sofia/sipinterface_5/xxxxxxxxxx@10.10.1.5:5060) Dialplan: sofia/sipinterface_4/xxxxxxxxxxxx@xxx.22.9.195 Action () 2011-03-11 14:20:49.075833 [DEBUG] switch_core_state_machine.c:119 (sofia/sipinterface_4/xxxxxxxxxxx@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@xxx.22.9.195 [BREAK] 2011-03-11 14:20:49.075833 [DEBUG] switch_core_state_machine.c:359 (sofia/sipinterface_4/xxxxxxxxxxx@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@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@xxx.22.9.195) State EXECUTE 2011-03-11 14:20:49.075833 [DEBUG] mod_sofia.c:240 sofia/sipinterface_4/xxxxxxxxxxxxx@xxx.22.9.195 SOFIA EXECUTE 2011-03-11 14:20:49.075833 [DEBUG] switch_core_state_machine.c:157 sofia/sipinterface_4/xxxxxxxxxx@xxx.22.9.195 Standard EXECUTE EXECUTE sofia/sipinterface_4/xxxxxxxxxxx@xxx.22.9.195 answer() 2011-03-11 14:20:49.075833 [DEBUG] sofia_glue.c:2990 AUDIO RTP [sofia/sipinterface_4/xxxxxxxxxxxx@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@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@xxx.22.9.195 [BREAK] 2011-03-11 14:20:49.076915 [DEBUG] switch_channel.c:2796 (sofia/sipinterface_4/xxxxxxxxxxxxx@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@xxx.22.9.195] has been answered 2011-03-11 14:20:49.077991 [DEBUG] sofia.c:4725 Channel sofia/sipinterface_4/xxxxxxxxxxxx@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@10.10.1.5:5060) 2011-03-11 14:20:49.077991 [DEBUG] switch_channel.c:2546 (sofia/sipinterface_4/xxxxxxxxxxx@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@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@xxx.22.9.195 [KILL] 2011-03-11 14:20:49.077991 [DEBUG] switch_core_session.c:1116 Send signal sofia/sipinterface_4/xxxxxxxxxxx@xxx.22.9.195 [BREAK] 2011-03-11 14:20:49.077991 [DEBUG] switch_core_state_machine.c:366 (sofia/sipinterface_4/xxxxxxxxxxxx@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@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@xxx.22.9.195) State HANGUP 2011-03-11 14:20:49.077991 [DEBUG] mod_sofia.c:457 Channel sofia/sipinterface_4/xxxxxxxxxxxx@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@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-... Sent from the freeswitch-users mailing list archive at Nabble.com. _______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org !DSPAM:4d7a1ea232768243425244!
yeah i wrote in my first message that partial text changing in every other error message. as you can see that is the part of the ip adress. but never used it in my script. it somehow gets part of channels name and shows it like invalid application. so strange. -- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/strange-errors-when-using-mod-... Sent from the freeswitch-users mailing list archive at Nabble.com.
Can you write the generated XML to a file on disk, to verify the XML given to FS is correct? You said it's ok manually, but it's possible that it's different when a FS session runs the script. -Steve On 11 March 2011 13:32, hkalyoncu <hkalyoncu@gmail.com> wrote:
yeah i wrote in my first message that partial text changing in every other error message. as you can see that is the part of the ip adress. but never used it in my script. it somehow gets part of channels name and shows it like invalid application. so strange.
-- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/strange-errors-when-using-mod-... Sent from the freeswitch-users mailing list archive at Nabble.com.
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
yes i dumped the generated xml output to a file. here is a sample generated xml: <?xml version="1.0" encoding="UTF-8" standalone="no"?> the xml output is as expected -- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/strange-errors-when-using-mod-... Sent from the freeswitch-users mailing list archive at Nabble.com.
xml is not displayed correctly after posting here it is again without tags: xml version="1.0" encoding="UTF-8" standalone="no" document type="freeswitch/xml" section name="dialplan" description="RE Dial Plan For FreeSWITCH" context name="context_3" extension name="generated" condition action application="answer" action application="bridge" data="sofia/sipinterface_5/xxxxxxxxxx@10.10.1.5:5060" action application="hangup" condition extension context section document -- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/strange-errors-when-using-mod-... Sent from the freeswitch-users mailing list archive at Nabble.com.
hkalyoncu wrote:
extension name="generated" I don't know if the same generated extension name is an issue. ----- FreeSWITCH hosted on a Seagate DockStar with OpenWRT. -- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/strange-errors-when-using-mod-... Sent from the freeswitch-users mailing list archive at Nabble.com.
participants (4)
-
hkalyoncu
-
mazilo
-
Peter Olsson
-
Steven Ayre