[asterisk-bugs] [JIRA] (ASTERISK-24414) TCP connection state is processed before the SIP response hits the transaction layer

[John Bigelow (JIRA)]

    [ https://issues.asterisk.org/jira/browse/ASTERISK-24414?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=223014#comment-223014 ] 

John Bigelow commented on ASTERISK-24414:
-----------------------------------------

*Note*: When resolved, the testsuite test corresponding to https://reviewboard.asterisk.org/r/4077/ needs to be updated to remove the pause at the end of the SIPp scenario.

> TCP connection state is processed before the SIP response hits the transaction layer
> ------------------------------------------------------------------------------------
>
>                 Key: ASTERISK-24414
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-24414
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Resources/res_pjsip, Resources/res_pjsip_outbound_registration
>    Affects Versions: SVN, 13.0.0-beta2
>         Environment: Asterisk SVN branch 13 @ 425285, PJSIP
>            Reporter: John Bigelow
>         Attachments: full.txt
>
>
> As discussed with jcolp, a TCP connection state is processed before the SIP response hits the transaction layer.
> The attached full log shows outbound registrations that register and then are immediately unregistered. Note: The patch on ASTERISK-24411 is applied but does not impact this issue. Additionally I've add warning messages to simply log the response code and result of whether or not the response status is in the 200 code class.
> Snippet of full log:
> {noformat}
> [Oct 13 10:56:14] DEBUG[15242] res_pjsip_outbound_registration.c: REGISTER attempt 1 to 'sip:ua-ipv6-tcp@[::1]:5061;transport=tcp' with client 'sip:ua-ipv6-tcp@[::1]:5060;transport=tcp'
> [Oct 13 10:56:14] DEBUG[15242] pjsip: 	tcpc0xb317c954 .TCP client transport created
> [Oct 13 10:56:14] DEBUG[15242] pjsip: 	tcpc0xb317c954 .TCP transport ::1:50777 is connecting to ::1:5061...
> [Oct 13 10:56:14] VERBOSE[15242] res_pjsip_logger.c: <--- Transmitting SIP request (513 bytes) to TCP:::1:5061 --->
> REGISTER sip:ua-ipv6-tcp@[::1]:5061;transport=tcp SIP/2.0
> Via: SIP/2.0/TCP [::1]:5060;rport;branch=z9hG4bKPj24635a48-f3ac-4689-9dbb-9e99bd2c6e71;alias
> From: <sip:ua-ipv6-tcp@[::1]>;tag=25fe9ce2-05e1-4b3b-9305-fdf3a919b7b7
> To: <sip:ua-ipv6-tcp@[::1]>
> Call-ID: fd63e184-b584-43fe-88bf-8aec6f07ceae
> CSeq: 64827 REGISTER
> Contact: <sip:s@[::1]:5060;transport=TCP>
> Expires: 300
> Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, REFER, MESSAGE
> Content-Length:  0
> [Oct 13 10:56:14] DEBUG[15247] pjsip: 	tcpc0xb317c954 TCP transport ::1:50777 is connected to ::1:5061
> [Oct 13 10:56:14] VERBOSE[15247] res_pjsip_logger.c: <--- Received SIP response (380 bytes) from TCP:::1:5061 --->
> SIP/2.0 200 OK
> Via: SIP/2.0/TCP [::1]:5060;rport;branch=z9hG4bKPj24635a48-f3ac-4689-9dbb-9e99bd2c6e71;alias
> From: <sip:ua-ipv6-tcp@[::1]>;tag=25fe9ce2-05e1-4b3b-9305-fdf3a919b7b7
> To: <sip:ua-ipv6-tcp@[::1]>;tag=15346SIPpTag011
> Call-ID: fd63e184-b584-43fe-88bf-8aec6f07ceae
> CSeq: 64827 REGISTER
> Expires: 300
> Contact: <sip:[::1]:5061;transport=TCP>
> Content-Length:     0
> [Oct 13 10:56:14] WARNING[15242] res_pjsip_outbound_registration.c: RESPONSE CODE: '200'
> [Oct 13 10:56:14] WARNING[15242] res_pjsip_outbound_registration.c: STATUS IN CLASS: '1'
> [Oct 13 10:56:14] DEBUG[15242] res_pjsip_outbound_registration.c: Outbound registration to 'sip:ua-ipv6-tcp@[::1]:5061;transport=tcp' with client 'sip:ua-ipv6-tcp@[::1]:5060;transport=tcp' successful
> [Oct 13 10:56:14] DEBUG[15319] manager.c: Examining AMI event:
> Event: Registry
> Privilege: system,all
> ChannelType: PJSIP
> Username: sip:ua-ipv6-tcp@[::1]:5060;transport=tcp
> Domain: sip:ua-ipv6-tcp@[::1]:5061;transport=tcp
> Status: Registered
> [Oct 13 10:56:14] DEBUG[15319] manager.c: Running action 'PJSIPUnregister'
> [Oct 13 10:56:14] VERBOSE[15242] res_pjsip_logger.c: <--- Transmitting SIP request (400 bytes) to TCP:::1:5061 --->
> REGISTER sip:ua-ipv6-tcp@[::1]:5061;transport=tcp SIP/2.0
> Via: SIP/2.0/TCP [::1]:5060;rport;branch=z9hG4bKPj5c93fca5-01f7-49e0-9dc1-bf9ef3a370d1;alias
> From: <sip:ua-ipv6-tcp@[::1]>;tag=85be1bab-c91b-4afc-8c83-5866dadfad17
> To: <sip:ua-ipv6-tcp@[::1]>
> Call-ID: fd63e184-b584-43fe-88bf-8aec6f07ceae
> CSeq: 64828 REGISTER
> Contact: <sip:s@[::1]:5060;transport=TCP>
> Expires: 0
> Content-Length:  0
> [Oct 13 10:56:14] VERBOSE[15247] res_pjsip_logger.c: <--- Received SIP response (378 bytes) from TCP:::1:5061 --->
> SIP/2.0 200 OK
> Via: SIP/2.0/TCP [::1]:5060;rport;branch=z9hG4bKPj5c93fca5-01f7-49e0-9dc1-bf9ef3a370d1;alias
> From: <sip:ua-ipv6-tcp@[::1]>;tag=85be1bab-c91b-4afc-8c83-5866dadfad17
> To: <sip:ua-ipv6-tcp@[::1]>;tag=15346SIPpTag011
> Call-ID: fd63e184-b584-43fe-88bf-8aec6f07ceae
> CSeq: 64828 REGISTER
> Expires: 0
> Contact: <sip:[::1]:5061;transport=TCP>
> Content-Length:     0
> [Oct 13 10:56:14] DEBUG[15247] pjsip: 	tcpc0xb317c954 TCP connection closed
> [Oct 13 10:56:14] WARNING[15242] res_pjsip_outbound_registration.c: RESPONSE CODE: '503'
> [Oct 13 10:56:14] WARNING[15242] res_pjsip_outbound_registration.c: STATUS IN CLASS: '0'
> [Oct 13 10:56:14] WARNING[15242] res_pjsip_outbound_registration.c: Maximum retries reached when attempting outbound registration to 'sip:ua-ipv6-tcp@[::1]:5061;transport=tcp' with client 'sip:ua-ipv6-tcp@[::1]:5060;transport=tcp', stopping registration attempt
> [Oct 13 10:56:14] DEBUG[15247] pjsip: 	tcpc0xb317c954 TCP transport destroyed with reason 70016: End of file (PJ_EEOF)
> [Oct 13 10:56:14] DEBUG[15319] manager.c: Examining AMI event:
> Event: Registry
> Privilege: system,all
> ChannelType: PJSIP
> Username: sip:ua-ipv6-tcp@[::1]:5060;transport=tcp
> Domain: sip:ua-ipv6-tcp@[::1]:5061;transport=tcp
> Status: Rejected
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.2#6252)