[asterisk-bugs] [JIRA] (ASTERISK-30011) Testsuite: notify race in resource list subscription
Kevin Harwell (JIRA)
noreply at issues.asterisk.org
Mon Apr 4 13:15:57 CDT 2022
[ https://issues.asterisk.org/jira/browse/ASTERISK-30011?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Kevin Harwell updated ASTERISK-30011:
-------------------------------------
Status: Open (was: Triage)
> Testsuite: notify race in resource list subscription
> ----------------------------------------------------
>
> Key: ASTERISK-30011
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-30011
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Components: Tests/testsuite
> Affects Versions: GIT
> Reporter: Kevin Harwell
>
> Jenkins logged a failure for the following test:
> {{tests/channels/pjsip/subscriptions/rls/lists/nominal/mwi/batched/multiple_resources_single_change}}
> Based on the logs it appears Asterisk sent a re-transmission of a NOTIFY after receiving the 200 OK for it.
> {noformat}
> [Mar 29 20:16:23] VERBOSE[3549] res_pjsip_logger.c: <--- Transmitting SIP request (1545 bytes) to UDP:127.0.0.1:5061 --->
> NOTIFY sip:127.0.0.1:5061 SIP/2.0
> Via: SIP/2.0/UDP 127.0.0.1:5060;rport;branch=z9hG4bKPj2c867d59-7360-4682-8bf7-0250152762c8
> From: "sut" <sip:mail_list at 127.0.0.1>;tag=660e5373-48ad-4a8c-aaa2-55b5138e11fa
> To: "sipp" <sip:sipp at 127.0.0.1>;tag=3611SIPpTag001
> Contact: <sip:127.0.0.1:5060>
> Call-ID: 1-3611 at 127.0.0.1
> CSeq: 24690 NOTIFY
> Event: message-summary
> Subscription-State: active;expires=3594
> Allow-Events: presence, dialog, message-summary, refer
> Require: eventlist
> Max-Forwards: 70
> User-Agent: Asterisk PBX GIT-master-df22e5e
> Content-Type: multipart/related;type="application/rlmi+xml";boundary=fqkki
> Content-Length: 903
> --fqkki
> Content-ID: <baxee at 127.0.0.1>
> Content-Type: application/rlmi+xml
> Content-Length: 455
> <?xml version="1.0" encoding="UTF-8"?>
> <list xmlns="urn:ietf:params:xml:ns:rlmi" uri="sip:mail_list at 127.0.0.1:5061" version="3" fullState="false">
> <name>mail_list</name>
> <resource uri="sip:alice at 127.0.0.1:5061">
> <name>alice</name>
> <instance id="ukgvh" state="active" cid="hciuw at 127.0.0.1" />
> </resource>
> <resource uri="sip:bob at 127.0.0.1:5061">
> <name>bob</name>
> <instance id="tprqv" state="active" cid="gupto at 127.0.0.1" />
> </resource>
> </list>
> --fqkki
> Content-ID: <hciuw at 127.0.0.1>
> Content-Type: application/simple-message-summary
> Content-Length: 49
> Messages-Waiting: yes
> Voice-Message: 2/0 (0/0)
> --fqkki
> Content-ID: <gupto at 127.0.0.1>
> Content-Type: application/simple-message-summary
> Content-Length: 49
> Messages-Waiting: yes
> Voice-Message: 2/0 (0/0)
> --fqkki--
> [Mar 29 20:16:23] DEBUG[3549] res_pjsip_pubsub.c: evsub 0x7f8a2c003578 state ACTIVE event USER sub_tree 0x7f8a2c00cdd0 sub_tree state Normal
> [Mar 29 20:16:23] DEBUG[3549] res_pjsip_pubsub.c: Updating persistence for 'sipp->mail_list' prune on boot: no
> [Mar 29 20:16:23] VERBOSE[3548] res_pjsip_logger.c: <--- Received SIP response (353 bytes) from UDP:127.0.0.1:5061 --->
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 127.0.0.1:5060;rport;branch=z9hG4bKPj2c867d59-7360-4682-8bf7-0250152762c8
> From: "sut" <sip:mail_list at 127.0.0.1>;tag=660e5373-48ad-4a8c-aaa2-55b5138e11fa
> To: "sipp" <sip:sipp at 127.0.0.1>;tag=3611SIPpTag001
> Call-ID: 1-3611 at 127.0.0.1
> CSeq: 24690 NOTIFY
> Contact: <sip:127.0.0.1:5062;transport=UDP>
> Content-Length: 0
> [Mar 29 20:16:23] DEBUG[3548] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f8a2c006c48 for Response msg 200/NOTIFY/cseq=24690 (rdata0x7f8a100a66f8)
> [Mar 29 20:16:23] DEBUG[3548] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-0000002c associated with dialog dlg0x7f8a2c006c48
> [Mar 29 20:16:23] VERBOSE[3548] res_pjsip_logger.c: <--- Received SIP request (553 bytes) from UDP:127.0.0.1:5061 --->
> SUBSCRIBE sip:mail_list at 127.0.0.1:5061 SIP/2.0
> Via: SIP/2.0/UDP 127.0.0.1:5062;branch=z9hG4bK-3611-1-13
> From: sipp <sip:sipp at 127.0.0.1:5062>;tag=3611SIPpTag001
> To: sut <sip:mail_list at 127.0.0.1:5061>;tag=660e5373-48ad-4a8c-aaa2-55b5138e11fa
> Call-ID: 1-3611 at 127.0.0.1
> CSeq: 24691 SUBSCRIBE
> Contact: sip:sipp at 127.0.0.1:5062
> Max-Forwards: 70
> Subject: Performance Test
> Event: message-summary
> Supported: eventlist
> Accept: application/rlmi+xml
> Accept: application/simple-message-summary
> Accept: multipart/related
> Expires: 0
> Content-Length: 0
> [Mar 29 20:16:23] DEBUG[3548] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f8a2c006c48 for Request msg SUBSCRIBE/cseq=24691 (rdata0x7f8a100cbd08)
> [Mar 29 20:16:23] DEBUG[3548] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-0000002c associated with dialog dlg0x7f8a2c006c48
> [Mar 29 20:16:24] DEBUG[3548] res_pjsip/pjsip_message_filter.c: Sanitizing Request: sip:127.0.0.1:5061
> [Mar 29 20:16:24] DEBUG[3548] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:mail_list at 127.0.0.1
> [Mar 29 20:16:24] DEBUG[3548] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:sipp at 127.0.0.1
> [Mar 29 20:16:24] DEBUG[3548] res_pjsip/pjsip_message_filter.c: Sanitizing Contact header: sip:127.0.0.1:5060
> [Mar 29 20:16:24] VERBOSE[3548] res_pjsip_logger.c: <--- Transmitting SIP request (1545 bytes) to UDP:127.0.0.1:5061 --->
> NOTIFY sip:127.0.0.1:5061 SIP/2.0
> Via: SIP/2.0/UDP 127.0.0.1:5060;rport;branch=z9hG4bKPj2c867d59-7360-4682-8bf7-0250152762c8
> From: "sut" <sip:mail_list at 127.0.0.1>;tag=660e5373-48ad-4a8c-aaa2-55b5138e11fa
> To: "sipp" <sip:sipp at 127.0.0.1>;tag=3611SIPpTag001
> Contact: <sip:127.0.0.1:5060>
> Call-ID: 1-3611 at 127.0.0.1
> CSeq: 24690 NOTIFY
> Event: message-summary
> Subscription-State: active;expires=3594
> Allow-Events: presence, dialog, message-summary, refer
> Require: eventlist
> Max-Forwards: 70
> User-Agent: Asterisk PBX GIT-master-df22e5e
> Content-Type: multipart/related;type="application/rlmi+xml";boundary=fqkki
> Content-Length: 903
> --fqkki
> Content-ID: <baxee at 127.0.0.1>
> Content-Type: application/rlmi+xml
> Content-Length: 455
> <?xml version="1.0" encoding="UTF-8"?>
> <list xmlns="urn:ietf:params:xml:ns:rlmi" uri="sip:mail_list at 127.0.0.1:5061" version="3" fullState="false">
> <name>mail_list</name>
> <resource uri="sip:alice at 127.0.0.1:5061">
> <name>alice</name>
> <instance id="ukgvh" state="active" cid="hciuw at 127.0.0.1" />
> </resource>
> <resource uri="sip:bob at 127.0.0.1:5061">
> <name>bob</name>
> <instance id="tprqv" state="active" cid="gupto at 127.0.0.1" />
> </resource>
> </list>
> --fqkki
> Content-ID: <hciuw at 127.0.0.1>
> Content-Type: application/simple-message-summary
> Content-Length: 49
> Messages-Waiting: yes
> Voice-Message: 2/0 (0/0)
> --fqkki
> Content-ID: <gupto at 127.0.0.1>
> Content-Type: application/simple-message-summary
> Content-Length: 49
> Messages-Waiting: yes
> Voice-Message: 2/0 (0/0)
> --fqkki--
> {noformat}
> It could be the re-transmission timer is not being canceled in time.
--
This message was sent by Atlassian JIRA
(v6.2#6252)
More information about the asterisk-bugs
mailing list