[asterisk-bugs] [JIRA] (ASTERISK-22217) TestSuite sip_hold test fails in SIPp scenarios on unexpected SIP INVITE requests

Matt Jordan (JIRA) noreply at issues.asterisk.org
Tue Jul 30 13:49:03 CDT 2013


     [ https://issues.asterisk.org/jira/browse/ASTERISK-22217?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Matt Jordan updated ASTERISK-22217:
-----------------------------------

    Description: 
It appears as if some re-INVITE messages are occurring - apparently to force directmedia - that weren't before. Yay.


{noformat}
Running ['tests/channels/SIP/sip_hold/run-test'] ...
[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... 
[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: Done.

[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:14:986	1375204274.986483: Aborting call on unexpected message for Call-Id '37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060': while pausing (index 6), received 'INVITE sip:phone_B at 127.0.0.3:5060;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK278ebec0
Max-Forwards: 70
From: "phone_A" <sip:phone_A at 127.0.0.1>;tag=as50c16487
To: <sip:127.0.0.3>;tag=1
Contact: <sip:phone_A at 127.0.0.1:5060>
Call-ID: 37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060
CSeq: 103 INVITE
User-Agent: Asterisk PBX SVN-trunk-r395686M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
X-asterisk-Info: SIP re-invite (External RTP bridge)
Content-Type: application/sdp
Content-Length: 267

v=0
o=root 1387452781 1387452782 IN IP4 127.0.0.2
s=Asterisk PBX SVN-trunk-r395686M
c=IN IP4 127.0.0.2
t=0 0
m=audio 2226 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
'.

[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_B_media_restrict.xml Failed [1]
[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_B_media_restrict.xml Failed
[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... 
[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: Done.

[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:14:988	1375204274.988396: Aborting call on unexpected message for Call-Id '1-7543 at 127.0.0.2': while expecting 'BYE' (index 6), received 'INVITE sip:phone_A at 127.0.0.2:5060 SIP/2.0
Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK0c48a3e2
Max-Forwards: 70
From: <sip:basicdial at 127.0.0.1:5060;user=phone>;tag=as004df771
To: phone_A <sip:phone_A at 127.0.0.2:5060>;tag=1
Contact: <sip:basicdial at 127.0.0.1:5060>
Call-ID: 1-7543 at 127.0.0.2
CSeq: 102 INVITE
User-Agent: Asterisk PBX SVN-trunk-r395686M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
X-asterisk-Info: SIP re-invite (External RTP bridge)
Content-Type: application/sdp
Content-Length: 268

v=0
o=root 1242229468 1242229469 IN IP4 127.0.0.1
s=Asterisk PBX SVN-trunk-r395686M
c=IN IP4 127.0.0.1
t=0 0
m=audio 10848 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
'.

[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_A.xml Failed [1]
[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_A.xml Failed
[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... 
[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: Done.

[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:15:193	1375204275.193873: Aborting call on unexpected message for Call-Id '1-7548 at 127.0.0.2': while expecting '180' (index 2), received 'SIP/2.0 603 Declined
Via: SIP/2.0/UDP 127.0.0.2:5060;branch=z9hG4bK-7548-1-0;received=127.0.0.2
From: phone_A <sip:phone_A at 127.0.0.2:5060>;tag=1
To: <sip:basicdial at 127.0.0.1:5060;user=phone>;tag=as4a10f805
Call-ID: 1-7548 at 127.0.0.2
CSeq: 1 INVITE
Server: Asterisk PBX SVN-trunk-r395686M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

'.

[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_A.xml Failed [1]
[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_A.xml Failed
[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... Done.

[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:15:688	1375204275.688405: Aborting call on unexpected message for Call-Id '37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060': while pausing (index 6), received 'INVITE sip:phone_B at 127.0.0.3:5060;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK7afe8fbf
Max-Forwards: 70
From: "phone_A" <sip:phone_A at 127.0.0.1>;tag=as50c16487
To: <sip:127.0.0.3>;tag=1
Contact: <sip:phone_A at 127.0.0.1:5060>
Call-ID: 37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060
CSeq: 104 INVITE
User-Agent: Asterisk PBX SVN-trunk-r395686M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
X-asterisk-Info: SIP re-invite (External RTP bridge)
Content-Type: application/sdp
Content-Length: 267

v=0
o=root 1387452781 1387452783 IN IP4 127.0.0.2
s=Asterisk PBX SVN-trunk-r395686M
c=IN IP4 127.0.0.2
t=0 0
m=audio 2226 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
'.

[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_B_IP_restrict.xml Failed [1]
[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_B_IP_restrict.xml Failed
[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... Done.

[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:15:803	1375204275.803695: Aborting call on unexpected message for Call-Id '1-8043 at 127.0.0.2': while expecting '100' (index 1), received 'SIP/2.0 503 Unavailable
Via: SIP/2.0/UDP 127.0.0.2:5060;branch=z9hG4bK-8043-1-0;received=127.0.0.2
From: phone_A <sip:phone_A at 127.0.0.2:5060>;tag=1
To: <sip:basicdial at 127.0.0.1:5060;user=phone>;tag=as44182b0f
Call-ID: 1-8043 at 127.0.0.2
CSeq: 1 INVITE
Server: Asterisk PBX SVN-trunk-r395686M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

'.

[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_A.xml Failed [1]
[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_A.xml Failed
[Jul 30 13:11:19] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... Done.

[Jul 30 13:11:19] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:19:599	1375204279.599578: Aborting call on unexpected message for Call-Id '37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060': while pausing (index 12), received 'INVITE sip:phone_B at 127.0.0.3:5060;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK66e8c55e
Max-Forwards: 70
From: phone_A <sip:phone_B at 127.0.0.1>;tag=as50c16487
To: phone_B <sip:phone_B at 127.0.0.3:5060>;tag=1
Contact: <sip:phone_A at 127.0.0.1:5060>
Call-ID: 37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060
CSeq: 105 INVITE
User-Agent: Asterisk PBX SVN-trunk-r395686M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
X-asterisk-Info: SIP re-invite (External RTP bridge)
Content-Type: application/sdp
Content-Length: 268

v=0
o=root 1387452781 1387452785 IN IP4 127.0.0.1
s=Asterisk PBX SVN-trunk-r395686M
c=IN IP4 127.0.0.1
t=0 0
m=audio 12068 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=recvonly
'.

[Jul 30 13:11:19] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_B_IP_media_restrict.xml Failed [1]
[Jul 30 13:11:19] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_B_IP_media_restrict.xml Failed
[Jul 30 13:11:20] ERROR[5035]: __main__:116 main: Failed to receive 6 MOH start events (received 0)
[Jul 30 13:11:20] ERROR[5035]: __main__:119 main: Failed to receive 6 MOH stop events (received 0)
[Jul 30 13:11:20] ERROR[5035]: __main__:122 main: Failed to receive 6 user test events (received 4)
{noformat}

  was:
It appears as if some re-INVITE messages are occurring that weren't before. Yay.


{noformat}
Running ['tests/channels/SIP/sip_hold/run-test'] ...
[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... 
[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: Done.

[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:14:986	1375204274.986483: Aborting call on unexpected message for Call-Id '37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060': while pausing (index 6), received 'INVITE sip:phone_B at 127.0.0.3:5060;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK278ebec0
Max-Forwards: 70
From: "phone_A" <sip:phone_A at 127.0.0.1>;tag=as50c16487
To: <sip:127.0.0.3>;tag=1
Contact: <sip:phone_A at 127.0.0.1:5060>
Call-ID: 37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060
CSeq: 103 INVITE
User-Agent: Asterisk PBX SVN-trunk-r395686M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
X-asterisk-Info: SIP re-invite (External RTP bridge)
Content-Type: application/sdp
Content-Length: 267

v=0
o=root 1387452781 1387452782 IN IP4 127.0.0.2
s=Asterisk PBX SVN-trunk-r395686M
c=IN IP4 127.0.0.2
t=0 0
m=audio 2226 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
'.

[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_B_media_restrict.xml Failed [1]
[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_B_media_restrict.xml Failed
[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... 
[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: Done.

[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:14:988	1375204274.988396: Aborting call on unexpected message for Call-Id '1-7543 at 127.0.0.2': while expecting 'BYE' (index 6), received 'INVITE sip:phone_A at 127.0.0.2:5060 SIP/2.0
Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK0c48a3e2
Max-Forwards: 70
From: <sip:basicdial at 127.0.0.1:5060;user=phone>;tag=as004df771
To: phone_A <sip:phone_A at 127.0.0.2:5060>;tag=1
Contact: <sip:basicdial at 127.0.0.1:5060>
Call-ID: 1-7543 at 127.0.0.2
CSeq: 102 INVITE
User-Agent: Asterisk PBX SVN-trunk-r395686M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
X-asterisk-Info: SIP re-invite (External RTP bridge)
Content-Type: application/sdp
Content-Length: 268

v=0
o=root 1242229468 1242229469 IN IP4 127.0.0.1
s=Asterisk PBX SVN-trunk-r395686M
c=IN IP4 127.0.0.1
t=0 0
m=audio 10848 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
'.

[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_A.xml Failed [1]
[Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_A.xml Failed
[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... 
[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: Done.

[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:15:193	1375204275.193873: Aborting call on unexpected message for Call-Id '1-7548 at 127.0.0.2': while expecting '180' (index 2), received 'SIP/2.0 603 Declined
Via: SIP/2.0/UDP 127.0.0.2:5060;branch=z9hG4bK-7548-1-0;received=127.0.0.2
From: phone_A <sip:phone_A at 127.0.0.2:5060>;tag=1
To: <sip:basicdial at 127.0.0.1:5060;user=phone>;tag=as4a10f805
Call-ID: 1-7548 at 127.0.0.2
CSeq: 1 INVITE
Server: Asterisk PBX SVN-trunk-r395686M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

'.

[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_A.xml Failed [1]
[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_A.xml Failed
[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... Done.

[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:15:688	1375204275.688405: Aborting call on unexpected message for Call-Id '37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060': while pausing (index 6), received 'INVITE sip:phone_B at 127.0.0.3:5060;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK7afe8fbf
Max-Forwards: 70
From: "phone_A" <sip:phone_A at 127.0.0.1>;tag=as50c16487
To: <sip:127.0.0.3>;tag=1
Contact: <sip:phone_A at 127.0.0.1:5060>
Call-ID: 37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060
CSeq: 104 INVITE
User-Agent: Asterisk PBX SVN-trunk-r395686M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
X-asterisk-Info: SIP re-invite (External RTP bridge)
Content-Type: application/sdp
Content-Length: 267

v=0
o=root 1387452781 1387452783 IN IP4 127.0.0.2
s=Asterisk PBX SVN-trunk-r395686M
c=IN IP4 127.0.0.2
t=0 0
m=audio 2226 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
'.

[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_B_IP_restrict.xml Failed [1]
[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_B_IP_restrict.xml Failed
[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... Done.

[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:15:803	1375204275.803695: Aborting call on unexpected message for Call-Id '1-8043 at 127.0.0.2': while expecting '100' (index 1), received 'SIP/2.0 503 Unavailable
Via: SIP/2.0/UDP 127.0.0.2:5060;branch=z9hG4bK-8043-1-0;received=127.0.0.2
From: phone_A <sip:phone_A at 127.0.0.2:5060>;tag=1
To: <sip:basicdial at 127.0.0.1:5060;user=phone>;tag=as44182b0f
Call-ID: 1-8043 at 127.0.0.2
CSeq: 1 INVITE
Server: Asterisk PBX SVN-trunk-r395686M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

'.

[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_A.xml Failed [1]
[Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_A.xml Failed
[Jul 30 13:11:19] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... Done.

[Jul 30 13:11:19] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:19:599	1375204279.599578: Aborting call on unexpected message for Call-Id '37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060': while pausing (index 12), received 'INVITE sip:phone_B at 127.0.0.3:5060;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK66e8c55e
Max-Forwards: 70
From: phone_A <sip:phone_B at 127.0.0.1>;tag=as50c16487
To: phone_B <sip:phone_B at 127.0.0.3:5060>;tag=1
Contact: <sip:phone_A at 127.0.0.1:5060>
Call-ID: 37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060
CSeq: 105 INVITE
User-Agent: Asterisk PBX SVN-trunk-r395686M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
X-asterisk-Info: SIP re-invite (External RTP bridge)
Content-Type: application/sdp
Content-Length: 268

v=0
o=root 1387452781 1387452785 IN IP4 127.0.0.1
s=Asterisk PBX SVN-trunk-r395686M
c=IN IP4 127.0.0.1
t=0 0
m=audio 12068 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=recvonly
'.

[Jul 30 13:11:19] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_B_IP_media_restrict.xml Failed [1]
[Jul 30 13:11:19] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_B_IP_media_restrict.xml Failed
[Jul 30 13:11:20] ERROR[5035]: __main__:116 main: Failed to receive 6 MOH start events (received 0)
[Jul 30 13:11:20] ERROR[5035]: __main__:119 main: Failed to receive 6 MOH stop events (received 0)
[Jul 30 13:11:20] ERROR[5035]: __main__:122 main: Failed to receive 6 user test events (received 4)
{noformat}

    
> TestSuite sip_hold test fails in SIPp scenarios on unexpected SIP INVITE requests
> ---------------------------------------------------------------------------------
>
>                 Key: ASTERISK-22217
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-22217
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Channels/chan_sip/General, Tests/testsuite
>            Reporter: Matt Jordan
>
> It appears as if some re-INVITE messages are occurring - apparently to force directmedia - that weren't before. Yay.
> {noformat}
> Running ['tests/channels/SIP/sip_hold/run-test'] ...
> [Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... 
> [Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: Done.
> [Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:14:986	1375204274.986483: Aborting call on unexpected message for Call-Id '37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060': while pausing (index 6), received 'INVITE sip:phone_B at 127.0.0.3:5060;transport=UDP SIP/2.0
> Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK278ebec0
> Max-Forwards: 70
> From: "phone_A" <sip:phone_A at 127.0.0.1>;tag=as50c16487
> To: <sip:127.0.0.3>;tag=1
> Contact: <sip:phone_A at 127.0.0.1:5060>
> Call-ID: 37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060
> CSeq: 103 INVITE
> User-Agent: Asterisk PBX SVN-trunk-r395686M
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
> Supported: replaces, timer
> X-asterisk-Info: SIP re-invite (External RTP bridge)
> Content-Type: application/sdp
> Content-Length: 267
> v=0
> o=root 1387452781 1387452782 IN IP4 127.0.0.2
> s=Asterisk PBX SVN-trunk-r395686M
> c=IN IP4 127.0.0.2
> t=0 0
> m=audio 2226 RTP/AVP 0 101
> a=rtpmap:0 PCMU/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:20
> a=sendrecv
> '.
> [Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_B_media_restrict.xml Failed [1]
> [Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_B_media_restrict.xml Failed
> [Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... 
> [Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: Done.
> [Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:14:988	1375204274.988396: Aborting call on unexpected message for Call-Id '1-7543 at 127.0.0.2': while expecting 'BYE' (index 6), received 'INVITE sip:phone_A at 127.0.0.2:5060 SIP/2.0
> Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK0c48a3e2
> Max-Forwards: 70
> From: <sip:basicdial at 127.0.0.1:5060;user=phone>;tag=as004df771
> To: phone_A <sip:phone_A at 127.0.0.2:5060>;tag=1
> Contact: <sip:basicdial at 127.0.0.1:5060>
> Call-ID: 1-7543 at 127.0.0.2
> CSeq: 102 INVITE
> User-Agent: Asterisk PBX SVN-trunk-r395686M
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
> Supported: replaces, timer
> X-asterisk-Info: SIP re-invite (External RTP bridge)
> Content-Type: application/sdp
> Content-Length: 268
> v=0
> o=root 1242229468 1242229469 IN IP4 127.0.0.1
> s=Asterisk PBX SVN-trunk-r395686M
> c=IN IP4 127.0.0.1
> t=0 0
> m=audio 10848 RTP/AVP 0 101
> a=rtpmap:0 PCMU/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:20
> a=sendrecv
> '.
> [Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_A.xml Failed [1]
> [Jul 30 13:11:14] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_A.xml Failed
> [Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... 
> [Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: Done.
> [Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:15:193	1375204275.193873: Aborting call on unexpected message for Call-Id '1-7548 at 127.0.0.2': while expecting '180' (index 2), received 'SIP/2.0 603 Declined
> Via: SIP/2.0/UDP 127.0.0.2:5060;branch=z9hG4bK-7548-1-0;received=127.0.0.2
> From: phone_A <sip:phone_A at 127.0.0.2:5060>;tag=1
> To: <sip:basicdial at 127.0.0.1:5060;user=phone>;tag=as4a10f805
> Call-ID: 1-7548 at 127.0.0.2
> CSeq: 1 INVITE
> Server: Asterisk PBX SVN-trunk-r395686M
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
> Supported: replaces, timer
> Content-Length: 0
> '.
> [Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_A.xml Failed [1]
> [Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_A.xml Failed
> [Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... Done.
> [Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:15:688	1375204275.688405: Aborting call on unexpected message for Call-Id '37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060': while pausing (index 6), received 'INVITE sip:phone_B at 127.0.0.3:5060;transport=UDP SIP/2.0
> Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK7afe8fbf
> Max-Forwards: 70
> From: "phone_A" <sip:phone_A at 127.0.0.1>;tag=as50c16487
> To: <sip:127.0.0.3>;tag=1
> Contact: <sip:phone_A at 127.0.0.1:5060>
> Call-ID: 37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060
> CSeq: 104 INVITE
> User-Agent: Asterisk PBX SVN-trunk-r395686M
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
> Supported: replaces, timer
> X-asterisk-Info: SIP re-invite (External RTP bridge)
> Content-Type: application/sdp
> Content-Length: 267
> v=0
> o=root 1387452781 1387452783 IN IP4 127.0.0.2
> s=Asterisk PBX SVN-trunk-r395686M
> c=IN IP4 127.0.0.2
> t=0 0
> m=audio 2226 RTP/AVP 0 101
> a=rtpmap:0 PCMU/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:20
> a=sendrecv
> '.
> [Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_B_IP_restrict.xml Failed [1]
> [Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_B_IP_restrict.xml Failed
> [Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... Done.
> [Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:15:803	1375204275.803695: Aborting call on unexpected message for Call-Id '1-8043 at 127.0.0.2': while expecting '100' (index 1), received 'SIP/2.0 503 Unavailable
> Via: SIP/2.0/UDP 127.0.0.2:5060;branch=z9hG4bK-8043-1-0;received=127.0.0.2
> From: phone_A <sip:phone_A at 127.0.0.2:5060>;tag=1
> To: <sip:basicdial at 127.0.0.1:5060;user=phone>;tag=as44182b0f
> Call-ID: 1-8043 at 127.0.0.2
> CSeq: 1 INVITE
> Server: Asterisk PBX SVN-trunk-r395686M
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
> Supported: replaces, timer
> Content-Length: 0
> '.
> [Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_A.xml Failed [1]
> [Jul 30 13:11:15] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_A.xml Failed
> [Jul 30 13:11:19] WARNING[5035]: asterisk.sipp:378 processEnded: Resolving remote host '127.0.0.1'... Done.
> [Jul 30 13:11:19] WARNING[5035]: asterisk.sipp:378 processEnded: 2013-07-30	13:11:19:599	1375204279.599578: Aborting call on unexpected message for Call-Id '37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060': while pausing (index 12), received 'INVITE sip:phone_B at 127.0.0.3:5060;transport=UDP SIP/2.0
> Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK66e8c55e
> Max-Forwards: 70
> From: phone_A <sip:phone_B at 127.0.0.1>;tag=as50c16487
> To: phone_B <sip:phone_B at 127.0.0.3:5060>;tag=1
> Contact: <sip:phone_A at 127.0.0.1:5060>
> Call-ID: 37f12a637c8d7f1b17769da73ecf6c75 at 127.0.0.1:5060
> CSeq: 105 INVITE
> User-Agent: Asterisk PBX SVN-trunk-r395686M
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
> Supported: replaces, timer
> X-asterisk-Info: SIP re-invite (External RTP bridge)
> Content-Type: application/sdp
> Content-Length: 268
> v=0
> o=root 1387452781 1387452785 IN IP4 127.0.0.1
> s=Asterisk PBX SVN-trunk-r395686M
> c=IN IP4 127.0.0.1
> t=0 0
> m=audio 12068 RTP/AVP 0 101
> a=rtpmap:0 PCMU/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:20
> a=recvonly
> '.
> [Jul 30 13:11:19] WARNING[5035]: asterisk.sipp:467 __scenario_callback: SIPp Scenario phone_B_IP_media_restrict.xml Failed [1]
> [Jul 30 13:11:19] WARNING[5035]: asterisk.sipp:475 __evaluate_scenario_results: SIPp Scenario phone_B_IP_media_restrict.xml Failed
> [Jul 30 13:11:20] ERROR[5035]: __main__:116 main: Failed to receive 6 MOH start events (received 0)
> [Jul 30 13:11:20] ERROR[5035]: __main__:119 main: Failed to receive 6 MOH stop events (received 0)
> [Jul 30 13:11:20] ERROR[5035]: __main__:122 main: Failed to receive 6 user test events (received 4)
> {noformat}

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.asterisk.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira



More information about the asterisk-bugs mailing list