2 Aug
2005
2 Aug
'05
5:21 p.m.
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@bronxville1
---
Call-ID: 1-26914@bronxville1
18c20
< Max-Forwards: 70
---
Max-Forwards: 16
21a24
P-hint: outbound
Thanks,
-Erich
------------------------------------------------------------------------
Session Initiation Protocol
Request-Line: INVITE sip:service@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@bronxville1:5060>;tag=1
SIP from address: sipp <sip:sipp@bronxville1:5060>
SIP tag: 1
To: sut <sip:service@10.0.1.41:5060>
Call-ID: 1-27019@bronxville1
CSeq: 1 INVITE
Contact: sip:sipp@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@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@bronxville1:5060>;tag=1
SIP from address: sipp <sip:sipp@bronxville1:5060>
SIP tag: 1
To: sut <sip:service@10.0.1.41:5060>
Call-ID: 1-28105@bronxville1
CSeq: 1 INVITE
Contact: sip:sipp@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@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@bronxville1:5060>;tag=1
SIP from address: sipp <sip:sipp@bronxville1:5060>
SIP tag: 1
To: sut <sip:service@10.0.1.41:5060>
Call-ID: 1-26885@bronxville1
CSeq: 1 INVITE
Contact: sip:sipp@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@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@bronxville1:5060>;tag=1
SIP from address: sipp <sip:sipp@bronxville1:5060>
SIP tag: 1
To: sut <sip:service@10.0.1.41:5060>
Call-ID: 1-26914@bronxville1
CSeq: 1 INVITE
Contact: sip:sipp@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@10.0.1.41:5060]
Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: to body [sut
<sip:service@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@10.0.1.41:5060]
Jul 26 19:21:06 crestwood ./openser[27466]: DEBUG: to body [sut
<sip:service@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@10.0.1.41:5060]
Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: to body [sut
<sip:service@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@10.0.1.41:5060]
Jul 26 19:21:07 crestwood ./openser[27467]: DEBUG: to body [sut
<sip:service@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@10.0.1.41:5060]
Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: to body [sut
<sip:service@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@10.0.1.41:5060]
Jul 26 19:21:08 crestwood ./openser[27468]: DEBUG: to body [sut
<sip:service@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