[Serusers] [Serdev] [Tracker] Created: (SER-332) tcp branching error
Tomasz Zieleniewski
tzieleniewski at gmail.com
Fri Nov 23 12:04:24 CET 2007
once again because to big attachments:)
On Nov 23, 2007 11:48 AM, Tomasz Zieleniewski <tzieleniewski at gmail.com> wrote:
> sorry I forgot to place the attachments
>
>
> On Nov 23, 2007 11:47 AM, Tomasz Zieleniewski <tzieleniewski at gmail.com> wrote:
> > Hi,
> >
> > Some more debug information:
> >
> > User contacts:
> > ser at sen:~/ser/ser-2.0/ssp$ ./serctl/ser_ctl usrloc show touk at voip.rd.touk.pl
> > sip:touk at 192.168.0.164:1338;rinstance=191d670c84591ea3;transport=TCP 3330 -1.0
> > sip:touk at 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 at voip.rd.touk.pl | sip:touk at voip.rd.touk.pl |
> > sip:touk at 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 at voip.rd.touk.pl | sip:touk at voip.rd.touk.pl |
> > sip:touk at 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 at 192.168.0.164:1338;rinstance=191d670c84591ea3;transport=TCP,
> > sip:touk at 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 at 192.168.0.164:1338;rinstance=191d670c84591ea3;transport=TCP>
> > t:<sip:touk at voip.rd.touk.pl> f:<sip:hellboy at 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 at 192.168.0.164:1348;rinstance=e51fd20db73fc732;transport=TCP>
> > t:<sip:touk at voip.rd.touk.pl> f:<sip:hellboy at 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 at 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 at iptel.org> wrote:
> > > On Nov 16, 2007 at 14:43, Tomasz Zieleniewski (JIRA) <tracker at 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: Critical
> > > >
> > > >
> > > > Hi,
> > > >
> > > > 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 at 192.168.0.164:1221;rinstance=d35f9cda6bd79b0a;transport=TCP,
> > > > sip:xlite at 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 at 192.168.0.164:1221;rinstance=d35f9cda6bd79b0a;transport=TCP>
> > > > t:<sip:00 at voip.rd.touk.pl> f:<sip:lkl at 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 at 192.168.0.164:7060;rinstance=cfca8523e3747cb0>
> > > > t:<sip:00 at voip.rd.touk.pl> f:<sip:lkl at 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 at 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 at lists.iptel.org
> > > http://lists.iptel.org/mailman/listinfo/serdev
> > >
> >
>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: ser_tcp_error.pcap.gz
Type: application/x-gzip
Size: 12888 bytes
Desc: not available
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20071123/21903c70/attachment.bin>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: ser_tcp_error.log.gz
Type: application/x-gzip
Size: 1300 bytes
Desc: not available
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20071123/21903c70/attachment-0001.bin>
More information about the sr-users
mailing list