Hello All, I have a setup which is SIPML5 -> Kamailio(Websocket) -> Freeswitch. All I am trying to do is initiate a call from SIPML5 and Play a Music file from freeswitch. This works, but the call hangs up after 30 seconds due to ACK timeout from from the SIPML5.
What I can see is the SIPML5 from Chrome does send an ACK on websocket, but I see the following error in kamailio syslog:
*via_builder(): TCP/TLS connection (id: 0) for WebSocket could not be found* *ERROR: <core> [msg_translator.c:1725]: build_req_buf_from_sip_req(): could not create Via header* *ERROR: <core> [forward.c:607]: forward_request(): ERROR: forward_request: building failed* *ERROR: sl [sl_funcs.c:371]: sl_reply_error(): ERROR: sl_reply_error used: I'm terribly sorry, server error occurred (1/SL)*
Can someone help me understand what I am missing here and why kamailio is not able to create a VIA header to forward this request towards freeswitch. I have built a simple config file by following https://gist.github.com/jesusprubio/4066845 as reference.
Any help in understanding this is really appreciated.
Thanks,
--- Jayesh
Hello,
On 6/14/13 4:52 PM, Jayesh Nambiar wrote:
Hello All, I have a setup which is SIPML5 -> Kamailio(Websocket) -> Freeswitch. All I am trying to do is initiate a call from SIPML5 and Play a Music file from freeswitch. This works, but the call hangs up after 30 seconds due to ACK timeout from from the SIPML5.
What I can see is the SIPML5 from Chrome does send an ACK on websocket, but I see the following error in kamailio syslog:
*via_builder(): TCP/TLS connection (id: 0) for WebSocket could not be found* *ERROR: <core> [msg_translator.c:1725]: build_req_buf_from_sip_req(): could not create Via header* *ERROR: <core> [forward.c:607]: forward_request(): ERROR: forward_request: building failed* *ERROR: sl [sl_funcs.c:371]: sl_reply_error(): ERROR: sl_reply_error used: I'm terribly sorry, server error occurred (1/SL)*
Can someone help me understand what I am missing here and why kamailio is not able to create a VIA header to forward this request towards freeswitch. I have built a simple config file by following https://gist.github.com/jesusprubio/4066845 as reference.
Any help in understanding this is really appreciated.
looks like the web rtc connection was down (closed by one side or interrupted by the network). You can check with kamcmd the list of active connections.
Cheers, Daniel
Hi Daniel, I checked using the kamcmd command and I see the webrtc connection active. The ACK comes from the webrtc client but somehow kamailio is unable to create a via header and forward the request. The ACK coming from webrtc client is as follows:
SEND: ACK sip:1223@126.128.68.8:5065;transport=udp SIP/2.0 Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKJ0Qsiuh94B2slPLp19qH;rport From: "Jayesh"sip:1000001001@ghanti.com;tag=vsTKsfB1ZR8EkHTPqzyc To: sip:1223@ghanti.com;tag=UQ9veX0vUg7QS Contact: "Jayesh"sip:1000001001@df7jal23ls0d.invalid ;rtcweb-breaker=no;click2call=no;transport=ws;+g.oma.sip-im;+sip.ice;language="en,fr" Call-ID: 2c76d5ee-e9d0-7f22-8be2-76e80b4ab48b CSeq: 42684 ACK Content-Length: 0 Route: sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp Max-Forwards: 70 Proxy-Authorization: Digest username="1000001001",realm="ghanti.com ",nonce="UcFsQ1HBaxc84k4N1J00fpVDj9G57x5p",uri="sip:1223@126.128.68.8:5065 ;transport=udp",response="5b18a2182c335315875224f2244fb48b",algorithm=MD5 Route: sip:126.128.68.9:8080 ;transport=ws;r2=on;lr=on;ftag=vsTKsfB1ZR8EkHTPqzyc;nat=yes Route: sip:126.128.68.9;r2=on;lr=on;ftag=vsTKsfB1ZR8EkHTPqzyc;nat=yes User-Agent: IM-client/OMA1.0 sipML5-v1.2013.03.27 Organization: Doubango Telecom
Where 126.128.68.9:5060 is the Kamailio; 126.128.68.8:5065 is a freeswitch playing music and the request is received on 126.128.68.9:8080 which is kamailio acting as a websocket server. Also the connection between Kamailio and Freeswitch is UDP. I am not able to use the websocket module just because of this small problem caused in signaling. Any help is really appreciated. Could it be related to the nathelper module?
Thanks,
--- Jayesh
On Tue, Jun 18, 2013 at 2:17 PM, Daniel-Constantin Mierla <miconda@gmail.com
wrote:
Hello,
On 6/14/13 4:52 PM, Jayesh Nambiar wrote:
Hello All, I have a setup which is SIPML5 -> Kamailio(Websocket) -> Freeswitch. All I am trying to do is initiate a call from SIPML5 and Play a Music file from freeswitch. This works, but the call hangs up after 30 seconds due to ACK timeout from from the SIPML5.
What I can see is the SIPML5 from Chrome does send an ACK on websocket, but I see the following error in kamailio syslog:
*via_builder(): TCP/TLS connection (id: 0) for WebSocket could not be found* *ERROR: <core> [msg_translator.c:1725]: build_req_buf_from_sip_req(): could not create Via header* *ERROR: <core> [forward.c:607]: forward_request(): ERROR: forward_request: building failed* *ERROR: sl [sl_funcs.c:371]: sl_reply_error(): ERROR: sl_reply_error used: I'm terribly sorry, server error occurred (1/SL)*
Can someone help me understand what I am missing here and why kamailio is not able to create a VIA header to forward this request towards freeswitch. I have built a simple config file by following https://gist.github.com/jesusprubio/4066845 as reference.
Any help in understanding this is really appreciated.
looks like the web rtc connection was down (closed by one side or interrupted by the network). You can check with kamcmd the list of active connections.
Cheers, Daniel
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda Kamailio Advanced Training, San Francisco, USA - June 24-27, 2013
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
Hi, Is it possible that this could be a problem in the script. But when I call using a normal SIP Client like X-Lite, it works well. This only happens when the request comes on websocket. Is there something to be handled specially when handling requests like ACK over websocket? The reference is more or less taken from https://gist.github.com/jesusprubio/4066845
--- Jayesh
On Wed, Jun 19, 2013 at 2:14 PM, Jayesh Nambiar jayesh1017@gmail.comwrote:
Hi Daniel, I checked using the kamcmd command and I see the webrtc connection active. The ACK comes from the webrtc client but somehow kamailio is unable to create a via header and forward the request. The ACK coming from webrtc client is as follows:
SEND: ACK sip:1223@126.128.68.8:5065;transport=udp SIP/2.0 Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKJ0Qsiuh94B2slPLp19qH;rport From: "Jayesh"sip:1000001001@ghanti.com;tag=vsTKsfB1ZR8EkHTPqzyc To: sip:1223@ghanti.com;tag=UQ9veX0vUg7QS Contact: "Jayesh"sip:1000001001@df7jal23ls0d.invalid ;rtcweb-breaker=no;click2call=no;transport=ws;+g.oma.sip-im;+sip.ice;language="en,fr" Call-ID: 2c76d5ee-e9d0-7f22-8be2-76e80b4ab48b CSeq: 42684 ACK Content-Length: 0 Route: sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp Max-Forwards: 70 Proxy-Authorization: Digest username="1000001001",realm="ghanti.com ",nonce="UcFsQ1HBaxc84k4N1J00fpVDj9G57x5p",uri="sip:1223@126.128.68.8:5065 ;transport=udp",response="5b18a2182c335315875224f2244fb48b",algorithm=MD5 Route: sip:126.128.68.9:8080 ;transport=ws;r2=on;lr=on;ftag=vsTKsfB1ZR8EkHTPqzyc;nat=yes Route: sip:126.128.68.9;r2=on;lr=on;ftag=vsTKsfB1ZR8EkHTPqzyc;nat=yes User-Agent: IM-client/OMA1.0 sipML5-v1.2013.03.27 Organization: Doubango Telecom
Where 126.128.68.9:5060 is the Kamailio; 126.128.68.8:5065 is a freeswitch playing music and the request is received on 126.128.68.9:8080which is kamailio acting as a websocket server. Also the connection between Kamailio and Freeswitch is UDP. I am not able to use the websocket module just because of this small problem caused in signaling. Any help is really appreciated. Could it be related to the nathelper module?
Thanks,
--- Jayesh
On Tue, Jun 18, 2013 at 2:17 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
Hello,
On 6/14/13 4:52 PM, Jayesh Nambiar wrote:
Hello All, I have a setup which is SIPML5 -> Kamailio(Websocket) -> Freeswitch. All I am trying to do is initiate a call from SIPML5 and Play a Music file from freeswitch. This works, but the call hangs up after 30 seconds due to ACK timeout from from the SIPML5.
What I can see is the SIPML5 from Chrome does send an ACK on websocket, but I see the following error in kamailio syslog:
*via_builder(): TCP/TLS connection (id: 0) for WebSocket could not be found* *ERROR: <core> [msg_translator.c:1725]: build_req_buf_from_sip_req(): could not create Via header* *ERROR: <core> [forward.c:607]: forward_request(): ERROR: forward_request: building failed* *ERROR: sl [sl_funcs.c:371]: sl_reply_error(): ERROR: sl_reply_error used: I'm terribly sorry, server error occurred (1/SL)*
Can someone help me understand what I am missing here and why kamailio is not able to create a VIA header to forward this request towards freeswitch. I have built a simple config file by following https://gist.github.com/jesusprubio/4066845 as reference.
Any help in understanding this is really appreciated.
looks like the web rtc connection was down (closed by one side or interrupted by the network). You can check with kamcmd the list of active connections.
Cheers, Daniel
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda Kamailio Advanced Training, San Francisco, USA - June 24-27, 2013
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
Are you sure the error messages are printed for this ACK, because it has to be sent via UDP, not via WS, thus the messages seem to be unrelated.
Get the log messages with debug=3 in order to see what is happening.
Cheers, Daniel
On 6/22/13 9:10 AM, Jayesh Nambiar wrote:
Hi, Is it possible that this could be a problem in the script. But when I call using a normal SIP Client like X-Lite, it works well. This only happens when the request comes on websocket. Is there something to be handled specially when handling requests like ACK over websocket? The reference is more or less taken from https://gist.github.com/jesusprubio/4066845
--- Jayesh
On Wed, Jun 19, 2013 at 2:14 PM, Jayesh Nambiar <jayesh1017@gmail.com mailto:jayesh1017@gmail.com> wrote:
Hi Daniel, I checked using the kamcmd command and I see the webrtc connection active. The ACK comes from the webrtc client but somehow kamailio is unable to create a via header and forward the request. The ACK coming from webrtc client is as follows: SEND: ACK sip:1223@126.128.68.8:5065;transport=udp SIP/2.0 Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKJ0Qsiuh94B2slPLp19qH;rport From: "Jayesh"<sip:1000001001@ghanti.com <mailto:sip%3A1000001001@ghanti.com>>;tag=vsTKsfB1ZR8EkHTPqzyc To: <sip:1223@ghanti.com <mailto:sip%3A1223@ghanti.com>>;tag=UQ9veX0vUg7QS Contact: "Jayesh"<sip:1000001001@df7jal23ls0d.invalid;rtcweb-breaker=no;click2call=no;transport=ws>;+g.oma.sip-im;+sip.ice;language="en,fr" Call-ID: 2c76d5ee-e9d0-7f22-8be2-76e80b4ab48b CSeq: 42684 ACK Content-Length: 0 Route: <sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp> Max-Forwards: 70 Proxy-Authorization: Digest username="1000001001",realm="ghanti.com <http://ghanti.com>",nonce="UcFsQ1HBaxc84k4N1J00fpVDj9G57x5p",uri="sip:1223@126.128.68.8:5065;transport=udp",response="5b18a2182c335315875224f2244fb48b",algorithm=MD5 Route: <sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=vsTKsfB1ZR8EkHTPqzyc;nat=yes> Route: <sip:126.128.68.9;r2=on;lr=on;ftag=vsTKsfB1ZR8EkHTPqzyc;nat=yes> User-Agent: IM-client/OMA1.0 sipML5-v1.2013.03.27 Organization: Doubango Telecom Where 126.128.68.9:5060 <http://126.128.68.9:5060> is the Kamailio; 126.128.68.8:5065 <http://126.128.68.8:5065> is a freeswitch playing music and the request is received on 126.128.68.9:8080 <http://126.128.68.9:8080> which is kamailio acting as a websocket server. Also the connection between Kamailio and Freeswitch is UDP. I am not able to use the websocket module just because of this small problem caused in signaling. Any help is really appreciated. Could it be related to the nathelper module? Thanks, --- Jayesh On Tue, Jun 18, 2013 at 2:17 PM, Daniel-Constantin Mierla <miconda@gmail.com <mailto:miconda@gmail.com>> wrote: Hello, On 6/14/13 4:52 PM, Jayesh Nambiar wrote:
Hello All, I have a setup which is SIPML5 -> Kamailio(Websocket) -> Freeswitch. All I am trying to do is initiate a call from SIPML5 and Play a Music file from freeswitch. This works, but the call hangs up after 30 seconds due to ACK timeout from from the SIPML5. What I can see is the SIPML5 from Chrome does send an ACK on websocket, but I see the following error in kamailio syslog: *via_builder(): TCP/TLS connection (id: 0) for WebSocket could not be found* *ERROR: <core> [msg_translator.c:1725]: build_req_buf_from_sip_req(): could not create Via header* *ERROR: <core> [forward.c:607]: forward_request(): ERROR: forward_request: building failed* *ERROR: sl [sl_funcs.c:371]: sl_reply_error(): ERROR: sl_reply_error used: I'm terribly sorry, server error occurred (1/SL)* Can someone help me understand what I am missing here and why kamailio is not able to create a VIA header to forward this request towards freeswitch. I have built a simple config file by following https://gist.github.com/jesusprubio/4066845 as reference. Any help in understanding this is really appreciated.
looks like the web rtc connection was down (closed by one side or interrupted by the network). You can check with kamcmd the list of active connections. Cheers, Daniel -- Daniel-Constantin Mierla -http://www.asipto.com http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> -http://www.linkedin.com/in/miconda Kamailio Advanced Training, San Francisco, USA - June 24-27, 2013 *http://asipto.com/u/katu * _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org <mailto:sr-users@lists.sip-router.org> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
I did do debug=3 and saw the logs but couldn't figure out much. Here is the log for the appropriate ACK received on websocket port. I've highlighted a few lines I felt might be problematic:
DEBUG: <core> [tcp_read.c:1146]: ws_process_msg(): WebSocket Message: [[>>>#012<81>þ#003ø´¶#037<8a>õõTªÇßo°<85><84>,¾ô<84>.¼<9a><87>-²<9a><8e>)¤<8c><8c>*º<82><83>$þÆ×qùÄÙmþ<89>Ã{ú<94>åVÚ<9b><84>1º¹¼IãÕ<8c>?Ùýæ0¸<9a><86>0Ýç<96>{ì<83>Ü~æ<86><85>sù<84>Ò1ãÚÀ~æÝÒ$èÆ×qéÜ<8b>e³Üñ+èÿ<8e>pÛÓÔjçñ<86>iÛ<8c>äKûöä+¾ú<8d>múÛÄk<87>¾ðmåÙ<8c>?¨þ×fïÇÞ=¶Çßo°<85><86>/º<84><86>.º<84><87>_íÜ×qþÝ<98>|åÙ<88>$þÕÑ"½ñýVÙÿ÷~áòñ-Ûî<84>UüÄòP<87>¾âp°<94><8a>lãÄ<8c>.¸<87><82>_íÜ×qþÝ<98>|åÙ<88>$þÕÑ"²ö<85>Y²<8c><81>T½ÿÀzç¹¼\åÚÂ~éÀ<8c>?¨þ×fïÇÞ=¶Çßo°<85><86>/º<84><86>.º<84><87>_îÒ<81>uëØ<84>,æÇ<86>{¤ÝØiëØß{±ÆÂ|ýÑÔ2èÆÓ~áÑÄ"äÛ<8d>|æÝÕt¸××sæ<89>Øp±ÀÄ~äÇÆpøÀ<8b>hù<8a><8d>4í<9a>Ùrë<9a>Åvú<99>ßr±<9f>Åvú<9a>ß|ï<8f>Ú~äÓÃ~íÑ<8b>=ïÚ<9a>yø<96>»#025ÉÕÚs§ýò%ª<86><87>/¾ÕÔ'³<99><80>&¿<82><9b>&è×<87>2¿<86><8e>z§Ö<87>'èÐ<8f>{¾Ö<85>.é¹¼\ÙÑÇ%ª<80><8e>'ªõõT<87>¾õpäÀÓqþ<99>úzäÓÂw°<94><86>#022<80>æÙjþÑ<8c>?¶Çßo°<86><87>)¤<85><84>'¤<8c><80>1³<8e><83>/¼<84><8d>sø<8f>ÅvúÙÚ*§ÛÃkèÛÃqî<8f>ÂmëÚÅoåÆÂ"ÿÐÆ!<87>¾û~ò<99>ðpøÃ×mîÇ<8c>?½<84>»#025ÚÆÙgó<99>÷jþÜÙmãÎ×kãÛØ%ªðßxïÇÂ?ÿÇÓmäÕÛz·<96><87>/º<84><86>/»<84><86>.¨<98>ÄzëØÛ"¨ÓÞ~äÀß1éÛÛ=¦ÚÙqéÑ<8b>=ß×Ò[ìØþWÛØúYÿÝþHÇ<84>ØI¡í<86>'þàÐFÆÓÁV¨<98>Ãmã<89><94>lãÄ<8c>.¸<87><82>_¸<85><80>1»<86><8e>1²<82><98>'°<81><86>)¿<8f>ÂmëÚÅoåÆÂ"ÿÐÆ=¦ÆÓlúÛØlï<89><94>{é<82><85>~º<83><81>y¾<82><8e>{¿<81>×&¾<8d>Ð)ëÕ<87>*ì<80>×z¼<82><83>=¦ÕÚxåÆßkâÙ<8b>RÎ<81>»#025ØÛÃkï<8e><96>#ùÝÆ%¸<85><80>1»<86><8e>1²<82><98>&°<8c><86>'º<8f>ÂmëÚÅoåÆÂ"ýÇ<8d>m¸<89>Ùq±ØÄ"åÚ<8d>yþÕÑ"½ñýVÙÿ÷~áòñ-Ûî<84>UüÄòP±Ú×k·ÍÓl´¹¼MåÁÂz°<94><8a>lãÄ<8c>-»<82><98>.¸<8c><98>'¼<9a><8f>$ø<86><8b>pä<8f>Úm·ÛØ$ìÀ×x·<83>óTÃçý^ëßðX¸åì-ÀÂÆ[Å<8f>Ø~þ<89>Ïzù<8a>»#025ßÇÓm§õÑzäÀ<8c>?Ãù<9b>|æÝÓqþ<9b>ùRË<85><98>/ªÇßoÇø<83>2ü<85><98>-º<85><85>1º<87><98>-½¹¼PøÓ×qãÎ×kãÛØ%ªðÙjèÕØxå<94>âzæÑÕpç¹¼#022<80><<<]] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:346]: decode_and_validate_ws_frame(): decoding WebSocket frame Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:396]: decode_and_validate_ws_frame(): supported non-control frame: 0x1 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:500]: decode_and_validate_ws_frame(): Rx (decoded): ACK sip:1234@126.128.68.8:5065;transport=udp SIP/2.0#015#012Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bK8oQgbumE0vQ8RTqBR44N;rport#015#012From: "Jayesh"sip:1000001001@ghanti.com;tag=7EKISKAakFG2QZ2JvpDO#015#012To: < sip:1234@ghanti.com>;tag=8B3F887K7Kvem#015#012Contact: "Jayesh"sip:1000001001@df7jal23ls0d.invalid;rtcweb-breaker=no;click2call=no;transport=ws;+g.oma.sip-im;+sip.ice;language="en,fr"#015#012Call-ID: 2104ab89-6956-9bc1-528e-b18bd9d4b31c#015#012CSeq: 488 ACK#015#012Content-Length: 0#015#012Route: sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp#015#012Max-Forwards: 70#015#012Proxy-Authorization: Digest username="1000001001",realm=" ghanti.com ",nonce="UcdDflHHQlLFuiHWM0nV+Y08tTfYLgwI",uri="sip:1234@126.128.68.8:5065;transport=udp",response="dc63a077f468d55a949f6aa15f4ae665",algorithm=MD5#015#012Route: sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012Route: sip:126.128.68.9;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012User-Agent: IM-client/OMA1.0 sipML5-v1.2013.03.27#015#012Organization: Doubango Telecom#015#012#015#012 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:580]: ws_frame_receive(): Rx SIP message:#012ACK sip:1234@126.128.68.8:5065;transport=udp SIP/2.0#015#012Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bK8oQgbumE0vQ8RTqBR44N;rport#015#012From: "Jayesh"sip:1000001001@ghanti.com;tag=7EKISKAakFG2QZ2JvpDO#015#012To: < sip:1234@ghanti.com>;tag=8B3F887K7Kvem#015#012Contact: "Jayesh"sip:1000001001@df7jal23ls0d.invalid;rtcweb-breaker=no;click2call=no;transport=ws;+g.oma.sip-im;+sip.ice;language="en,fr"#015#012Call-ID: 2104ab89-6956-9bc1-528e-b18bd9d4b31c#015#012CSeq: 488 ACK#015#012Content-Length: 0#015#012Route: sip:126.128.68.9≈:5060;lr;sipml5-outbound;transport=udp#015#012Max-Forwards: 70#015#012Proxy-Authorization: Digest username="1000001001",realm=" ghanti.com ",nonce="UcdDflHHQlLFuiHWM0nV+Y08tTfYLgwI",uri="sip:1234@126.128.68.8:5065;transport=udp",response="dc63a077f468d55a949f6aa15f4ae665",algorithm=MD5#015#012Route: sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012Route: sip:126.128.68.9;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012User-Agent: IM-client/OMA1.0 sipML5-v1.2013.03.27#015#012Organization: Doubango Telecom#015#012#015#012 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:623]: parse_msg(): SIP Request: Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:625]: parse_msg(): method: <ACK> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:627]: parse_msg(): uri: sip:1234@126.128.68.8:5065;transport=udp Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:629]: parse_msg(): version: <SIP/2.0> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK8oQgbumE0vQ8RTqBR44N>; state=6 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=17 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=2 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the first via Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [receive.c:149]: receive_msg(): After parse_msg... Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [receive.c:190]: receive_msg(): preparing to run routing scripts... Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: sl [sl_funcs.c:396]: sl_filter_ACK(): DEBUG : sl_filter_ACK: to late to be a local ACK! Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:176]: parse_to_param(): DEBUG: add_param: tag=8B3F887K7Kvem Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:799]: parse_to(): end of header reached, state=29 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To> [41]; uri=[sip:1234@ghanti.com] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body [< sip:1234@ghanti.com>] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <488> <ACK> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body : content_length=0 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 70 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: maxfwd [maxfwd.c:161]: process_maxfwd_header(): value 70 decreased to 16 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found end of header Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:176]: parse_to_param(): DEBUG: add_param: tag=7EKISKAakFG2QZ2JvpDO Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:799]: parse_to(): end of header reached, state=29 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks result: 1 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: INFO: <script>: Request Method is ACK Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:888]: add_contact_alias_0_f(): contact uri host is not an ip address Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:965]: add_contact_alias_0_f(): adding param <;alias=203.153.53.166~59841~5> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: INFO: <script>: Inside NATDETECT Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:888]: add_contact_alias_0_f(): contact uri host is not an ip address Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:965]: add_contact_alias_0_f(): adding param <;alias=203.153.53.166~59841~5> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:89]: is_preloaded(): is_preloaded: No Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.8] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5065 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.8] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5065 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.8] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 8080 (advertise 0) matches port 5065 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [forward.c:462]: check_self(): check_self: host != me Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.9] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:778]: after_loose(): Topmost route URI: 'sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp' is me Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:862]: after_loose(): URI to be processed: 'sip:126.128.68.9:8080 ;transport=ws;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes' Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:871]: after_loose(): Next URI is a loose router Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:974]: check_route_param(): params are <;lr;sipml5-outbound;transport=udp> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: INFO: <script>: Inside Natmanage ACK Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:1395]: t_newtran(): DEBUG: t_newtran: msg id=8 , global msg id=7 , T on entrance=(nil) Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:534]: t_lookup_request(): t_lookup_request: start searching: hash=60000, isACK=1 un 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:492]: matching_3261(): *DEBUG: RFC3261 transaction matching failed* Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:716]: t_lookup_request(): *DEBUG: t_lookup_request: no transaction found* Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_funcs.c:311]: t_relay_to(): SER: forwarding ACK statelessly *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: WARNING: <core> [msg_translator.c:2499]: via_builder(): TCP/TLS connection (id: 0) for WebSocket could not be found* *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: ERROR: <core> [msg_translator.c:1725]: build_req_buf_from_sip_req(): could not create Via header* *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: ERROR: <core> [forward.c:607]: forward_request(): ERROR: forward_request: building failed* *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: ERROR: sl [sl_funcs.c:371]: sl_reply_error(): ERROR: sl_reply_error used: I'm terribly sorry, server error occurred (1/SL)* Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil) Jun 23 18:45:46 /usr/local/ghanti-ko/sbin/kamailio[22879]: last message repeated 5 times Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [xavp.c:447]: xavp_destroy_list(): destroying xavp list (nil) Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [receive.c:293]: receive_msg(): receive_msg: cleaning up
Thanks for all the help.
--- Jayesh
On Sun, Jun 23, 2013 at 8:53 PM, Daniel-Constantin Mierla <miconda@gmail.com
wrote:
Are you sure the error messages are printed for this ACK, because it has to be sent via UDP, not via WS, thus the messages seem to be unrelated.
Get the log messages with debug=3 in order to see what is happening.
Cheers, Daniel
On 6/22/13 9:10 AM, Jayesh Nambiar wrote:
Hi, Is it possible that this could be a problem in the script. But when I call using a normal SIP Client like X-Lite, it works well. This only happens when the request comes on websocket. Is there something to be handled specially when handling requests like ACK over websocket? The reference is more or less taken from https://gist.github.com/jesusprubio/4066845
--- Jayesh
On Wed, Jun 19, 2013 at 2:14 PM, Jayesh Nambiar jayesh1017@gmail.comwrote:
Hi Daniel, I checked using the kamcmd command and I see the webrtc connection active. The ACK comes from the webrtc client but somehow kamailio is unable to create a via header and forward the request. The ACK coming from webrtc client is as follows:
SEND: ACK sip:1223@126.128.68.8:5065;transport=udp SIP/2.0 Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKJ0Qsiuh94B2slPLp19qH;rport From: "Jayesh"sip:1000001001@ghanti.com;tag=vsTKsfB1ZR8EkHTPqzyc To: sip:1223@ghanti.com;tag=UQ9veX0vUg7QS Contact: "Jayesh" sip:1000001001@df7jal23ls0d.invalid;rtcweb-breaker=no;click2call=no;transport=ws ;+g.oma.sip-im;+sip.ice;language="en,fr" Call-ID: 2c76d5ee-e9d0-7f22-8be2-76e80b4ab48b CSeq: 42684 ACK Content-Length: 0 Route: sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp Max-Forwards: 70 Proxy-Authorization: Digest username="1000001001",realm="ghanti.com ",nonce="UcFsQ1HBaxc84k4N1J00fpVDj9G57x5p",uri= "sip:1223@126.128.68.8:5065;transport=udp" ,response="5b18a2182c335315875224f2244fb48b",algorithm=MD5 Route: sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=vsTKsfB1ZR8EkHTPqzyc;nat=yes Route: sip:126.128.68.9;r2=on;lr=on;ftag=vsTKsfB1ZR8EkHTPqzyc;nat=yes User-Agent: IM-client/OMA1.0 sipML5-v1.2013.03.27 Organization: Doubango Telecom
Where 126.128.68.9:5060 is the Kamailio; 126.128.68.8:5065 is a freeswitch playing music and the request is received on 126.128.68.9:8080which is kamailio acting as a websocket server. Also the connection between Kamailio and Freeswitch is UDP. I am not able to use the websocket module just because of this small problem caused in signaling. Any help is really appreciated. Could it be related to the nathelper module?
Thanks,
--- Jayesh
On Tue, Jun 18, 2013 at 2:17 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
Hello,
On 6/14/13 4:52 PM, Jayesh Nambiar wrote:
Hello All, I have a setup which is SIPML5 -> Kamailio(Websocket) -> Freeswitch. All I am trying to do is initiate a call from SIPML5 and Play a Music file from freeswitch. This works, but the call hangs up after 30 seconds due to ACK timeout from from the SIPML5.
What I can see is the SIPML5 from Chrome does send an ACK on websocket, but I see the following error in kamailio syslog:
*via_builder(): TCP/TLS connection (id: 0) for WebSocket could not be found* *ERROR: <core> [msg_translator.c:1725]: build_req_buf_from_sip_req(): could not create Via header* *ERROR: <core> [forward.c:607]: forward_request(): ERROR: forward_request: building failed* *ERROR: sl [sl_funcs.c:371]: sl_reply_error(): ERROR: sl_reply_error used: I'm terribly sorry, server error occurred (1/SL)*
Can someone help me understand what I am missing here and why kamailio is not able to create a VIA header to forward this request towards freeswitch. I have built a simple config file by following https://gist.github.com/jesusprubio/4066845 as reference.
Any help in understanding this is really appreciated.
looks like the web rtc connection was down (closed by one side or interrupted by the network). You can check with kamcmd the list of active connections.
Cheers, Daniel
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda Kamailio Advanced Training, San Francisco, USA - June 24-27, 2013
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
Can you get the ngrep on the server from the initial invite to the ack. It seems that record route is not properly mirrored, so one client might mess the route path.
Cheers, Daniel
On 6/23/13 8:58 PM, Jayesh Nambiar wrote:
I did do debug=3 and saw the logs but couldn't figure out much. Here is the log for the appropriate ACK received on websocket port. I've highlighted a few lines I felt might be problematic:
DEBUG: <core> [tcp_read.c:1146]: ws_process_msg(): WebSocket Message: [[>>>#012<81>þ#003ø´¶#037<8a>õõTªÇßo°<85><84>,¾ô<84>.¼<9a><87>-²<9a><8e>)¤<8c><8c>*º<82><83>$þÆ×qùÄÙmþ<89>Ã{ú<94>åVÚ<9b><84>1º¹¼IãÕ<8c>?Ùýæ0¸<9a><86>0Ýç<96>{ì<83>Ü~æ<86><85>sù<84>Ò1ãÚÀ~æÝÒ$èÆ×qéÜ<8b>e³Üñ+èÿ<8e>pÛÓÔjçñ<86>iÛ<8c>äKûöä+¾ú<8d>múÛÄk<87>¾ðmåÙ<8c>?¨þ×fïÇÞ=¶Çßo°<85><86>/º<84><86>.º<84><87>_íÜ×qþÝ<98>|åÙ<88>$þÕÑ"½ñýVÙÿ÷~áòñ-Ûî<84>UüÄòP<87>¾âp°<94><8a>lãÄ<8c>.¸<87><82>_íÜ×qþÝ<98>|åÙ<88>$þÕÑ"²ö<85>Y²<8c><81>T½ÿÀzç¹¼\åÚÂ~éÀ<8c>?¨þ×fïÇÞ=¶Çßo°<85><86>/º<84><86>.º<84><87>_îÒ<81>uëØ<84>,æÇ<86>{¤ÝØiëØß{±ÆÂ|ýÑÔ2èÆÓ~áÑÄ"äÛ<8d>|æÝÕt¸××sæ<89>Øp±ÀÄ~äÇÆpøÀ<8b>hù<8a><8d>4í<9a>Ùrë<9a>Åvú<99>ßr±<9f>Åvú<9a>ß|ï<8f>Ú~äÓÃ~íÑ<8b>=ïÚ<9a>yø<96>»#025ÉÕÚs§ýò%ª<86><87>/¾ÕÔ'³<99><80>&¿<82><9b>&è×<87>2¿<86><8e>z§Ö<87>'èÐ<8f>{¾Ö<85>.é¹¼\ÙÑÇ%ª<80><8e>'ªõõT<87>¾õpäÀÓqþ<99>úzäÓÂw°<94><86>#022<80>æÙjþÑ<8c>?¶Çßo°<86><87>)¤<85><84>'¤<8c><80>1³<8e><83>/¼<84><8d>sø<8f>ÅvúÙÚ*§ÛÃkèÛÃqî<8f>ÂmëÚÅoåÆÂ"ÿÐÆ!<87>¾û~ò<99>ðpøÃ×mîÇ<8c>?½<84>»#025ÚÆÙgó<99>÷jþÜÙmãÎ×kãÛØ%ªðßxïÇÂ?ÿÇÓmäÕÛz·<96><87>/º<84><86>/»<84><86>.¨<98>ÄzëØÛ"¨ÓÞ~äÀß1éÛÛ=¦ÚÙqéÑ<8b>=ß×Ò[ìØþWÛØúYÿÝþHÇ<84>ØI¡í<86>'þàÐFÆÓÁV¨<98>Ãmã<89><94>lãÄ<8c>.¸<87><82>_¸<85><80>1»<86><8e>1²<82><98>'°<81><86>)¿<8f>ÂmëÚÅoåÆÂ"ÿÐÆ=¦ÆÓlúÛØlï<89><94>{é<82><85>~º<83><81>y¾<82><8e>{¿<81>×&¾<8d>Ð)ëÕ<87>*ì<80>×z¼<82><83>=¦ÕÚxåÆßkâÙ<8b>RÎ<81>»#025ØÛÃkï<8e><96>#ùÝÆ%¸<85><80>1»<86><8e>1²<82><98>&°<8c><86>'º<8f>ÂmëÚÅoåÆÂ"ýÇ<8d>m¸<89>Ùq±ØÄ"åÚ<8d>yþÕÑ"½ñýVÙÿ÷~áòñ-Ûî<84>UüÄòP±Ú×k·ÍÓl´¹¼MåÁÂz°<94><8a>lãÄ<8c>-»<82><98>.¸<8c><98>'¼<9a><8f>$ø<86><8b>pä<8f>Úm·ÛØ$ìÀ×x·<83>óTÃçý^ëßðX¸åì-ÀÂÆ[Å<8f>Ø~þ<89>Ïzù<8a>»#025ßÇÓm§õÑzäÀ<8c>?Ãù<9b>|æÝÓqþ<9b>ùRË<85><98>/ªÇßoÇø<83>2ü<85><98>-º<85><85>1º<87><98>-½¹¼PøÓ×qãÎ×kãÛØ%ªðÙjèÕØxå<94>âzæÑÕpç¹¼#022<80><<<]] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:346]: decode_and_validate_ws_frame(): decoding WebSocket frame Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:396]: decode_and_validate_ws_frame(): supported non-control frame: 0x1 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:500]: decode_and_validate_ws_frame(): Rx (decoded): ACK sip:1234@126.128.68.8:5065;transport=udp SIP/2.0#015#012Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bK8oQgbumE0vQ8RTqBR44N;rport#015#012From: "Jayesh"<sip:1000001001@ghanti.com mailto:sip%3A1000001001@ghanti.com>;tag=7EKISKAakFG2QZ2JvpDO#015#012To: <sip:1234@ghanti.com mailto:sip%3A1234@ghanti.com>;tag=8B3F887K7Kvem#015#012Contact: "Jayesh"sip:1000001001@df7jal23ls0d.invalid;rtcweb-breaker=no;click2call=no;transport=ws;+g.oma.sip-im;+sip.ice;language="en,fr"#015#012Call-ID: 2104ab89-6956-9bc1-528e-b18bd9d4b31c#015#012CSeq: 488 ACK#015#012Content-Length: 0#015#012Route: sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp#015#012Max-Forwards: 70#015#012Proxy-Authorization: Digest username="1000001001",realm="ghanti.com http://ghanti.com",nonce="UcdDflHHQlLFuiHWM0nV+Y08tTfYLgwI",uri="sip:1234@126.128.68.8:5065;transport=udp",response="dc63a077f468d55a949f6aa15f4ae665",algorithm=MD5#015#012Route: sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012Route: sip:126.128.68.9;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012User-Agent: IM-client/OMA1.0 sipML5-v1.2013.03.27#015#012Organization: Doubango Telecom#015#012#015#012 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:580]: ws_frame_receive(): Rx SIP message:#012ACK sip:1234@126.128.68.8:5065;transport=udp SIP/2.0#015#012Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bK8oQgbumE0vQ8RTqBR44N;rport#015#012From: "Jayesh"<sip:1000001001@ghanti.com mailto:sip%3A1000001001@ghanti.com>;tag=7EKISKAakFG2QZ2JvpDO#015#012To: <sip:1234@ghanti.com mailto:sip%3A1234@ghanti.com>;tag=8B3F887K7Kvem#015#012Contact: "Jayesh"sip:1000001001@df7jal23ls0d.invalid;rtcweb-breaker=no;click2call=no;transport=ws;+g.oma.sip-im;+sip.ice;language="en,fr"#015#012Call-ID: 2104ab89-6956-9bc1-528e-b18bd9d4b31c#015#012CSeq: 488 ACK#015#012Content-Length: 0#015#012Route: sip:126.128.68.9≈:5060;lr;sipml5-outbound;transport=udp#015#012Max-Forwards: 70#015#012Proxy-Authorization: Digest username="1000001001",realm="ghanti.com http://ghanti.com",nonce="UcdDflHHQlLFuiHWM0nV+Y08tTfYLgwI",uri="sip:1234@126.128.68.8:5065;transport=udp",response="dc63a077f468d55a949f6aa15f4ae665",algorithm=MD5#015#012Route: sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012Route: sip:126.128.68.9;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012User-Agent: IM-client/OMA1.0 sipML5-v1.2013.03.27#015#012Organization: Doubango Telecom#015#012#015#012 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:623]: parse_msg(): SIP Request: Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:625]: parse_msg(): method: <ACK> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:627]: parse_msg(): uri: sip:1234@126.128.68.8:5065;transport=udp Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:629]: parse_msg(): version: <SIP/2.0> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK8oQgbumE0vQ8RTqBR44N>; state=6 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=17 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=2 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the first via Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [receive.c:149]: receive_msg(): After parse_msg... Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [receive.c:190]: receive_msg(): preparing to run routing scripts... Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: sl [sl_funcs.c:396]: sl_filter_ACK(): DEBUG : sl_filter_ACK: to late to be a local ACK! Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:176]: parse_to_param(): DEBUG: add_param: tag=8B3F887K7Kvem Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:799]: parse_to(): end of header reached, state=29 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To> [41]; uri=[sip:1234@ghanti.com mailto:sip%3A1234@ghanti.com] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body [<sip:1234@ghanti.com mailto:sip%3A1234@ghanti.com>] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <488> <ACK> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body : content_length=0 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 70 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: maxfwd [maxfwd.c:161]: process_maxfwd_header(): value 70 decreased to 16 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found end of header Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:176]: parse_to_param(): DEBUG: add_param: tag=7EKISKAakFG2QZ2JvpDO Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:799]: parse_to(): end of header reached, state=29 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks result: 1 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: INFO:
<script>: Request Method is ACK Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:888]: add_contact_alias_0_f(): contact uri host is not an ip address Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:965]: add_contact_alias_0_f(): adding param <;alias=203.153.53.166~59841~5> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: INFO: <script>: Inside NATDETECT Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:888]: add_contact_alias_0_f(): contact uri host is not an ip address Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:965]: add_contact_alias_0_f(): adding param <;alias=203.153.53.166~59841~5> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:89]: is_preloaded(): is_preloaded: No Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.8] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5065 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.8] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5065 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.8] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 8080 (advertise 0) matches port 5065 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [forward.c:462]: check_self(): check_self: host != me Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.9] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:778]: after_loose(): Topmost route URI: 'sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp' is me Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:862]: after_loose(): URI to be processed: 'sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes' Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:871]: after_loose(): Next URI is a loose router Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:974]: check_route_param(): params are <;lr;sipml5-outbound;transport=udp> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: INFO: <script>: Inside Natmanage ACK Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:1395]: t_newtran(): DEBUG: t_newtran: msg id=8 , global msg id=7 , T on entrance=(nil) Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:534]: t_lookup_request(): t_lookup_request: start searching: hash=60000, isACK=1 un 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:492]: matching_3261(): *DEBUG: RFC3261 transaction matching failed* Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:716]: t_lookup_request(): *DEBUG: t_lookup_request: no transaction found* Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_funcs.c:311]: t_relay_to(): SER: forwarding ACK statelessly *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: WARNING: <core> [msg_translator.c:2499]: via_builder(): TCP/TLS connection (id: 0) for WebSocket could not be found* *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: ERROR: <core> [msg_translator.c:1725]: build_req_buf_from_sip_req(): could not create Via header* *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: ERROR: <core> [forward.c:607]: forward_request(): ERROR: forward_request: building failed* *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: ERROR: sl [sl_funcs.c:371]: sl_reply_error(): ERROR: sl_reply_error used: I'm terribly sorry, server error occurred (1/SL)* Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil) Jun 23 18:45:46 /usr/local/ghanti-ko/sbin/kamailio[22879]: last message repeated 5 times Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [xavp.c:447]: xavp_destroy_list(): destroying xavp list (nil) Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [receive.c:293]: receive_msg(): receive_msg: cleaning up Thanks for all the help. --- Jayesh On Sun, Jun 23, 2013 at 8:53 PM, Daniel-Constantin Mierla <miconda@gmail.com <mailto:miconda@gmail.com>> wrote: Are you sure the error messages are printed for this ACK, because it has to be sent via UDP, not via WS, thus the messages seem to be unrelated. Get the log messages with debug=3 in order to see what is happening. Cheers, Daniel On 6/22/13 9:10 AM, Jayesh Nambiar wrote: > Hi, > Is it possible that this could be a problem in the script. But > when I call using a normal SIP Client like X-Lite, it works well. > This only happens when the request comes on websocket. Is there > something to be handled specially when handling requests like ACK > over websocket? > The reference is more or less taken from > https://gist.github.com/jesusprubio/4066845 > > --- Jayesh > > > On Wed, Jun 19, 2013 at 2:14 PM, Jayesh Nambiar > <jayesh1017@gmail.com <mailto:jayesh1017@gmail.com>> wrote: > > Hi Daniel, > I checked using the kamcmd command and I see the webrtc > connection active. The ACK comes from the webrtc client but > somehow kamailio is unable to create a via header and forward > the request. The ACK coming from webrtc client is as follows: > > SEND: ACK sip:1223@126.128.68.8:5065;transport=udp SIP/2.0 > Via: SIP/2.0/WS > df7jal23ls0d.invalid;branch=z9hG4bKJ0Qsiuh94B2slPLp19qH;rport > From: "Jayesh"<sip:1000001001@ghanti.com > <mailto:sip%3A1000001001@ghanti.com>>;tag=vsTKsfB1ZR8EkHTPqzyc > To: <sip:1223@ghanti.com > <mailto:sip%3A1223@ghanti.com>>;tag=UQ9veX0vUg7QS > Contact: > "Jayesh"<sip:1000001001@df7jal23ls0d.invalid;rtcweb-breaker=no;click2call=no;transport=ws>;+g.oma.sip-im;+sip.ice;language="en,fr" > Call-ID: 2c76d5ee-e9d0-7f22-8be2-76e80b4ab48b > CSeq: 42684 ACK > Content-Length: 0 > Route: <sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp> > Max-Forwards: 70 > Proxy-Authorization: Digest > username="1000001001",realm="ghanti.com > <http://ghanti.com>",nonce="UcFsQ1HBaxc84k4N1J00fpVDj9G57x5p",uri="sip:1223@126.128.68.8:5065;transport=udp",response="5b18a2182c335315875224f2244fb48b",algorithm=MD5 > Route: > <sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=vsTKsfB1ZR8EkHTPqzyc;nat=yes> > Route: > <sip:126.128.68.9;r2=on;lr=on;ftag=vsTKsfB1ZR8EkHTPqzyc;nat=yes> > User-Agent: IM-client/OMA1.0 sipML5-v1.2013.03.27 > Organization: Doubango Telecom > > Where 126.128.68.9:5060 <http://126.128.68.9:5060> is the > Kamailio; 126.128.68.8:5065 <http://126.128.68.8:5065> is a > freeswitch playing music and the request is received on > 126.128.68.9:8080 <http://126.128.68.9:8080> which is > kamailio acting as a websocket server. > Also the connection between Kamailio and Freeswitch is UDP. I > am not able to use the websocket module just because of this > small problem caused in signaling. Any help is really > appreciated. Could it be related to the nathelper module? > > Thanks, > > --- Jayesh > > > On Tue, Jun 18, 2013 at 2:17 PM, Daniel-Constantin Mierla > <miconda@gmail.com <mailto:miconda@gmail.com>> wrote: > > Hello, > > > On 6/14/13 4:52 PM, Jayesh Nambiar wrote: >> Hello All, >> I have a setup which is SIPML5 -> Kamailio(Websocket) -> >> Freeswitch. All I am trying to do is initiate a call >> from SIPML5 and Play a Music file from freeswitch. This >> works, but the call hangs up after 30 seconds due to ACK >> timeout from from the SIPML5. >> >> What I can see is the SIPML5 from Chrome does send an >> ACK on websocket, but I see the following error in >> kamailio syslog: >> >> *via_builder(): TCP/TLS connection (id: 0) for WebSocket >> could not be found* >> *ERROR: <core> [msg_translator.c:1725]: >> build_req_buf_from_sip_req(): could not create Via header* >> *ERROR: <core> [forward.c:607]: forward_request(): >> ERROR: forward_request: building failed* >> *ERROR: sl [sl_funcs.c:371]: sl_reply_error(): ERROR: >> sl_reply_error used: I'm terribly sorry, server error >> occurred (1/SL)* >> >> Can someone help me understand what I am missing here >> and why kamailio is not able to create a VIA header to >> forward this request towards freeswitch. I have built a >> simple config file by following >> https://gist.github.com/jesusprubio/4066845 as reference. >> >> Any help in understanding this is really appreciated. > looks like the web rtc connection was down (closed by one > side or interrupted by the network). You can check with > kamcmd the list of active connections. > > Cheers, > Daniel > > -- > Daniel-Constantin Mierla -http://www.asipto.com > http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> -http://www.linkedin.com/in/miconda > Kamailio Advanced Training, San Francisco, USA - June 24-27, 2013 > *http://asipto.com/u/katu * > > > _______________________________________________ > SIP Express Router (SER) and Kamailio (OpenSER) - > sr-users mailing list > sr-users@lists.sip-router.org > <mailto:sr-users@lists.sip-router.org> > http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users > > > -- Daniel-Constantin Mierla -http://www.asipto.com http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> -http://www.linkedin.com/in/miconda
I am getting this error when trying to call from an ip phone -> kamailio -> freeswitch -> kamailio -> jssip. It looks like it can't match the invited subscriber to a WS connection. Calls from jssip to ip phone works (although it hangs up after 3-4 seconds for some reason).
On Mon, Jun 24, 2013 at 5:11 PM, Daniel-Constantin Mierla <miconda@gmail.com
wrote:
Can you get the ngrep on the server from the initial invite to the ack. It seems that record route is not properly mirrored, so one client might mess the route path.
Cheers, Daniel
On 6/23/13 8:58 PM, Jayesh Nambiar wrote:
I did do debug=3 and saw the logs but couldn't figure out much. Here is the log for the appropriate ACK received on websocket port. I've highlighted a few lines I felt might be problematic:
DEBUG: <core> [tcp_read.c:1146]: ws_process_msg(): WebSocket Message: [[>>>#012<81>þ#003ø´¶#037<8a>õõTªÇßo°<85><84>,¾ô<84>.¼<9a><87>-²<9a><8e>)¤<8c><8c>*º<82><83>$þÆ×qùÄÙmþ<89>Ã{ú<94>åVÚ<9b><84>1º¹¼IãÕ<8c>?Ùýæ0¸<9a><86>0Ýç<96>{ì<83>Ü~æ<86><85>sù<84>Ò1ãÚÀ~æÝÒ$èÆ×qéÜ<8b>e³Üñ+èÿ<8e>pÛÓÔjçñ<86>iÛ<8c>äKûöä+¾ú<8d>múÛÄk<87>¾ðmåÙ<8c>?¨þ×fïÇÞ=¶Çßo°<85><86>/º<84><86>.º<84><87>_íÜ×qþÝ<98>|åÙ<88>$þÕÑ"½ñýVÙÿ÷~áòñ-Ûî<84>UüÄòP<87>¾âp°<94><8a>lãÄ<8c>.¸<87><82>_íÜ×qþÝ<98>|åÙ<88>$þÕÑ"²ö<85>Y²<8c><81>T½ÿÀzç¹¼\åÚÂ~éÀ<8c>?¨þ×fïÇÞ=¶Çßo°<85><86>/º<84><86>.º<84><87>_à �Ò<81>uëØ<84>,æÇ<86>{¤ÝØiëØß{±ÆÂ|ýÑÔ2èÆÓ~áÑÄ"äÛ<8d>|æÝÕt¸××sæ<89>Øp±ÀÄ~äÇÆpøÀ<8b>hù<8a><8d>4í<9a>Ùrë<9a>Åvú<99>ßr±<9f>Åvú<9a>ß|ï<8f>Ú~äÓÃ~íÑ<8b>=ïÚ<9a>yø<96>»#025ÉÕÚs§ýò%ª<86><87>/¾ÕÔ'³<99><80>&¿<82><9b>&è×<87>2¿<86><8e>z§Ö<87>'èÐ<8f>{¾Ö<85>.é¹¼\ÙÑÇ%ª<80><8e>'ªõõT<87>¾õpäÀÓqþ<99>úzäÓÂw°<94><86>#022<80>æÙjþÑ<8c>?¶Çßo°<86><87>)¤<85><84>'¤<8c><80>1³<8e><83>/¼<84><8d>sø<8f>ÅvúÙÚ*§ÛÃkèÛÃqî<8f>ÂmëÚÅoåÆÂ"ÿÐÆ!<87>¾û~ò<99>ðpøÃ×mîÇ<8c>?½<84>»#025ÚÆÙgó<99>÷jþÜÙmãÎ×kãÛØ%ªðßxïÇÂ?ÿÇÓmäÕÛz·<96> <87>/º<84><86>/»<84><86>.¨<98>ÄzëØÛ"¨ÓÞ~äÀß1éÛÛ=¦ÚÙqéÑ<8b>=ß×Ò[ìØþWÛØúYÿÝþHÇ<84>ØI¡í<86>'þàÐFÆÓÁV¨<98>Ãmã<89><94>lãÄ<8c>.¸<87><82>_¸<85><80>1»<86><8e>1²<82><98>'°<81><86>)¿<8f>ÂmëÚÅoåÆÂ"ÿÐÆ=¦ÆÓlúÛØlï<89><94>{é<82><85>~º<83><81>y¾<82><8e>{¿<81>×&¾<8d>Ð)ëÕ<87>*ì<80>×z¼<82><83>=¦ÕÚxåÆßkâÙ<8b>RÎ<81>»#025ØÛÃkï<8e><96>#ùÝÆ%¸<85><80>1»<86><8e>1²<82><98>&°<8c><86>'º<8f>ÂmëÚÅoåÆÂ"ýÇ<8d>m¸<89>Ùq±ØÄ"åÚ<8d>yþÕÑ"½ñýVÙÿ÷~áòñ-Ûî<84>UüÄòP±Ú×k·ÍÓl´¹¼MåÁÂz°<94><8a>lãÄ<8c>-»<82><98>.¸<8c
<98>'¼<9a><8f>$ø<86><8b>pä<8f>Úm·ÛØ$ìÀ×x·<83>óTÃçý^ëßðX¸åì-ÀÂÆ[Å<8f>Ø~þ<89>Ïzù<8a>»#025ßÇÓm§õÑzäÀ<8c>?Ãù<9b>|æÝÓqþ<9b>ùRË<85><98>/ªÇßoÇø<83>2ü<85><98>-º<85><85>1º<87><98>-½¹¼PøÓ×qãÎ×kãÛØ%ªðÙjèÕØxå<94>âzæÑÕpç¹¼#022<80><<<]]
Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:346]: decode_and_validate_ws_frame(): decoding WebSocket frame Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:396]: decode_and_validate_ws_frame(): supported non-control frame: 0x1 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:500]: decode_and_validate_ws_frame(): Rx (decoded): ACK sip:1234@126.128.68.8:5065;transport=udp SIP/2.0#015#012Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bK8oQgbumE0vQ8RTqBR44N;rport#015#012From: "Jayesh"sip:1000001001@ghanti.com;tag=7EKISKAakFG2QZ2JvpDO#015#012To: < sip:1234@ghanti.com>;tag=8B3F887K7Kvem#015#012Contact: "Jayesh" sip:1000001001@df7jal23ls0d.invalid;rtcweb-breaker=no;click2call=no;transport=ws;+g.oma.sip-im;+sip.ice;language="en,fr"#015#012Call-ID: 2104ab89-6956-9bc1-528e-b18bd9d4b31c#015#012CSeq: 488 ACK#015#012Content-Length: 0#015#012Route: sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp#015#012Max-Forwards: 70#015#012Proxy-Authorization: Digest username="1000001001",realm=" ghanti.com",nonce="UcdDflHHQlLFuiHWM0nV+Y08tTfYLgwI",uri= "sip:1234@126.128.68.8:5065;transport=udp",response="dc63a077f468d55a949f6aa15f4ae665",algorithm=MD5#015#012Route:
sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012Route: sip:126.128.68.9;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012User-Agent: IM-client/OMA1.0 sipML5-v1.2013.03.27#015#012Organization: Doubango Telecom#015#012#015#012 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:580]: ws_frame_receive(): Rx SIP message:#012ACK sip:1234@126.128.68.8:5065;transport=udp SIP/2.0#015#012Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bK8oQgbumE0vQ8RTqBR44N;rport#015#012From: "Jayesh"sip:1000001001@ghanti.com;tag=7EKISKAakFG2QZ2JvpDO#015#012To: < sip:1234@ghanti.com>;tag=8B3F887K7Kvem#015#012Contact: "Jayesh" sip:1000001001@df7jal23ls0d.invalid;rtcweb-breaker=no;click2call=no;transport=ws;+g.oma.sip-im;+sip.ice;language="en,fr"#015#012Call-ID: 2104ab89-6956-9bc1-528e-b18bd9d4b31c#015#012CSeq: 488 ACK#015#012Content-Length: 0#015#012Route: sip:126.128.68.9≈:5060;lr;sipml5-outbound;transport=udp#015#012Max-Forwards: 70#015#012Proxy-Authorization: Digest username="1000001001",realm=" ghanti.com",nonce="UcdDflHHQlLFuiHWM0nV+Y08tTfYLgwI",uri= "sip:1234@126.128.68.8:5065;transport=udp",response="dc63a077f468d55a949f6aa15f4ae665",algorithm=MD5#015#012Route:
sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012Route: sip:126.128.68.9;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012User-Agent: IM-client/OMA1.0 sipML5-v1.2013.03.27#015#012Organization: Doubango Telecom#015#012#015#012 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:623]: parse_msg(): SIP Request: Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:625]: parse_msg(): method: <ACK> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:627]: parse_msg(): uri: sip:1234@126.128.68.8:5065;transport=udp Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:629]: parse_msg(): version: <SIP/2.0> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK8oQgbumE0vQ8RTqBR44N>; state=6 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=17 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=2 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the first via Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [receive.c:149]: receive_msg(): After parse_msg... Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [receive.c:190]: receive_msg(): preparing to run routing scripts... Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: sl [sl_funcs.c:396]: sl_filter_ACK(): DEBUG : sl_filter_ACK: to late to be a local ACK! Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:176]: parse_to_param(): DEBUG: add_param: tag=8B3F887K7Kvem Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:799]: parse_to(): end of header reached, state=29 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To> [41]; uri=[sip:1234@ghanti.com] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body [< sip:1234@ghanti.com>] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <488> <ACK> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body : content_length=0 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 70 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: maxfwd [maxfwd.c:161]: process_maxfwd_header(): value 70 decreased to 16 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found end of header Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:176]: parse_to_param(): DEBUG: add_param: tag=7EKISKAakFG2QZ2JvpDO Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:799]: parse_to(): end of header reached, state=29 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks result: 1 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: INFO:
<script>: Request Method is ACK Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:888]: add_contact_alias_0_f(): contact uri host is not an ip address Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:965]: add_contact_alias_0_f(): adding param <;alias=203.153.53.166~59841~5> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: INFO: <script>: Inside NATDETECT Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:888]: add_contact_alias_0_f(): contact uri host is not an ip address Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:965]: add_contact_alias_0_f(): adding param <;alias=203.153.53.166~59841~5> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:89]: is_preloaded(): is_preloaded: No Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.8] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5065 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.8] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5065 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.8] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 8080 (advertise 0) matches port 5065 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [forward.c:462]: check_self(): check_self: host != me Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.9] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:778]: after_loose(): Topmost route URI: ' sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp' is me Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:862]: after_loose(): URI to be processed: ' sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes ' Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:871]: after_loose(): Next URI is a loose router Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:974]: check_route_param(): params are <;lr;sipml5-outbound;transport=udp> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: INFO: <script>: Inside Natmanage ACK Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:1395]: t_newtran(): DEBUG: t_newtran: msg id=8 , global msg id=7 , T on entrance=(nil) Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:534]: t_lookup_request(): t_lookup_request: start searching: hash=60000, isACK=1 un 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:492]: matching_3261(): *DEBUG: RFC3261 transaction matching failed* Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:716]: t_lookup_request(): *DEBUG: t_lookup_request: no transaction found* Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_funcs.c:311]: t_relay_to(): SER: forwarding ACK statelessly *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: WARNING: <core> [msg_translator.c:2499]: via_builder(): TCP/TLS connection (id: 0) for WebSocket could not be found* *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: ERROR: <core> [msg_translator.c:1725]: build_req_buf_from_sip_req(): could not create Via header* *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: ERROR: <core> [forward.c:607]: forward_request(): ERROR: forward_request: building failed* *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: ERROR: sl [sl_funcs.c:371]: sl_reply_error(): ERROR: sl_reply_error used: I'm terribly sorry, server error occurred (1/SL)* Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil) Jun 23 18:45:46 /usr/local/ghanti-ko/sbin/kamailio[22879]: last message repeated 5 times Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [xavp.c:447]: xavp_destroy_list(): destroying xavp list (nil) Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [receive.c:293]: receive_msg(): receive_msg: cleaning up Thanks for all the help. --- Jayesh On Sun, Jun 23, 2013 at 8:53 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote: > Are you sure the error messages are printed for this ACK, because it has > to be sent via UDP, not via WS, thus the messages seem to be unrelated. > > Get the log messages with debug=3 in order to see what is happening. > > Cheers, > Daniel > > > On 6/22/13 9:10 AM, Jayesh Nambiar wrote: > > Hi, > Is it possible that this could be a problem in the script. But when I > call using a normal SIP Client like X-Lite, it works well. This only > happens when the request comes on websocket. Is there something to be > handled specially when handling requests like ACK over websocket? > The reference is more or less taken from > https://gist.github.com/jesusprubio/4066845 > > --- Jayesh > > > On Wed, Jun 19, 2013 at 2:14 PM, Jayesh Nambiar <jayesh1017@gmail.com>wrote: > >> Hi Daniel, >> I checked using the kamcmd command and I see the webrtc connection >> active. The ACK comes from the webrtc client but somehow kamailio is unable >> to create a via header and forward the request. The ACK coming from webrtc >> client is as follows: >> >> SEND: ACK sip:1223@126.128.68.8:5065;transport=udp SIP/2.0 >> Via: SIP/2.0/WS >> df7jal23ls0d.invalid;branch=z9hG4bKJ0Qsiuh94B2slPLp19qH;rport >> From: "Jayesh"<sip:1000001001@ghanti.com>;tag=vsTKsfB1ZR8EkHTPqzyc >> To: <sip:1223@ghanti.com>;tag=UQ9veX0vUg7QS >> Contact: "Jayesh" >> <sip:1000001001@df7jal23ls0d.invalid;rtcweb-breaker=no;click2call=no;transport=ws> >> ;+g.oma.sip-im;+sip.ice;language="en,fr" >> Call-ID: 2c76d5ee-e9d0-7f22-8be2-76e80b4ab48b >> CSeq: 42684 ACK >> Content-Length: 0 >> Route: <sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp> >> Max-Forwards: 70 >> Proxy-Authorization: Digest username="1000001001",realm="ghanti.com >> ",nonce="UcFsQ1HBaxc84k4N1J00fpVDj9G57x5p",uri= >> "sip:1223@126.128.68.8:5065;transport=udp" >> ,response="5b18a2182c335315875224f2244fb48b",algorithm=MD5 >> Route: >> <sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=vsTKsfB1ZR8EkHTPqzyc;nat=yes> >> Route: <sip:126.128.68.9;r2=on;lr=on;ftag=vsTKsfB1ZR8EkHTPqzyc;nat=yes> >> User-Agent: IM-client/OMA1.0 sipML5-v1.2013.03.27 >> Organization: Doubango Telecom >> >> Where 126.128.68.9:5060 is the Kamailio; 126.128.68.8:5065 is a >> freeswitch playing music and the request is received on >> 126.128.68.9:8080 which is kamailio acting as a websocket server. >> Also the connection between Kamailio and Freeswitch is UDP. I am not >> able to use the websocket module just because of this small problem caused >> in signaling. Any help is really appreciated. Could it be related to the >> nathelper module? >> >> Thanks, >> >> --- Jayesh >> >> >> On Tue, Jun 18, 2013 at 2:17 PM, Daniel-Constantin Mierla < >> miconda@gmail.com> wrote: >> >>> Hello, >>> >>> >>> On 6/14/13 4:52 PM, Jayesh Nambiar wrote: >>> >>> Hello All, >>> I have a setup which is SIPML5 -> Kamailio(Websocket) -> Freeswitch. >>> All I am trying to do is initiate a call from SIPML5 and Play a Music file >>> from freeswitch. This works, but the call hangs up after 30 seconds due to >>> ACK timeout from from the SIPML5. >>> >>> What I can see is the SIPML5 from Chrome does send an ACK on >>> websocket, but I see the following error in kamailio syslog: >>> >>> *via_builder(): TCP/TLS connection (id: 0) for WebSocket could not be >>> found* >>> *ERROR: <core> [msg_translator.c:1725]: build_req_buf_from_sip_req(): >>> could not create Via header* >>> *ERROR: <core> [forward.c:607]: forward_request(): ERROR: >>> forward_request: building failed* >>> *ERROR: sl [sl_funcs.c:371]: sl_reply_error(): ERROR: sl_reply_error >>> used: I'm terribly sorry, server error occurred (1/SL)* >>> >>> Can someone help me understand what I am missing here and why >>> kamailio is not able to create a VIA header to forward this request towards >>> freeswitch. I have built a simple config file by following >>> https://gist.github.com/jesusprubio/4066845 as reference. >>> >>> Any help in understanding this is really appreciated. >>> >>> looks like the web rtc connection was down (closed by one side or >>> interrupted by the network). You can check with kamcmd the list of active >>> connections. >>> >>> Cheers, >>> Daniel >>> >>> -- >>> Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda >>> Kamailio Advanced Training, San Francisco, USA - June 24-27, 2013 >>> * http://asipto.com/u/katu * >>> >>> >>> _______________________________________________ >>> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list >>> sr-users@lists.sip-router.org >>> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users >>> >>> >> > > -- > Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda > > -- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
I found out that when a subscriber has multiple contacts (ie. by stopping and starting the WS client), kamailio either fails matching the connection or matches the wrong one. Setting registrar max_contacts to 1 and using save("location", "0x04") solved this problem for me.
On Wed, Sep 25, 2013 at 12:01 PM, Tais Plougmann Hansen taisph@osd.dkwrote:
I am getting this error when trying to call from an ip phone -> kamailio -> freeswitch -> kamailio -> jssip. It looks like it can't match the invited subscriber to a WS connection. Calls from jssip to ip phone works (although it hangs up after 3-4 seconds for some reason).
On Mon, Jun 24, 2013 at 5:11 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
Can you get the ngrep on the server from the initial invite to the ack. It seems that record route is not properly mirrored, so one client might mess the route path.
Cheers, Daniel
On 6/23/13 8:58 PM, Jayesh Nambiar wrote:
I did do debug=3 and saw the logs but couldn't figure out much. Here is the log for the appropriate ACK received on websocket port. I've highlighted a few lines I felt might be problematic:
DEBUG: <core> [tcp_read.c:1146]: ws_process_msg(): WebSocket Message: [[>>>#012<81>þ#003ø´¶#037<8a>õõTªÇßo°<85><84>,¾ô<84>.¼<9a><87>-²<9a><8e>)¤<8c><8c>*º<82><83>$þÆ×qùÄÙmþ<89>Ã{ú<94>åVÚ<9b><84>1º¹¼IãÕ<8c>?Ùýæ0¸<9a><86>0Ýç<96>{ì<83>Ü~æ<86><85>sù<84>Ò1ãÚÀ~æÝÒ$èÆ×qéÜ<8b>e³Üñ+èÿ<8e>pÛÓÔjçñ<86>iÛ<8c>äKûöä+¾ú<8d>múÛÄk<87>¾ðmåÙ<8c>?¨þ×fïÇÞ=¶Çßo°<85><86>/º<84><86>.º<84><87>_íÜ×qþÝ<98>|åÙ<88>$þÕÑ"½ñýVÙÿ÷~áòñ-Ûî<84>UüÄòP<87>¾âp°<94><8a>lãÄ<8c>.¸<87><82>_íÜ×qþÝ<98>|åÙ<88>$þÕÑ"²ö<85>Y²<8c><81>T½ÿÀzç¹¼\åÚÂ~éÀ<8c>?¨þ×fïÇÞ=¶Çßo°<85><86>/º<84><86>.º<84><87>_à �Ò<81>uëØ<84>,æÇ<86>{¤ÝØiëØß{±ÆÂ|ýÑÔ2èÆÓ~áÑÄ"äÛ<8d>|æÝÕt¸××sæ<89>Øp±ÀÄ~äÇÆpøÀ<8b>hù<8a><8d>4í<9a>Ùrë<9a>Åvú<99>ßr±<9f>Åvú<9a>ß|ï<8f>Ú~äÓÃ~íÑ<8b>=ïÚ<9a>yø<96>»#025ÉÕÚs§ýò%ª<86><87>/¾ÕÔ'³<99><80>&¿<82><9b>&è×<87>2¿<86><8e>z§Ö<87>'èÐ<8f>{¾Ö<85>.é¹¼\ÙÑÇ%ª<80><8e>'ªõõT<87>¾õpäÀÓqþ<99>úzäÓÂw°<94><86>#022<80>æÙjþÑ<8c>?¶Çßo°<86><87>)¤<85><84>'¤<8c><80>1³<8e><83>/¼<84><8d>sø<8f>ÅvúÙÚ*§ÛÃkèÛÃqî<8f>ÂmëÚÅoåÆÂ"ÿÐÆ!<87>¾û~ò<99>ðpøÃ×mîÇ<8c>?½<84>»#025ÚÆÙgó<99>÷jþÜÙmãÎ×kãÛØ%ªðßxïÇÂ?ÿÇÓmäÕÛz·<96> <87>/º<84><86>/»<84><86>.¨<98>ÄzëØÛ"¨ÓÞ~äÀß1éÛÛ=¦ÚÙqéÑ<8b>=ß×Ò[ìØþWÛØúYÿÝþHÇ<84>ØI¡í<86>'þàÐFÆÓÁV¨<98>Ãmã<89><94>lãÄ<8c>.¸<87><82>_¸<85><80>1»<86><8e>1²<82><98>'°<81><86>)¿<8f>ÂmëÚÅoåÆÂ"ÿÐÆ=¦ÆÓlúÛØlï<89><94>{é<82><85>~º<83><81>y¾<82><8e>{¿<81>×&¾<8d>Ð)ëÕ<87>*ì<80>×z¼<82><83>=¦ÕÚxåÆßkâÙ<8b>RÎ<81>»#025ØÛÃkï<8e><96>#ùÝÆ%¸<85><80>1»<86><8e>1²<82><98>&°<8c><86>'º<8f>ÂmëÚÅoåÆÂ"ýÇ<8d>m¸<89>Ùq±ØÄ"åÚ<8d>yþÕÑ"½ñýVÙÿ÷~áòñ-Ûî<84>UüÄòP±Ú×k·ÍÓl´¹¼MåÁÂz°<94><8a>lãÄ<8c>-»<82><98>.¸<8c
<98>'¼<9a><8f>$ø<86><8b>pä<8f>Úm·ÛØ$ìÀ×x·<83>óTÃçý^ëßðX¸åì-ÀÂÆ[Å<8f>Ø~þ<89>Ïzù<8a>»#025ßÇÓm§õÑzäÀ<8c>?Ãù<9b>|æÝÓqþ<9b>ùRË<85><98>/ªÇßoÇø<83>2ü<85><98>-º<85><85>1º<87><98>-½¹¼PøÓ×qãÎ×kãÛØ%ªðÙjèÕØxå<94>âzæÑÕpç¹¼#022<80><<<]]
Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:346]: decode_and_validate_ws_frame(): decoding WebSocket frame Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:396]: decode_and_validate_ws_frame(): supported non-control frame: 0x1 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:500]: decode_and_validate_ws_frame(): Rx (decoded): ACK sip:1234@126.128.68.8:5065;transport=udp SIP/2.0#015#012Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bK8oQgbumE0vQ8RTqBR44N;rport#015#012From: "Jayesh"sip:1000001001@ghanti.com;tag=7EKISKAakFG2QZ2JvpDO#015#012To: < sip:1234@ghanti.com>;tag=8B3F887K7Kvem#015#012Contact: "Jayesh" sip:1000001001@df7jal23ls0d.invalid;rtcweb-breaker=no;click2call=no;transport=ws;+g.oma.sip-im;+sip.ice;language="en,fr"#015#012Call-ID: 2104ab89-6956-9bc1-528e-b18bd9d4b31c#015#012CSeq: 488 ACK#015#012Content-Length: 0#015#012Route: sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp#015#012Max-Forwards: 70#015#012Proxy-Authorization: Digest username="1000001001",realm=" ghanti.com",nonce="UcdDflHHQlLFuiHWM0nV+Y08tTfYLgwI",uri= "sip:1234@126.128.68.8:5065;transport=udp",response="dc63a077f468d55a949f6aa15f4ae665",algorithm=MD5#015#012Route:
sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012Route: sip:126.128.68.9;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012User-Agent: IM-client/OMA1.0 sipML5-v1.2013.03.27#015#012Organization: Doubango Telecom#015#012#015#012 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: websocket [ws_frame.c:580]: ws_frame_receive(): Rx SIP message:#012ACK sip:1234@126.128.68.8:5065;transport=udp SIP/2.0#015#012Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bK8oQgbumE0vQ8RTqBR44N;rport#015#012From: "Jayesh"sip:1000001001@ghanti.com;tag=7EKISKAakFG2QZ2JvpDO#015#012To: < sip:1234@ghanti.com>;tag=8B3F887K7Kvem#015#012Contact: "Jayesh" sip:1000001001@df7jal23ls0d.invalid;rtcweb-breaker=no;click2call=no;transport=ws;+g.oma.sip-im;+sip.ice;language="en,fr"#015#012Call-ID: 2104ab89-6956-9bc1-528e-b18bd9d4b31c#015#012CSeq: 488 ACK#015#012Content-Length: 0#015#012Route: sip:126.128.68.9≈:5060;lr;sipml5-outbound;transport=udp#015#012Max-Forwards: 70#015#012Proxy-Authorization: Digest username="1000001001",realm=" ghanti.com",nonce="UcdDflHHQlLFuiHWM0nV+Y08tTfYLgwI",uri= "sip:1234@126.128.68.8:5065;transport=udp",response="dc63a077f468d55a949f6aa15f4ae665",algorithm=MD5#015#012Route:
sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012Route: sip:126.128.68.9;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes#015#012User-Agent: IM-client/OMA1.0 sipML5-v1.2013.03.27#015#012Organization: Doubango Telecom#015#012#015#012 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:623]: parse_msg(): SIP Request: Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:625]: parse_msg(): method: <ACK> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:627]: parse_msg(): uri: sip:1234@126.128.68.8:5065;transport=udp Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:629]: parse_msg(): version: <SIP/2.0> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK8oQgbumE0vQ8RTqBR44N>; state=6 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=17 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=2 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the first via Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [receive.c:149]: receive_msg(): After parse_msg... Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [receive.c:190]: receive_msg(): preparing to run routing scripts... Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: sl [sl_funcs.c:396]: sl_filter_ACK(): DEBUG : sl_filter_ACK: to late to be a local ACK! Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:176]: parse_to_param(): DEBUG: add_param: tag=8B3F887K7Kvem Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:799]: parse_to(): end of header reached, state=29 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To> [41]; uri=[sip:1234@ghanti.com] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body [< sip:1234@ghanti.com>] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <488> <ACK> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body : content_length=0 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 70 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: maxfwd [maxfwd.c:161]: process_maxfwd_header(): value 70 decreased to 16 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found end of header Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:176]: parse_to_param(): DEBUG: add_param: tag=7EKISKAakFG2QZ2JvpDO Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [parser/parse_to.c:799]: parse_to(): end of header reached, state=29 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks result: 1 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: INFO:
<script>: Request Method is ACK Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:888]: add_contact_alias_0_f(): contact uri host is not an ip address Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:965]: add_contact_alias_0_f(): adding param <;alias=203.153.53.166~59841~5> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: INFO: <script>: Inside NATDETECT Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:888]: add_contact_alias_0_f(): contact uri host is not an ip address Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: nathelper [nathelper.c:965]: add_contact_alias_0_f(): adding param <;alias=203.153.53.166~59841~5> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:89]: is_preloaded(): is_preloaded: No Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.8] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5065 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.8] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5065 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.8] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 8080 (advertise 0) matches port 5065 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [forward.c:462]: check_self(): check_self: host != me Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:589]: grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [126.128.68.9] == [126.128.68.9] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [socket_info.c:593]: grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060 Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:778]: after_loose(): Topmost route URI: ' sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp' is me Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:862]: after_loose(): URI to be processed: ' sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes ' Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:871]: after_loose(): Next URI is a loose router Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:974]: check_route_param(): params are <;lr;sipml5-outbound;transport=udp> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: INFO: <script>: Inside Natmanage ACK Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:1395]: t_newtran(): DEBUG: t_newtran: msg id=8 , global msg id=7 , T on entrance=(nil) Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:534]: t_lookup_request(): t_lookup_request: start searching: hash=60000, isACK=1 un 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:492]: matching_3261(): *DEBUG: RFC3261 transaction matching failed* Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:716]: t_lookup_request(): *DEBUG: t_lookup_request: no transaction found* Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_funcs.c:311]: t_relay_to(): SER: forwarding ACK statelessly *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: WARNING: <core> [msg_translator.c:2499]: via_builder(): TCP/TLS connection (id: 0) for WebSocket could not be found* *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: ERROR: <core> [msg_translator.c:1725]: build_req_buf_from_sip_req(): could not create Via header* *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: ERROR: <core> [forward.c:607]: forward_request(): ERROR: forward_request: building failed* *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: ERROR: sl [sl_funcs.c:371]: sl_reply_error(): ERROR: sl_reply_error used: I'm terribly sorry, server error occurred (1/SL)* Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil) Jun 23 18:45:46 /usr/local/ghanti-ko/sbin/kamailio[22879]: last message repeated 5 times Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [xavp.c:447]: xavp_destroy_list(): destroying xavp list (nil) Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: <core> [receive.c:293]: receive_msg(): receive_msg: cleaning up Thanks for all the help. --- Jayesh On Sun, Jun 23, 2013 at 8:53 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote: > Are you sure the error messages are printed for this ACK, because it > has to be sent via UDP, not via WS, thus the messages seem to be unrelated. > > Get the log messages with debug=3 in order to see what is happening. > > Cheers, > Daniel > > > On 6/22/13 9:10 AM, Jayesh Nambiar wrote: > > Hi, > Is it possible that this could be a problem in the script. But when I > call using a normal SIP Client like X-Lite, it works well. This only > happens when the request comes on websocket. Is there something to be > handled specially when handling requests like ACK over websocket? > The reference is more or less taken from > https://gist.github.com/jesusprubio/4066845 > > --- Jayesh > > > On Wed, Jun 19, 2013 at 2:14 PM, Jayesh Nambiar <jayesh1017@gmail.com>wrote: > >> Hi Daniel, >> I checked using the kamcmd command and I see the webrtc connection >> active. The ACK comes from the webrtc client but somehow kamailio is unable >> to create a via header and forward the request. The ACK coming from webrtc >> client is as follows: >> >> SEND: ACK sip:1223@126.128.68.8:5065;transport=udp SIP/2.0 >> Via: SIP/2.0/WS >> df7jal23ls0d.invalid;branch=z9hG4bKJ0Qsiuh94B2slPLp19qH;rport >> From: "Jayesh"<sip:1000001001@ghanti.com>;tag=vsTKsfB1ZR8EkHTPqzyc >> To: <sip:1223@ghanti.com>;tag=UQ9veX0vUg7QS >> Contact: "Jayesh" >> <sip:1000001001@df7jal23ls0d.invalid;rtcweb-breaker=no;click2call=no;transport=ws> >> ;+g.oma.sip-im;+sip.ice;language="en,fr" >> Call-ID: 2c76d5ee-e9d0-7f22-8be2-76e80b4ab48b >> CSeq: 42684 ACK >> Content-Length: 0 >> Route: <sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp> >> Max-Forwards: 70 >> Proxy-Authorization: Digest username="1000001001",realm="ghanti.com >> ",nonce="UcFsQ1HBaxc84k4N1J00fpVDj9G57x5p",uri= >> "sip:1223@126.128.68.8:5065;transport=udp" >> ,response="5b18a2182c335315875224f2244fb48b",algorithm=MD5 >> Route: >> <sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=vsTKsfB1ZR8EkHTPqzyc;nat=yes> >> Route: <sip:126.128.68.9;r2=on;lr=on;ftag=vsTKsfB1ZR8EkHTPqzyc;nat=yes> >> User-Agent: IM-client/OMA1.0 sipML5-v1.2013.03.27 >> Organization: Doubango Telecom >> >> Where 126.128.68.9:5060 is the Kamailio; 126.128.68.8:5065 is a >> freeswitch playing music and the request is received on >> 126.128.68.9:8080 which is kamailio acting as a websocket server. >> Also the connection between Kamailio and Freeswitch is UDP. I am not >> able to use the websocket module just because of this small problem caused >> in signaling. Any help is really appreciated. Could it be related to the >> nathelper module? >> >> Thanks, >> >> --- Jayesh >> >> >> On Tue, Jun 18, 2013 at 2:17 PM, Daniel-Constantin Mierla < >> miconda@gmail.com> wrote: >> >>> Hello, >>> >>> >>> On 6/14/13 4:52 PM, Jayesh Nambiar wrote: >>> >>> Hello All, >>> I have a setup which is SIPML5 -> Kamailio(Websocket) -> Freeswitch. >>> All I am trying to do is initiate a call from SIPML5 and Play a Music file >>> from freeswitch. This works, but the call hangs up after 30 seconds due to >>> ACK timeout from from the SIPML5. >>> >>> What I can see is the SIPML5 from Chrome does send an ACK on >>> websocket, but I see the following error in kamailio syslog: >>> >>> *via_builder(): TCP/TLS connection (id: 0) for WebSocket could not >>> be found* >>> *ERROR: <core> [msg_translator.c:1725]: build_req_buf_from_sip_req(): >>> could not create Via header* >>> *ERROR: <core> [forward.c:607]: forward_request(): ERROR: >>> forward_request: building failed* >>> *ERROR: sl [sl_funcs.c:371]: sl_reply_error(): ERROR: sl_reply_error >>> used: I'm terribly sorry, server error occurred (1/SL)* >>> >>> Can someone help me understand what I am missing here and why >>> kamailio is not able to create a VIA header to forward this request towards >>> freeswitch. I have built a simple config file by following >>> https://gist.github.com/jesusprubio/4066845 as reference. >>> >>> Any help in understanding this is really appreciated. >>> >>> looks like the web rtc connection was down (closed by one side or >>> interrupted by the network). You can check with kamcmd the list of active >>> connections. >>> >>> Cheers, >>> Daniel >>> >>> -- >>> Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda >>> Kamailio Advanced Training, San Francisco, USA - June 24-27, 2013 >>> * http://asipto.com/u/katu * >>> >>> >>> _______________________________________________ >>> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list >>> sr-users@lists.sip-router.org >>> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users >>> >>> >> > > -- > Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda > > -- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- Tais Plougmann Hansen
OSD Consulting ApS osd.dk Tel: +45 78101078 CVR: DK31332737
Can you get the logs with debug=4?
It doesn't seem like the same problem with the one reported initially in this thread.
Cheers, Daniel
On 9/25/13 6:04 PM, Tais Plougmann Hansen wrote:
I found out that when a subscriber has multiple contacts (ie. by stopping and starting the WS client), kamailio either fails matching the connection or matches the wrong one. Setting registrar max_contacts to 1 and using save("location", "0x04") solved this problem for me.
On Wed, Sep 25, 2013 at 12:01 PM, Tais Plougmann Hansen <taisph@osd.dk mailto:taisph@osd.dk> wrote:
I am getting this error when trying to call from an ip phone -> kamailio -> freeswitch -> kamailio -> jssip. It looks like it can't match the invited subscriber to a WS connection. Calls from jssip to ip phone works (although it hangs up after 3-4 seconds for some reason). On Mon, Jun 24, 2013 at 5:11 PM, Daniel-Constantin Mierla <miconda@gmail.com <mailto:miconda@gmail.com>> wrote: Can you get the ngrep on the server from the initial invite to the ack. It seems that record route is not properly mirrored, so one client might mess the route path. Cheers, Daniel
There's a whole lot of loglines at debug=4. I grabbed the block of lines that seem to belong to the failing INVITE.
2(5209) INFO: <script>: INVITE sip:john.doe.1@1.mail.example.com (F: sip:john.doe.2@1.mail.example.com, T: sip:john.doe.1@1.mail.example.com) 2(5209) DEBUG: <core> [msg_translator.c:206]: check_via_address(): check_via_address(10.0.0.1, 10.0.0.1, 0) 2(5209) DEBUG: siputils [checks.c:103]: has_totag(): no totag 2(5209) DEBUG: tm [t_lookup.c:1100]: t_check_msg(): DEBUG: t_check_msg: msg id=9 global id=7 T start=(nil) 2(5209) DEBUG: tm [t_lookup.c:534]: t_lookup_request(): t_lookup_request: start searching: hash=307, isACK=0 2(5209) DEBUG: tm [t_lookup.c:492]: matching_3261(): DEBUG: RFC3261 transaction matching failed 2(5209) DEBUG: tm [t_lookup.c:716]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found 2(5209) DEBUG: tm [t_lookup.c:1169]: t_check_msg(): DEBUG: t_check_msg: msg id=9 global id=9 T end=(nil) 2(5209) INFO: <script>: LOCATION 2(5209) DEBUG: registrar [lookup.c:181]: lookup(): contact for [ john.doe.1@1.mail.example.com] found by address 2(5209) INFO: <script>: RELAY 2(5209) DEBUG: tm [t_lookup.c:1400]: t_newtran(): DEBUG: t_newtran: msg id=9 , global msg id=9 , T on entrance=(nil) 2(5209) DEBUG: tm [t_lookup.c:534]: t_lookup_request(): t_lookup_request: start searching: hash=307, isACK=0 2(5209) DEBUG: tm [t_lookup.c:492]: matching_3261(): DEBUG: RFC3261 transaction matching failed 2(5209) DEBUG: tm [t_lookup.c:716]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found 2(5209) DEBUG: tm [t_hooks.c:374]: run_reqin_callbacks_internal(): DBG: trans=0x7f3c9ac29d90, callback type 1, id 0 entered 2(5209) DEBUG: dialog [dlg_handlers.c:724]: dlg_onreq(): dialog creation on config flag 2(5209) DEBUG: dialog [dlg_hash.c:664]: internal_get_dlg(): no dialog callid='a84d5218-a202-1231-5d9f-52540051a1d1' found 2(5209) DEBUG: dialog [dlg_hash.c:695]: get_dlg(): no dialog callid='a84d5218-a202-1231-5d9f-52540051a1d1' found 2(5209) DEBUG: dialog [dlg_hash.c:439]: build_new_dlg(): new dialog on hash 3304 2(5209) DEBUG: dialog [dlg_handlers.c:274]: populate_leg_info(): route_set , contact sip:john.doe.3@2.mail.example.com:5080;transport=udp;gw=testpbxs1, cseq 49802847 and bind_addr udp:10.0.0.2:5060 2(5209) DEBUG: dialog [dlg_hash.c:718]: link_dlg(): linking dialog [3304:2157] 2(5209) DEBUG: dialog [dlg_hash.c:727]: link_dlg(): ref dlg 0x7f3c9ac2b0c0 with 1 -> 1 2(5209) DEBUG: dialog [dlg_hash.c:747]: dlg_ref(): ref dlg 0x7f3c9ac2b0c0 with 1 -> 2 2(5209) DEBUG: dialog [dlg_profile.c:406]: set_current_dialog(): setting current dialog [3304:2157] 2(5209) DEBUG: dialog [dlg_hash.c:765]: dlg_unref(): unref dlg 0x7f3c9ac2b0c0 with 1 -> 1 2(5209) DEBUG: dialog [dlg_hash.c:600]: dlg_lookup(): ref dlg 0x7f3c9ac2b0c0 with 1 -> 2 2(5209) DEBUG: dialog [dlg_hash.c:602]: dlg_lookup(): dialog id=2157 found on entry 3304 2(5209) DEBUG: dialog [dlg_handlers.c:729]: dlg_onreq(): dialog added to tm callbacks 2(5209) DEBUG: dialog [dlg_hash.c:765]: dlg_unref(): unref dlg 0x7f3c9ac2b0c0 with 1 -> 1 2(5209) DEBUG: tm [t_hooks.c:374]: run_reqin_callbacks_internal(): DBG: trans=0x7f3c9ac29d90, callback type 1, id 0 entered 2(5209) DEBUG: tm [t_funcs.c:347]: t_relay_to(): SER: new INVITE 2(5209) DEBUG: <core> [msg_translator.c:206]: check_via_address(): check_via_address(10.0.0.1, 10.0.0.1, 0) 2(5209) DEBUG: <core> [mem/shm_mem.c:111]: _shm_resize(): WARNING:vqm_resize: resize(0) called 2(5209) DEBUG: tm [t_reply.c:706]: _reply_light(): DEBUG: reply sent out. buf=0x7f3ca36c25a0: SIP/2.0 100 trying -..., shmem=0x7f3c9ac2c7f0: SIP/2.0 100 trying - 2(5209) DEBUG: tm [t_reply.c:716]: _reply_light(): DEBUG: _reply_light: finished 2(5209) DEBUG: <script>: new branch [0] to sip:93m51afg@nj1hjakcqv9a.invalid;transport=ws 2(5209) WARNING: <core> [msg_translator.c:2499]: via_builder(): TCP/TLS connection (id: 0) for WebSocket could not be found 2(5209) ERROR: <core> [msg_translator.c:1725]: build_req_buf_from_sip_req(): could not create Via header 2(5209) ERROR: tm [t_fwd.c:435]: prepare_new_uac(): could not build request 2(5209) ERROR: tm [t_fwd.c:1534]: t_forward_nonack(): ERROR: t_forward_nonack: failure to add branches 2(5209) DEBUG: tm [t_funcs.c:357]: t_relay_to(): ERROR:tm:t_relay_to: t_forward_nonack returned error 2(5209) DEBUG: tm [t_funcs.c:365]: t_relay_to(): -2 error reply generation delayed 2(5209) DEBUG: <core> [msg_translator.c:206]: check_via_address(): check_via_address(10.0.0.1, 10.0.0.1, 0) 2(5209) ERROR: sl [sl_funcs.c:371]: sl_reply_error(): ERROR: sl_reply_error used: No error (2/SL) 2(5209) DEBUG: dialog [dlg_hash.c:600]: dlg_lookup(): ref dlg 0x7f3c9ac2b0c0 with 1 -> 2 2(5209) DEBUG: dialog [dlg_hash.c:602]: dlg_lookup(): dialog id=2157 found on entry 3304 2(5209) DEBUG: dialog [dlg_hash.c:765]: dlg_unref(): unref dlg 0x7f3c9ac2b0c0 with 1 -> 1 2(5209) DEBUG: tm [t_lookup.c:1553]: t_unref(): t_unref: delayed error reply generation(-2) 2(5209) DEBUG: <core> [msg_translator.c:206]: check_via_address(): check_via_address(10.0.0.1, 10.0.0.1, 0) 2(5209) DEBUG: tm [t_hooks.c:288]: run_trans_callbacks_internal(): DBG: trans=0x7f3c9ac29d90, callback type 1048576, id 0 entered
On Thu, Sep 26, 2013 at 11:14 AM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
Can you get the logs with debug=4?
It doesn't seem like the same problem with the one reported initially in this thread.
Cheers, Daniel
On 9/25/13 6:04 PM, Tais Plougmann Hansen wrote:
I found out that when a subscriber has multiple contacts (ie. by stopping and starting the WS client), kamailio either fails matching the connection or matches the wrong one. Setting registrar max_contacts to 1 and using save("location", "0x04") solved this problem for me.
On Wed, Sep 25, 2013 at 12:01 PM, Tais Plougmann Hansen taisph@osd.dkwrote:
I am getting this error when trying to call from an ip phone -> kamailio -> freeswitch -> kamailio -> jssip. It looks like it can't match the invited subscriber to a WS connection. Calls from jssip to ip phone works (although it hangs up after 3-4 seconds for some reason).
On Mon, Jun 24, 2013 at 5:11 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
Can you get the ngrep on the server from the initial invite to the ack. It seems that record route is not properly mirrored, so one client might mess the route path.
Cheers, Daniel
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
Kamailio Advanced Trainings - Berlin, Oct 21-24; Miami, Nov 11-13, 2013
- more details about Kamailio trainings at http://www.asipto.com -
Sorry for reviving this old thread. I think I've come across the same issue as Jayesh and it is triggered by the Route inserted by sipml5 into in-dialog requests like ACK - Route: sip:172.18.101.48:5060;lr;sipml5-outbound;transport=udp
Jayesh had two Route headers that belong to this kamailio instance and I also have two of them: Route: sip:172.18.101.48;transport=ws;r2=on;lr=on;ftag=RtycJXR6JIUFzAezAbRX;nat=yes;ngcplb=yes;socket=ws:172.18.101.48:5060 Route: sip:127.0.0.1;r2=on;lr=on;ftag=RtycJXR6JIUFzAezAbRX;nat=yes;ngcplb=yes;socket=ws:172.18.101.48:5060
Although RFC3261 doesn't seem to forbit that explicitly, but when sipml5 adds a pre-existing Route to *in-dialog* request, it creates a set where not all URIs are unique. What happens in kamailio is that when loose_route encounters the topmost Route from sipml5 client, it does not remove other routes before sending the request, e.g. I see no further processing after "Next URI is a loose router". I can share the kamailio debug log, but the most important part is:
Feb 14 23:26:54 spce lb[3773]: DEBUG: websocket [ws_frame.c:589]: ws_frame_receive(): Rx SIP message: ACK sip:ngcp-lb@172.18.101.48:5060;ngcpct=7369703a3132372e302e302e313a35303830 SIP/2.0 Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKPLN9elJsPlfeyLsMqN2J;rport From: "4252143385"sip:4252143385@172.18.101.48;tag=RtycJXR6JIUFzAezAbRX To: sip:2067077495@172.18.101.48;tag=1F9894DE-52FE982E000437E0-321A4700 Contact: "4252143385"sip:4252143385@df7jal23ls0d.invalid;rtcweb-breaker=yes;click2call=no;transport=ws;+g.oma.sip-im;+sip.ice;language="en,fr" Call-ID: 1bff80ac-1e47-ab0f-3ea4-6a7b8637030b CSeq: 43084 ACK Content-Length: 0 Route: sip:172.18.101.48:5060;lr;sipml5-outbound;transport=udp Max-Forwards: 70 Proxy-Authorization: … Route: sip:172.18.101.48;transport=ws;r2=on;lr=on;ftag=RtycJXR6JIUFzAezAbRX;nat=yes;ngcplb=yes;socket=ws:172.18.101.48:5060 Route: sip:127.0.0.1;r2=on;lr=on;ftag=RtycJXR6JIUFzAezAbRX;nat=yes;ngcplb=yes;socket=ws:172.18.101.48:5060 Route: sip:127.0.0.1:5062;lr=on;ftag=RtycJXR6JIUFzAezAbRX;did=117.fcb;mpd=ii;ice_caller=replace;savp_caller=force_srtp;avpf_caller=force_avpf;ice_callee=strip;savp_callee=force_rtp;avpf_callee=force_avp;rtpprx=yes;vsf=ampNeU9nS3R6XXJyQ2QgJVJTaiZjfFJ4S35Wf0E- User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 Organization: Doubango Telecom [...] Feb 14 23:26:54 spce lb[3773]: DEBUG: rr [loose.c:778]: after_loose(): Topmost route URI: 'sip:172.18.101.48:5060;lr;sipml5-outbound;transport=udp' is me Feb 14 23:26:54 spce lb[3773]: DEBUG: rr [loose.c:862]: after_loose(): URI to be processed: 'sip:172.18.101.48;transport=ws;r2=on;lr=on;ftag=RtycJXR6JIUFzAezAbRX;nat=yes;ngcplb=yes;socket=ws:172.18.101.48:5060' Feb 14 23:26:54 spce lb[3773]: DEBUG: rr [loose.c:871]: after_loose(): Next URI is a loose router Feb 14 23:26:54 spce lb[3773]: DEBUG: rr [rr_cb.c:97]: run_rr_callbacks(): callback id 0 entered with <lr;sipml5-outbound;transport=udp> Feb 14 23:26:54 spce lb[3773]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Feb 14 23:26:54 spce lb[3773]: DEBUG: rr [loose.c:974]: check_route_param(): params are <;lr;sipml5-outbound;transport=udp> Feb 14 23:26:54 spce lb[3773]: INFO: <script>: Reset loose-routing, du='sip:172.18.101.48;transport=ws;r2=on;lr=on;ftag=RtycJXR6JIUFzAezAbRX;nat=yes;ngcplb=yes;socket=ws:172.18.101.48:5060' - R=sip:127.0.0.1:5080 ID=1bff80ac-1e47-ab0f-3ea4-6a7b8637030b
I see several people came to this mailing list with this issue, but I'm unsure about the outcome. Is this acceptable for an UAC to add a route to in-dialog ACK, which was not in the route set received from the UAS or proxy? Does it intend that the request should spiral? Did anyone take it to the sipml5.org guys? Is loose_route() behavior 100% valid?
Thanks in advance. Andrew
P.S. the log file from Jayesh is quoted below:
On 24/06/13 17:11, Daniel-Constantin Mierla wrote:
Can you get the ngrep on the server from the initial invite to the ack. It seems that record route is not properly mirrored, so one client might mess the route path.
Cheers, Daniel
On 6/23/13 8:58 PM, Jayesh Nambiar wrote:
I did do debug=3 and saw the logs but couldn't figure out much. Here is the log for the appropriate ACK received on websocket port. I've highlighted a few lines I felt might be problematic: [...] Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:778]: after_loose(): Topmost route URI: 'sip:126.128.68.9:5060;lr;sipml5-outbound;transport=udp' is me Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:862]: after_loose(): URI to be processed: 'sip:126.128.68.9:8080;transport=ws;r2=on;lr=on;ftag=7EKISKAakFG2QZ2JvpDO;nat=yes' Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:871]: after_loose(): Next URI is a loose router Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: rr [loose.c:974]: check_route_param(): params are <;lr;sipml5-outbound;transport=udp> Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: INFO:
<script>: Inside Natmanage ACK Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: siputils [checks.c:106]: has_totag(): totag found Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:1395]: t_newtran(): DEBUG: t_newtran: msg id=8 , global msg id=7 , T on entrance=(nil) Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:534]: t_lookup_request(): t_lookup_request: start searching: hash=60000, isACK=1 un 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:492]: matching_3261(): *DEBUG: RFC3261 transaction matching failed* Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_lookup.c:716]: t_lookup_request(): *DEBUG: t_lookup_request: no transaction found* Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: DEBUG: tm [t_funcs.c:311]: t_relay_to(): SER: forwarding ACK statelessly *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: WARNING: <core> [msg_translator.c:2499]: via_builder(): TCP/TLS connection (id: 0) for WebSocket could not be found* *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: ERROR: <core> [msg_translator.c:1725]: build_req_buf_from_sip_req(): could not create Via header* *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: ERROR: <core> [forward.c:607]: forward_request(): ERROR: forward_request: building failed* *Jun 23 18:45:46 v9 /usr/local/ghanti-ko/sbin/kamailio[22879]: ERROR: sl [sl_funcs.c:371]: sl_reply_error(): ERROR: sl_reply_error used: I'm terribly sorry, server error occurred *