[Users] via header not added when transport=TCP?

Erich Nahum nahum at watson.ibm.com
Wed Jul 27 01:35:54 CEST 2005 

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

-- 
Erich M. Nahum                  IBM T.J. Watson Research Center
Research Staff Member           P.O. Box 704
nahum at watson.ibm.com            Yorktown Heights NY 10598
-------------- next part --------------
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

-------------- next part --------------
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

-------------- next part --------------
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

        
-------------- next part --------------
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
-------------- next part --------------
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