[Users] via header not added when transport=TCP?
Bogdan-Andrei Iancu
bogdan at voice-system.ro
Tue Aug 2 16:21:22 CEST 2005
Hi Erich,
I analysed a little bit the dumps and logs you sent and I would say
there is nothing wrong with OpenSER here - it seams more like the result
of strange SIP UAs:
The second TCP message is from .40 -> .41 which is UAC -> UAS. For the
first message the IP/TCP headers are missing. So, the SIP requests over
TCP does not hit the proxy at all!! For UDP, the net dump shows two
requests, 40 -> 42 and 42->41, which is the normal path.
In same idea, you can notice in OpenSER logs that there is no log
regarding the request, but only some replies processing. And this is
very, very strange!!! The UAS receives the request via TCP directly from
UAC, but sends back the reply to proxy, ignoring the VIA
stack.....that's broken...
I will strongly advice to re-try the scenario using different SIP UAs.
regards,
bogdan
Erich Nahum wrote:
>On Mon, Jul 25, 2005 at 03:05:23PM +0300, Bogdan-Andrei Iancu wrote:
>
>
>>do you get any errors in the log when OpenSER forwards the request over TCP?
>>why is the RR header missing when using TCP? can you post for the TCP
>>case, the full network capture -incoming and outgoing message with
>>addresses and ports?
>>
>>
>
>Sorry, I was mistaken before when I said I was mistaken. The fault does
>seem to be from openser. I was looking at the wrong dumps.
>I'm attaching the following items in the hopes that they illustrate
>the problem:
>
>ethereal text dump of UAC TCP
>ethereal text dump of UAC UDP
>ethereal text dump of UAS TCP
>ethereal text dump of UAS UDP
>logs from /var/log/messages with debug=5
>
>To cut to the chase, here's a diff of the UAS TCP packet with the UDP.
>bronxville == UAC == 10.0.1.40
>crestwood == proxy == 10.0.1.42
>tuckahoe == UAS == 10.0.1.41
>
>< Via: SIP/2.0/TCP bronxville1:5060;branch=z9hG4bK-1-0
>---
>
>
>> Record-Route: <sip:10.0.1.42;ftag=1;lr=on>
>> Via: SIP/2.0/UDP 10.0.1.42;branch=z9hG4bKcf89.f46403c6.0
>> Via: SIP/2.0/UDP bronxville1:5060;received=10.0.1.40;branch=z9hG4bK-1-0
>>
>>
>15c17
>< Call-ID: 1-26885 at bronxville1
>---
>
>
>> Call-ID: 1-26914 at bronxville1
>>
>>
>18c20
>< Max-Forwards: 70
>---
>
>
>> Max-Forwards: 16
>>
>>
>21a24
>
>
>> P-hint: outbound
>>
>>
>
>Thanks,
>
>-Erich
>
>
>
>------------------------------------------------------------------------
>
>Session Initiation Protocol
> Request-Line: INVITE sip:service at 10.0.1.41:5060 SIP/2.0
> Method: INVITE
> Resent Packet: False
> Message Header
> Via: SIP/2.0/TCP bronxville1:5060;branch=z9hG4bK-1-0
> From: sipp <sip:sipp at bronxville1:5060>;tag=1
> SIP from address: sipp <sip:sipp at bronxville1:5060>
> SIP tag: 1
> To: sut <sip:service at 10.0.1.41:5060>
> Call-ID: 1-27019 at bronxville1
> CSeq: 1 INVITE
> Contact: sip:sipp at bronxville1:5060
> Max-Forwards: 70
> Subject: Performance Test
> Content-Type: application/sdp
> Content-Length: 132
> Message body
>
>
>
>------------------------------------------------------------------------
>
>Frame 7 (537 bytes on wire, 537 bytes captured)
>Ethernet II, Src: 00:11:25:29:11:5d, Dst: 00:0d:60:9d:30:3f
>Internet Protocol, Src Addr: 10.0.1.40 (10.0.1.40), Dst Addr: 10.0.1.42 (10.0.1.42)
>User Datagram Protocol, Src Port: 5060 (5060), Dst Port: 5060 (5060)
>Session Initiation Protocol
> Request-Line: INVITE sip:service at 10.0.1.41:5060 SIP/2.0
> Method: INVITE
> Resent Packet: False
> Message Header
> Via: SIP/2.0/UDP bronxville1:5060;branch=z9hG4bK-1-0
> From: sipp <sip:sipp at bronxville1:5060>;tag=1
> SIP from address: sipp <sip:sipp at bronxville1:5060>
> SIP tag: 1
> To: sut <sip:service at 10.0.1.41:5060>
> Call-ID: 1-28105 at bronxville1
> CSeq: 1 INVITE
> Contact: sip:sipp at bronxville1:5060
> Max-Forwards: 70
> Subject: Performance Test
> Content-Type: application/sdp
> Content-Length: 132
> Message body
>
>
>
>------------------------------------------------------------------------
>
>Frame 16 (561 bytes on wire, 561 bytes captured)
>Ethernet II, Src: 00:11:25:29:11:5d, Dst: 00:0d:60:9d:73:db
>Internet Protocol, Src Addr: 10.0.1.40 (10.0.1.40), Dst Addr: 10.0.1.41 (10.0.1.41)
>Transmission Control Protocol, Src Port: 56280 (56280), Dst Port: 5060 (5060), Seq: 1, Ack: 1, Len: 495
>Session Initiation Protocol
> Request-Line: INVITE sip:service at 10.0.1.41:5060 SIP/2.0
> Method: INVITE
> Resent Packet: False
> Message Header
> Via: SIP/2.0/TCP bronxville1:5060;branch=z9hG4bK-1-0
> From: sipp <sip:sipp at bronxville1:5060>;tag=1
> SIP from address: sipp <sip:sipp at bronxville1:5060>
> SIP tag: 1
> To: sut <sip:service at 10.0.1.41:5060>
> Call-ID: 1-26885 at bronxville1
> CSeq: 1 INVITE
> Contact: sip:sipp at bronxville1:5060
> Max-Forwards: 70
> Subject: Performance Test
> Content-Type: application/sdp
> Content-Length: 132
> Message body
>
>
>
>
>------------------------------------------------------------------------
>
>Frame 10 (676 bytes on wire, 676 bytes captured)
>Ethernet II, Src: 00:0d:60:9d:30:3f, Dst: 00:0d:60:9d:73:db
>Internet Protocol, Src Addr: 10.0.1.42 (10.0.1.42), Dst Addr: 10.0.1.41 (10.0.1.41)
>User Datagram Protocol, Src Port: 5060 (5060), Dst Port: 5060 (5060)
>Session Initiation Protocol
> Request-Line: INVITE sip:service at 10.0.1.41:5060 SIP/2.0
> Method: INVITE
> Resent Packet: False
> Message Header
> Record-Route: <sip:10.0.1.42;ftag=1;lr=on>
> Via: SIP/2.0/UDP 10.0.1.42;branch=z9hG4bKcf89.f46403c6.0
> Via: SIP/2.0/UDP bronxville1:5060;received=10.0.1.40;branch=z9hG4bK-1-0
> From: sipp <sip:sipp at bronxville1:5060>;tag=1
> SIP from address: sipp <sip:sipp at bronxville1:5060>
> SIP tag: 1
> To: sut <sip:service at 10.0.1.41:5060>
> Call-ID: 1-26914 at bronxville1
> CSeq: 1 INVITE
> Contact: sip:sipp at bronxville1:5060
> Max-Forwards: 16
> Subject: Performance Test
> Content-Type: application/sdp
> Content-Length: 132
> P-hint: outbound
> Message body
>
>
>------------------------------------------------------------------------
>
>Jul 26 19:21:06 crestwood ./openser[27474]: tcpconn_new: new tcp connection: 10.0.1.41
>Jul 26 19:21:06 crestwood ./openser[27474]: tcpconn_new: on port 47197, type 2
>Jul 26 19:21:06 crestwood ./openser[27474]: tcpconn_add: hashes: 87, 9
>Jul 26 19:21:06 crestwood ./openser[27474]: tcp_main_loop: new connection: 0x403b6e10 64
>Jul 26 19:21:06 crestwood ./openser[27474]: send2child: to tcp child 0 35(27466), 0x403b6e10
>Jul 26 19:21:06 crestwood ./openser[27466]: received n=4 con=0x403b6e10, fd=49
>Jul 26 19:21:06 crestwood ./openser[27466]: tcp_read_req: content-length= 0
>Jul 26 19:21:06 crestwood ./openser[27466]: SIP Reply (status):
>Jul 26 19:21:06 crestwood ./openser[27466]: version: <SIP/2.0>
>Jul 26 19:21:06 crestwood ./openser[27466]: status: <180>
>Jul 26 19:21:06 crestwood ./openser[27466]: reason: <Ringing>
>Jul 26 19:21:06 crestwood ./openser[27466]: parse_headers: flags=1
>Jul 26 19:21:06 crestwood ./openser[27466]: Found param type 232, <branch> = <z9hG4bK-1-0>; state=16
>Jul 26 19:21:06 crestwood ./openser[27466]: end of header reached, state=5
>Jul 26 19:21:06 crestwood ./openser[27466]: parse_headers: Via found, flags=1
>Jul 26 19:21:06 crestwood ./openser[27466]: parse_headers: this is the first via
>Jul 26 19:21:06 crestwood ./openser[27466]: After parse_msg...
>Jul 26 19:21:06 crestwood ./openser[27466]: forward_reply: found module tm, passing reply to it
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: t_check: msg id=7 global id=6 T start=(nil)
>Jul 26 19:21:06 crestwood ./openser[27466]: parse_headers: flags=17
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: add_param: tag=1
>Jul 26 19:21:06 crestwood ./openser[27466]: end of header reached, state=29
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: get_hdr_field: <To> [40]; uri=[sip:service at 10.0.1.41:5060]
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: to body [sut <sip:service at 10.0.1.41:5060>]
>Jul 26 19:21:06 crestwood ./openser[27466]: get_hdr_field: cseq <CSeq>: <1> <INVITE>
>Jul 26 19:21:06 crestwood ./openser[27466]: parse_headers: flags=4
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: t_reply_matching: failure to match a transaction
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: t_check: msg id=7 global id=7 T end=(nil)
>Jul 26 19:21:06 crestwood ./openser[27466]: parse_headers: flags=2
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: get_hdr_body : content_length=0
>Jul 26 19:21:06 crestwood ./openser[27466]: found end of header
>Jul 26 19:21:06 crestwood ./openser[27466]: ERROR: forward_reply: no 2nd via found in reply
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG:destroy_avp_list: destroying list (nil)
>Jul 26 19:21:06 crestwood ./openser[27466]: receive_msg: cleaning up
>Jul 26 19:21:06 crestwood ./openser[27466]: tcp_read_req: content-length= 130
>Jul 26 19:21:06 crestwood ./openser[27466]: SIP Reply (status):
>Jul 26 19:21:06 crestwood ./openser[27466]: version: <SIP/2.0>
>Jul 26 19:21:06 crestwood ./openser[27466]: status: <200>
>Jul 26 19:21:06 crestwood ./openser[27466]: reason: <OK>
>Jul 26 19:21:06 crestwood ./openser[27466]: parse_headers: flags=1
>Jul 26 19:21:06 crestwood ./openser[27466]: Found param type 232, <branch> = <z9hG4bK-1-0>; state=16
>Jul 26 19:21:06 crestwood ./openser[27466]: end of header reached, state=5
>Jul 26 19:21:06 crestwood ./openser[27466]: parse_headers: Via found, flags=1
>Jul 26 19:21:06 crestwood ./openser[27466]: parse_headers: this is the first via
>Jul 26 19:21:06 crestwood ./openser[27466]: After parse_msg...
>Jul 26 19:21:06 crestwood ./openser[27466]: forward_reply: found module tm, passing reply to it
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: t_check: msg id=8 global id=7 T start=(nil)
>Jul 26 19:21:06 crestwood ./openser[27466]: parse_headers: flags=17
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: add_param: tag=1
>Jul 26 19:21:06 crestwood ./openser[27466]: end of header reached, state=29
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: get_hdr_field: <To> [40]; uri=[sip:service at 10.0.1.41:5060]
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: to body [sut <sip:service at 10.0.1.41:5060>]
>Jul 26 19:21:06 crestwood ./openser[27466]: get_hdr_field: cseq <CSeq>: <1> <INVITE>
>Jul 26 19:21:06 crestwood ./openser[27466]: parse_headers: flags=4
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: t_reply_matching: failure to match a transaction
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: t_check: msg id=8 global id=8 T end=(nil)
>Jul 26 19:21:06 crestwood ./openser[27466]: parse_headers: flags=2
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: get_hdr_body : content_length=130
>Jul 26 19:21:06 crestwood ./openser[27466]: found end of header
>Jul 26 19:21:06 crestwood ./openser[27466]: ERROR: forward_reply: no 2nd via found in reply
>Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG:destroy_avp_list: destroying list (nil)
>Jul 26 19:21:06 crestwood ./openser[27466]: receive_msg: cleaning up
>Jul 26 19:21:07 crestwood ./openser[27474]: tcpconn_new: new tcp connection: 10.0.1.41
>Jul 26 19:21:07 crestwood ./openser[27474]: tcpconn_new: on port 47198, type 2
>Jul 26 19:21:07 crestwood ./openser[27474]: tcpconn_add: hashes: 84, 10
>Jul 26 19:21:07 crestwood ./openser[27474]: tcp_main_loop: new connection: 0x403a6cf8 66
>Jul 26 19:21:07 crestwood ./openser[27474]: send2child: to tcp child 1 36(27467), 0x403a6cf8
>Jul 26 19:21:07 crestwood ./openser[27467]: received n=4 con=0x403a6cf8, fd=50
>Jul 26 19:21:07 crestwood ./openser[27467]: tcp_read_req: content-length= 0
>Jul 26 19:21:07 crestwood ./openser[27467]: SIP Reply (status):
>Jul 26 19:21:07 crestwood ./openser[27467]: version: <SIP/2.0>
>Jul 26 19:21:07 crestwood ./openser[27467]: status: <180>
>Jul 26 19:21:07 crestwood ./openser[27467]: reason: <Ringing>
>Jul 26 19:21:07 crestwood ./openser[27467]: parse_headers: flags=1
>Jul 26 19:21:07 crestwood ./openser[27467]: Found param type 232, <branch> = <z9hG4bK-2-0>; state=16
>Jul 26 19:21:07 crestwood ./openser[27467]: end of header reached, state=5
>Jul 26 19:21:07 crestwood ./openser[27467]: parse_headers: Via found, flags=1
>Jul 26 19:21:07 crestwood ./openser[27467]: parse_headers: this is the first via
>Jul 26 19:21:07 crestwood ./openser[27467]: After parse_msg...
>Jul 26 19:21:07 crestwood ./openser[27467]: forward_reply: found module tm, passing reply to it
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: t_check: msg id=7 global id=6 T start=(nil)
>Jul 26 19:21:07 crestwood ./openser[27467]: parse_headers: flags=17
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: add_param: tag=2
>Jul 26 19:21:07 crestwood ./openser[27467]: end of header reached, state=29
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: get_hdr_field: <To> [40]; uri=[sip:service at 10.0.1.41:5060]
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: to body [sut <sip:service at 10.0.1.41:5060>]
>Jul 26 19:21:07 crestwood ./openser[27467]: get_hdr_field: cseq <CSeq>: <1> <INVITE>
>Jul 26 19:21:07 crestwood ./openser[27467]: parse_headers: flags=4
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: t_reply_matching: failure to match a transaction
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: t_check: msg id=7 global id=7 T end=(nil)
>Jul 26 19:21:07 crestwood ./openser[27467]: parse_headers: flags=2
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: get_hdr_body : content_length=0
>Jul 26 19:21:07 crestwood ./openser[27467]: found end of header
>Jul 26 19:21:07 crestwood ./openser[27467]: ERROR: forward_reply: no 2nd via found in reply
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG:destroy_avp_list: destroying list (nil)
>Jul 26 19:21:07 crestwood ./openser[27467]: receive_msg: cleaning up
>Jul 26 19:21:07 crestwood ./openser[27467]: tcp_read_req: content-length= 130
>Jul 26 19:21:07 crestwood ./openser[27467]: SIP Reply (status):
>Jul 26 19:21:07 crestwood ./openser[27467]: version: <SIP/2.0>
>Jul 26 19:21:07 crestwood ./openser[27467]: status: <200>
>Jul 26 19:21:07 crestwood ./openser[27467]: reason: <OK>
>Jul 26 19:21:07 crestwood ./openser[27467]: parse_headers: flags=1
>Jul 26 19:21:07 crestwood ./openser[27467]: Found param type 232, <branch> = <z9hG4bK-2-0>; state=16
>Jul 26 19:21:07 crestwood ./openser[27467]: end of header reached, state=5
>Jul 26 19:21:07 crestwood ./openser[27467]: parse_headers: Via found, flags=1
>Jul 26 19:21:07 crestwood ./openser[27467]: parse_headers: this is the first via
>Jul 26 19:21:07 crestwood ./openser[27467]: After parse_msg...
>Jul 26 19:21:07 crestwood ./openser[27467]: forward_reply: found module tm, passing reply to it
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: t_check: msg id=8 global id=7 T start=(nil)
>Jul 26 19:21:07 crestwood ./openser[27467]: parse_headers: flags=17
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: add_param: tag=2
>Jul 26 19:21:07 crestwood ./openser[27467]: end of header reached, state=29
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: get_hdr_field: <To> [40]; uri=[sip:service at 10.0.1.41:5060]
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: to body [sut <sip:service at 10.0.1.41:5060>]
>Jul 26 19:21:07 crestwood ./openser[27467]: get_hdr_field: cseq <CSeq>: <1> <INVITE>
>Jul 26 19:21:07 crestwood ./openser[27467]: parse_headers: flags=4
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: t_reply_matching: failure to match a transaction
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: t_check: msg id=8 global id=8 T end=(nil)
>Jul 26 19:21:07 crestwood ./openser[27467]: parse_headers: flags=2
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: get_hdr_body : content_length=130
>Jul 26 19:21:07 crestwood ./openser[27467]: found end of header
>Jul 26 19:21:07 crestwood ./openser[27467]: ERROR: forward_reply: no 2nd via found in reply
>Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG:destroy_avp_list: destroying list (nil)
>Jul 26 19:21:07 crestwood ./openser[27467]: receive_msg: cleaning up
>Jul 26 19:21:08 crestwood ./openser[27474]: tcpconn_new: new tcp connection: 10.0.1.41
>Jul 26 19:21:08 crestwood ./openser[27474]: tcpconn_new: on port 47199, type 2
>Jul 26 19:21:08 crestwood ./openser[27474]: tcpconn_add: hashes: 85, 11
>Jul 26 19:21:08 crestwood ./openser[27474]: tcp_main_loop: new connection: 0x403c6f28 67
>Jul 26 19:21:08 crestwood ./openser[27474]: send2child: to tcp child 2 37(27468), 0x403c6f28
>Jul 26 19:21:08 crestwood ./openser[27468]: received n=4 con=0x403c6f28, fd=52
>Jul 26 19:21:08 crestwood ./openser[27468]: tcp_read_req: content-length= 0
>Jul 26 19:21:08 crestwood ./openser[27468]: SIP Reply (status):
>Jul 26 19:21:08 crestwood ./openser[27468]: version: <SIP/2.0>
>Jul 26 19:21:08 crestwood ./openser[27468]: status: <180>
>Jul 26 19:21:08 crestwood ./openser[27468]: reason: <Ringing>
>Jul 26 19:21:08 crestwood ./openser[27468]: parse_headers: flags=1
>Jul 26 19:21:08 crestwood ./openser[27468]: Found param type 232, <branch> = <z9hG4bK-3-0>; state=16
>Jul 26 19:21:08 crestwood ./openser[27468]: end of header reached, state=5
>Jul 26 19:21:08 crestwood ./openser[27468]: parse_headers: Via found, flags=1
>Jul 26 19:21:08 crestwood ./openser[27468]: parse_headers: this is the first via
>Jul 26 19:21:08 crestwood ./openser[27468]: After parse_msg...
>Jul 26 19:21:08 crestwood ./openser[27468]: forward_reply: found module tm, passing reply to it
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: t_check: msg id=5 global id=4 T start=(nil)
>Jul 26 19:21:08 crestwood ./openser[27468]: parse_headers: flags=17
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: add_param: tag=3
>Jul 26 19:21:08 crestwood ./openser[27468]: end of header reached, state=29
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: get_hdr_field: <To> [40]; uri=[sip:service at 10.0.1.41:5060]
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: to body [sut <sip:service at 10.0.1.41:5060>]
>Jul 26 19:21:08 crestwood ./openser[27468]: get_hdr_field: cseq <CSeq>: <1> <INVITE>
>Jul 26 19:21:08 crestwood ./openser[27468]: parse_headers: flags=4
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: t_reply_matching: failure to match a transaction
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: t_check: msg id=5 global id=5 T end=(nil)
>Jul 26 19:21:08 crestwood ./openser[27468]: parse_headers: flags=2
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: get_hdr_body : content_length=0
>Jul 26 19:21:08 crestwood ./openser[27468]: found end of header
>Jul 26 19:21:08 crestwood ./openser[27468]: ERROR: forward_reply: no 2nd via found in reply
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG:destroy_avp_list: destroying list (nil)
>Jul 26 19:21:08 crestwood ./openser[27468]: receive_msg: cleaning up
>Jul 26 19:21:08 crestwood ./openser[27468]: tcp_read_req: content-length= 130
>Jul 26 19:21:08 crestwood ./openser[27468]: SIP Reply (status):
>Jul 26 19:21:08 crestwood ./openser[27468]: version: <SIP/2.0>
>Jul 26 19:21:08 crestwood ./openser[27468]: status: <200>
>Jul 26 19:21:08 crestwood ./openser[27468]: reason: <OK>
>Jul 26 19:21:08 crestwood ./openser[27468]: parse_headers: flags=1
>Jul 26 19:21:08 crestwood ./openser[27468]: Found param type 232, <branch> = <z9hG4bK-3-0>; state=16
>Jul 26 19:21:08 crestwood ./openser[27468]: end of header reached, state=5
>Jul 26 19:21:08 crestwood ./openser[27468]: parse_headers: Via found, flags=1
>Jul 26 19:21:08 crestwood ./openser[27468]: parse_headers: this is the first via
>Jul 26 19:21:08 crestwood ./openser[27468]: After parse_msg...
>Jul 26 19:21:08 crestwood ./openser[27468]: forward_reply: found module tm, passing reply to it
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: t_check: msg id=6 global id=5 T start=(nil)
>Jul 26 19:21:08 crestwood ./openser[27468]: parse_headers: flags=17
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: add_param: tag=3
>Jul 26 19:21:08 crestwood ./openser[27468]: end of header reached, state=29
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: get_hdr_field: <To> [40]; uri=[sip:service at 10.0.1.41:5060]
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: to body [sut <sip:service at 10.0.1.41:5060>]
>Jul 26 19:21:08 crestwood ./openser[27468]: get_hdr_field: cseq <CSeq>: <1> <INVITE>
>Jul 26 19:21:08 crestwood ./openser[27468]: parse_headers: flags=4
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: t_reply_matching: failure to match a transaction
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: t_check: msg id=6 global id=6 T end=(nil)
>Jul 26 19:21:08 crestwood ./openser[27468]: parse_headers: flags=2
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: get_hdr_body : content_length=130
>Jul 26 19:21:08 crestwood ./openser[27468]: found end of header
>Jul 26 19:21:08 crestwood ./openser[27468]: ERROR: forward_reply: no 2nd via found in reply
>Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG:destroy_avp_list: destroying list (nil)
>Jul 26 19:21:08 crestwood ./openser[27468]: receive_msg: cleaning up
>Jul 26 19:21:10 crestwood ./openser[27466]: tcp_read: EOF on 0x403b6e10, FD 49
>Jul 26 19:21:10 crestwood ./openser[27466]: tcp_read_req: EOF
>Jul 26 19:21:10 crestwood ./openser[27466]: releasing con 0x403b6e10, state -1, fd=49, id=9
>Jul 26 19:21:10 crestwood ./openser[27466]: extra_data (nil)
>Jul 26 19:21:10 crestwood ./openser[27467]: tcp_read: EOF on 0x403a6cf8, FD 50
>Jul 26 19:21:10 crestwood ./openser[27467]: tcp_read_req: EOF
>Jul 26 19:21:10 crestwood ./openser[27467]: releasing con 0x403a6cf8, state -1, fd=50, id=10
>Jul 26 19:21:10 crestwood ./openser[27467]: extra_data (nil)
>Jul 26 19:21:10 crestwood ./openser[27468]: tcp_read: EOF on 0x403c6f28, FD 52
>Jul 26 19:21:10 crestwood ./openser[27468]: tcp_read_req: EOF
>Jul 26 19:21:10 crestwood ./openser[27468]: releasing con 0x403c6f28, state -1, fd=52, id=11
>Jul 26 19:21:10 crestwood ./openser[27474]: tcp_main_loop: reader response= 403b6e10, -1 from 0
>Jul 26 19:21:10 crestwood ./openser[27474]: tcp_main_loop: destroying connection
>Jul 26 19:21:10 crestwood ./openser[27474]: tcp_main_loop: reader response= 403a6cf8, -1 from 1
>Jul 26 19:21:10 crestwood ./openser[27474]: tcp_main_loop: destroying connection
>Jul 26 19:21:10 crestwood ./openser[27468]: extra_data (nil)
>Jul 26 19:21:10 crestwood ./openser[27474]: tcp_main_loop: reader response= 403c6f28, -1 from 2
>Jul 26 19:21:10 crestwood ./openser[27474]: tcp_main_loop: destroying connection
>
>
More information about the Users
mailing list