once again because to big attachments:)
On Nov 23, 2007 11:48 AM, Tomasz Zieleniewski tzieleniewski@gmail.com wrote:
sorry I forgot to place the attachments
On Nov 23, 2007 11:47 AM, Tomasz Zieleniewski tzieleniewski@gmail.com wrote:
Hi,
Some more debug information:
User contacts: ser@sen:~/ser/ser-2.0/ssp$ ./serctl/ser_ctl usrloc show touk@voip.rd.touk.pl sip:touk@192.168.0.164:1338;rinstance=191d670c84591ea3;transport=TCP 3330 -1.0 sip:touk@192.168.0.164:1348;rinstance=e51fd20db73fc732;transport=TCP 3405 -1.0
Contents of the location table: mysql> select * from location where uid like 'touk@%'; +----------------------+--------------------------+----------------------------------------------------------------------+----------+---------------------+----+----------------------------------------------+------+-------+----------------------------------+----------+ | uid | aor | contact | received | expires | q | callid | cseq | flags | user_agent | instance | +----------------------+--------------------------+----------------------------------------------------------------------+----------+---------------------+----+----------------------------------------------+------+-------+----------------------------------+----------+ | touk@voip.rd.touk.pl | sip:touk@voip.rd.touk.pl | sip:touk@192.168.0.164:1338;rinstance=191d670c84591ea3;transport=TCP | NULL | 2007-11-23 11:17:03 | -1 | MTQ1ZWZmZWE2MWIxZjViYmVkNzZlNmU0YTEwNjRmMTA. | 4 | 0 | X-Lite release 1011s stamp 41150 | NULL | | touk@voip.rd.touk.pl | sip:touk@voip.rd.touk.pl | sip:touk@192.168.0.164:1348;rinstance=e51fd20db73fc732;transport=TCP | NULL | 2007-11-23 11:18:18 | -1 | NDk0ZDA3ZmU5NmFlZmYyMjA5Mjc2ZTZiYTFmMTMxODY. | 4 | 0 | X-Lite release 1011s stamp 41150 | NULL | +----------------------+--------------------------+----------------------------------------------------------------------+----------+---------------------+----+----------------------------------------------+------+-------+----------------------------------+----------+ 2 rows in set (0.00 sec)
Here is what does the internal proxy (192.168.0.165:7160) which is registrar and perform location service, the destination set contains both contacts and the first contact used is the one which is unavailable. this proxy sends first invite with this contact to boundary sip proxy Nov 23 11:20:27 sen ser[28434]: route[FORWARD]: xlset_attr(bsp_route, <$global_addr_bsp;lr=on>) Nov 23 11:20:27 sen ser[28434]: route[FORWARD]: attr_destination($bsp_route) Nov 23 11:20:27 sen ser[28434]: route[FORWARD]: ($fr_inv_timer) Nov 23 11:20:27 sen ser[28434]: route[FORWARD]: t_on_reply(ONREPLY_ROUTE) Nov 23 11:20:27 sen ser[28434]: route[FORWARD]: t_on_failure(FAILURE_ROUTE) Nov 23 11:20:27 sen ser[28434]: route[FORWARD]: t_on_branch(BRANCH_ROUTE) Nov 23 11:20:27 sen ser[28434]: route[FORWARD]: destination set: Contact: sip:touk@192.168.0.164:1338;rinstance=191d670c84591ea3;transport=TCP, sip:touk@192.168.0.164:1348;rinstance=e51fd20db73fc732;transpo Nov 23 11:20:27 sen ser[28434]: route[FORWARD]: next route: <null> Nov 23 11:20:27 sen ser[28434]: route[FORWARD]: message's next hop: sip:voip.rd.touk.pl:7060;lr=on Nov 23 11:20:27 sen ser[28434]: route[FORWARD]: (!t_relay()) Nov 23 11:20:27 sen ser[28434]: branch_route[BRANCH_ROUTE]: <INVITE> ruri:sip:touk@192.168.0.164:1338;rinstance=191d670c84591ea3;transport=TCP t:sip:touk@voip.rd.touk.pl f:sip:hellboy@voip.rd.touk.pl c Nov 23 11:20:27 sen ser[28434]: branch_route[BRANCH_ROUTE]: append_hf(P-Warn: forked branch) Nov 23 11:20:27 sen ser[28434]: branch_route[BRANCH_ROUTE]: <INVITE> ruri:sip:touk@192.168.0.164:1348;rinstance=e51fd20db73fc732;transport=TCP t:sip:touk@voip.rd.touk.pl f:sip:hellboy@voip.rd.touk.pl c Nov 23 11:20:27 sen ser[28434]: branch_route[BRANCH_ROUTE]: append_hf(P-Warn: forked branch) Nov 23 11:20:27 sen ser[28434]: ERROR: tcp_blocking_connect: poll error: flags 18 Nov 23 11:20:27 sen ser[28434]: ERROR: tcp_blocking_connect: SO_ERROR (111) Connection refused Nov 23 11:20:27 sen ser[28434]: ERROR: tcpconn_connect: tcp_blocking_connect failed Nov 23 11:20:27 sen ser[28434]: ERROR: tcp_send: connect failed Nov 23 11:20:27 sen ser[28434]: msg_send: ERROR: tcp_send failed Nov 23 11:20:27 sen ser[28434]: ERROR: t_send_branch: sending request on branch 1 failed Nov 23 11:20:27 sen ser[28434]: route[FORWARD]: drop
here is what happens in boundary sip proxy: is receives the invite tries to do the t_rqlay but there is the tcp error. t_relay() fails and it sends the sl_reply_error to internal sip proxy: Nov 23 11:31:38 sen ser[31861]: route[FORWARD]: destination set: <null> Nov 23 11:31:38 sen ser[31861]: route[FORWARD]: next route: <null> Nov 23 11:31:38 sen ser[31861]: route[FORWARD]: message's next hop: sip:touk@192.168.0.164:1338;rinstance=191d670c84591ea3;transport=TCP Nov 23 11:31:38 sen ser[31861]: route[FORWARD]: (!t_relay()) Nov 23 11:31:38 sen ser[31861]: ERROR: tcp_blocking_connect: poll error: flags 18 Nov 23 11:31:38 sen ser[31861]: ERROR: tcp_blocking_connect: SO_ERROR (111) Connection refused Nov 23 11:31:38 sen ser[31861]: ERROR: tcpconn_connect: tcp_blocking_connect failed Nov 23 11:31:38 sen ser[31861]: ERROR: tcp_send: connect failed Nov 23 11:31:38 sen ser[31861]: msg_send: ERROR: tcp_send failed Nov 23 11:31:38 sen ser[31861]: ERROR: t_send_branch: sending request on branch 0 failed Nov 23 11:31:38 sen ser[31861]: route[FORWARD]: (!t_relay()) -> TRUE Nov 23 11:31:38 sen ser[31861]: route[FORWARD]: sl_reply_error() Nov 23 11:31:38 sen ser[31861]: ERROR: sl_reply_error used: I'm terribly sorry, server error occurred (1/SL)
in the attachment there are ngrep and wireshark log from the same situation
if you need more info please let me know waiting for your feedback
Cheers tomasz
On Nov 22, 2007 8:40 PM, Andrei Pelinescu-Onciul andrei@iptel.org wrote:
On Nov 16, 2007 at 14:43, Tomasz Zieleniewski (JIRA) tracker@iptel.org wrote:
tcp branching error
Key: SER-332 URL: http://tracker.iptel.org/browse/SER-332 Project: SER Issue Type: Bug Components: core Affects Versions: 2.0 Environment: Linux sen 2.6.18-5-amd64 #1 SMP Tue Oct 2 20:37:02 UTC 2007 x86_64 GNU/Linux Reporter: Tomasz Zieleniewski Priority: CriticalHi,
I have the following situation. I have two ser rel_2_0_0 instances one acting as a boundary proxy the other on as internal proxy (registrar, location).
I have the following situation I have a user which has registered two contacs one woth tcp transport the other one with udp.
All messages coming to and outgoing from my network travels through boundary sip proxy.
When internal ser perform lookup_location it get to contacts and the destination set contains two records: Nov 15 11:03:13 sen ser[3673]: route[FORWARD]: destination set: Contact: sip:xlite@192.168.0.164:1221;rinstance=d35f9cda6bd79b0a;transport=TCP, sip:xlite@192.168.0.164:7060
Then internal ser forward message to boundary SIP proxy by changing the destination of the message and with the usage of t_relay(). I see from log that there are two branches involved: Nov 15 11:03:13 sen ser[3673]: branch_route[BRANCH_ROUTE]: <INVITE> ruri:sip:xlite@192.168.0.164:1221;rinstance=d35f9cda6bd79b0a;transport=TCP t:sip:00@voip.rd.touk.pl f:sip:lkl@voip.rd.touk.pl Nov 15 11:03:13 sen ser[3673]: branch_route[BRANCH_ROUTE]: append_hf(P-Warn: forked branch) Nov 15 11:03:13 sen ser[3673]: branch_route[BRANCH_ROUTE]: <INVITE> ruri:sip:xlite@192.168.0.164:7060;rinstance=cfca8523e3747cb0 t:sip:00@voip.rd.touk.pl f:sip:lkl@voip.rd.touk.pl Nov 15 11:03:13 sen ser[3673]: branch_route[BRANCH_ROUTE]: append_hf(P-Warn: forked branch)
both INVITES reaches boudary SIP proxy.
Because first contact was unreachable there was an tcp error: ser[3516]: ERROR: tcp_blocking_connect: poll error: flags 18 Nov 15 11:03:13 sen ser[3516]: ERROR: tcp_blocking_connect: SO_ERROR (111) Connection refused Nov 15 11:03:13 sen ser[3516]: ERROR: tcpconn_connect: tcp_blocking_connect failed Nov 15 11:03:13 sen ser[3516]: ERROR: tcp_send: connect failed Nov 15 11:03:13 sen ser[3516]: msg_send: ERROR: tcp_send failed Nov 15 11:03:13 sen ser[3516]: ERROR: t_send_branch: sending request on branch 0 failed
after which ser invokes sl_reply_error() which results in 477 next hop error reponse message sent to internal ser instance. The problem arises when boudary sip proxy processes second INVITE which correspond to second destination. when boundary SIP proxy receives it doesn't send it to user agent but instead reponses to internal ser with 500 I'm terribly sorry, server error occurred (1/SL) the only thing I see in the boundary SIP proxy log is: ERROR: sl_reply_error used: I'm terribly sorry, server error occurred (1/SL)
Did I miss something here or this is an error? Waiting for Your feedback
Could you make some traffic dump between the 2 proxies and send it to me (andrei@iptel.org)? It's sounds quite strange (it should work without any problems) and a look at the packets might help.
Thanks, Andrei _______________________________________________ Serdev mailing list Serdev@lists.iptel.org http://lists.iptel.org/mailman/listinfo/serdev