Where music on hold is being played on answer is difficult to replicate. I’ll keep persevering on that one. But here is the debug information showing music on hold being started and stopped during call setup. As much as I read this debug information I cannot see what is triggering music on hold. In this example, the server’s IP address has been masked at 1.2.3.4 and the WAN IP address that both telephones sit behind is 4.3.2.1.
The server has recently been updated from version 11.5.1 to 11.8.1 and the problem has stayed.
[May 3 12:30:30] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:52548 --->
ˇINVITE sip:12101012@1.2.3.4:5060 SIP/2.0
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bK73bb97d4d5093cb8e45c40773ab681e2;rport
ˇFrom: <sip:12101010@192.168.2.230:5060>;tag=2686082741
ˇTo: "Chris A" <sip:12101012@sip.v.net>;tag=as48e4883b
ˇCall-ID: 55f6abe042b3103748b652a55cb011d3@sip.v.net
ˇCSeq: 103 INVITE
ˇContact: <sip:12101010@192.168.2.230:5060>
ˇMax-Forwards: 70
ˇUser-Agent: N300 IP/42.076.00.000.000
ˇSupported: replaces
ˇAllow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, REFER, SUBSCRIBE, NOTIFY
ˇContent-Type: application/sdp
ˇContent-Length: 146
ˇ
ˇv=0
ˇo=12101010 5020 20 IN IP4 192.168.2.230
ˇs=Mapping
ˇc=IN IP4 192.168.2.230
ˇt=0 0
ˇm=audio 5020 RTP/AVP 8
ˇa=rtpmap:8 PCMA/8000
ˇa=sendonly
ˇ<------------->
[May 3 12:30:30] VERBOSE[12432] chan_sip.c: --- (13 headers 8 lines) ---
[May 3 12:30:30] VERBOSE[12432][C-000000d1] chan_sip.c: Sending to 4.3.2.1:52548 (NAT)
[May 3 12:30:30] VERBOSE[12432][C-000000d1] chan_sip.c: Found RTP audio format 8
[May 3 12:30:30] VERBOSE[12432][C-000000d1] chan_sip.c: Found audio description format PCMA for ID 8
[May 3 12:30:30] VERBOSE[12432][C-000000d1] chan_sip.c: Capabilities: us - (ulaw|alaw|g726), peer - audio=(alaw)/video=(nothing)/text=(nothing), combined - (alaw)
[May 3 12:30:30] VERBOSE[12432][C-000000d1] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x0 (nothing), combined - 0x0 (nothing)
[May 3 12:30:30] VERBOSE[12432][C-000000d1] chan_sip.c: Peer audio RTP is at port 192.168.2.230:5020
[May 3 12:30:30] VERBOSE[12432][C-000000d1] chan_sip.c:
ˇ<--- Transmitting (NAT) to 4.3.2.1:52548 --->
ˇSIP/2.0 100 Trying
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bK73bb97d4d5093cb8e45c40773ab681e2;received=4.3.2.1;rport=52548
ˇFrom: <sip:12101010@192.168.2.230:5060>;tag=2686082741
ˇTo: "Chris A" <sip:12101012@sip.v.net>;tag=as48e4883b
ˇCall-ID: 55f6abe042b3103748b652a55cb011d3@sip.v.net
ˇCSeq: 103 INVITE
ˇServer: v Exchange (Asterisk 11)
ˇAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ˇSupported: replaces, timer
ˇContact: <sip:12101012@1.2.3.4:5060>
ˇContent-Length: 0
ˇ
ˇ
ˇ<------------>
[May 3 12:30:30] VERBOSE[12432][C-000000d1] chan_sip.c: Audio is at 11088
[May 3 12:30:30] VERBOSE[12432][C-000000d1] chan_sip.c: Adding codec 100004 (alaw) to SDP
[May 3 12:30:30] VERBOSE[12432][C-000000d1] chan_sip.c:
ˇ<--- Reliably Transmitting (NAT) to 4.3.2.1:52548 --->
ˇSIP/2.0 200 OK
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bK73bb97d4d5093cb8e45c40773ab681e2;received=4.3.2.1;rport=52548
ˇFrom: <sip:12101010@192.168.2.230:5060>;tag=2686082741
ˇTo: "Chris A" <sip:12101012@sip.v.net>;tag=as48e4883b
ˇCall-ID: 55f6abe042b3103748b652a55cb011d3@sip.v.net
ˇCSeq: 103 INVITE
ˇServer: v Exchange (Asterisk 11)
ˇAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ˇSupported: replaces, timer
ˇContact: <sip:12101012@1.2.3.4:5060>
ˇContent-Type: application/sdp
ˇContent-Length: 179
ˇ
ˇv=0
ˇo=root 1513933244 1513933245 IN IP4 1.2.3.4
ˇs=Asterisk PBX 11.8.1
ˇc=IN IP4 1.2.3.4
ˇt=0 0
ˇm=audio 11088 RTP/AVP 8
ˇa=rtpmap:8 PCMA/8000
ˇa=ptime:20
ˇa=recvonly
ˇ
ˇ<------------>
[May 3 12:30:30] VERBOSE[27202][C-000000d1] res_musiconhold.c: -- Started music on hold, class 'default', on SIP/12101012-00000181
[May 3 12:30:30] VERBOSE[12432] chan_sip.c: Retransmitting #1 (NAT) to 4.3.2.1:52548:
ˇSIP/2.0 200 OK
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bK73bb97d4d5093cb8e45c40773ab681e2;received=4.3.2.1;rport=52548
ˇFrom: <sip:12101010@192.168.2.230:5060>;tag=2686082741
ˇTo: "Chris A" <sip:12101012@sip.v.net>;tag=as48e4883b
ˇCall-ID: 55f6abe042b3103748b652a55cb011d3@sip.v.net
ˇCSeq: 103 INVITE
ˇServer: v Exchange (Asterisk 11)
ˇAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ˇSupported: replaces, timer
ˇContact: <sip:12101012@1.2.3.4:5060>
ˇContent-Type: application/sdp
ˇContent-Length: 179
ˇ
ˇv=0
ˇo=root 1513933244 1513933245 IN IP4 1.2.3.4
ˇs=Asterisk PBX 11.8.1
ˇc=IN IP4 1.2.3.4
ˇt=0 0
ˇm=audio 11088 RTP/AVP 8
ˇa=rtpmap:8 PCMA/8000
ˇa=ptime:20
ˇa=recvonly
ˇ
ˇ---
[May 3 12:30:30] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:52548 --->
ˇACK sip:12101012@1.2.3.4:5060 SIP/2.0
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bKc2fb9a016720ab88b93b33ced01ea139;rport
ˇFrom: <sip:12101010@192.168.2.230:5060>;tag=2686082741
ˇTo: "Chris A" <sip:12101012@sip.v.net>;tag=as48e4883b
ˇCall-ID: 55f6abe042b3103748b652a55cb011d3@sip.v.net
ˇCSeq: 103 ACK
ˇContact: <sip:12101010@192.168.2.230:5060>
ˇMax-Forwards: 70
ˇUser-Agent: N300 IP/42.076.00.000.000
ˇContent-Length: 0
ˇ
ˇ<------------->
[May 3 12:30:30] VERBOSE[12432] chan_sip.c: --- (10 headers 0 lines) ---
[May 3 12:30:30] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:52548 --->
ˇ
ˇ
ˇ<------------->
[May 3 12:30:30] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:52548 --->
ˇACK sip:12101012@1.2.3.4:5060 SIP/2.0
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bK521b1ae0d2ab11ca116d0f86779a232c;rport
ˇFrom: <sip:12101010@192.168.2.230:5060>;tag=2686082741
ˇTo: "Chris A" <sip:12101012@sip.v.net>;tag=as48e4883b
ˇCall-ID: 55f6abe042b3103748b652a55cb011d3@sip.v.net
ˇCSeq: 103 ACK
ˇContact: <sip:12101010@192.168.2.230:5060>
ˇMax-Forwards: 70
ˇUser-Agent: N300 IP/42.076.00.000.000
ˇContent-Length: 0
ˇ
ˇ<------------->
[May 3 12:30:30] VERBOSE[12432] chan_sip.c: --- (10 headers 0 lines) ---
[May 3 12:30:30] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:50044 --->
ˇ
ˇ<------------->
[May 3 12:30:34] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:52548 --->
ˇREGISTER sip:sip.v.net SIP/2.0
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bK5f6bd9eaf14bde63d31e1377df8fb376;rport
ˇFrom: "1210 1010" <sip:12101010@sip.v.net>;tag=4173783066
ˇTo: "1210 1010" <sip:12101010@sip.v.net>
ˇCall-ID: 2890711642@192_168_2_230
ˇCSeq: 11725 REGISTER
ˇContact: <sip:12101010@192.168.2.230:5060>
ˇMax-Forwards: 70
ˇUser-Agent: N300 IP/42.076.00.000.000
ˇExpires: 180
ˇAllow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, REFER, SUBSCRIBE, NOTIFY
ˇContent-Length: 0
ˇ
ˇ<------------->
[May 3 12:30:34] VERBOSE[12432] chan_sip.c: --- (12 headers 0 lines) ---
[May 3 12:30:34] VERBOSE[12432] chan_sip.c: Sending to 4.3.2.1:52548 (no NAT)
[May 3 12:30:34] VERBOSE[12432] chan_sip.c: Sending to 4.3.2.1:52548 (no NAT)
[May 3 12:30:34] VERBOSE[12432] chan_sip.c:
ˇ<--- Transmitting (NAT) to 4.3.2.1:52548 --->
ˇSIP/2.0 401 Unauthorized
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bK5f6bd9eaf14bde63d31e1377df8fb376;received=4.3.2.1;rport=52548
ˇFrom: "1210 1010" <sip:12101010@sip.v.net>;tag=4173783066
ˇTo: "1210 1010" <sip:12101010@sip.v.net>;tag=as00c460d8
ˇCall-ID: 2890711642@192_168_2_230
ˇCSeq: 11725 REGISTER
ˇServer: v Exchange (Asterisk 11)
ˇAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ˇSupported: replaces, timer
ˇWWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="2e2ab69e"
ˇContent-Length: 0
ˇ
ˇ
ˇ<------------>
[May 3 12:30:34] VERBOSE[12432] chan_sip.c: Scheduling destruction of SIP dialog '2890711642@192_168_2_230' in 32000 ms (Method: REGISTER)
[May 3 12:30:34] SECURITY[12414] res_security_log.c: SecurityEvent="ChallengeSent",EventTV="1399116634-719271",Severity="Informational",Service="SIP",EventVersion="1",AccountID="12101010",SessionID="0xb741f3bc",LocalAddress="IPV4/UDP/1.2.3.4/5060",RemoteAddress="IPV4/UDP/4.3.2.1/5060",Challenge="2e2ab69e"
[May 3 12:30:34] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:52548 --->
ˇREGISTER sip:sip.v.net SIP/2.0
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bK42b492a4f3036879570aa1ae6d7594da;rport
ˇFrom: "1210 1010" <sip:12101010@sip.v.net>;tag=4173783066
ˇTo: "1210 1010" <sip:12101010@sip.v.net>
ˇCall-ID: 2890711642@192_168_2_230
ˇCSeq: 11726 REGISTER
ˇContact: <sip:12101010@192.168.2.230:5060>
ˇAuthorization: Digest username="12101010", realm="asterisk", algorithm=MD5, uri="sip:sip.v.net", nonce="2e2ab69e", response="324c8b4f2200c510b9a47bf113855b55"
ˇMax-Forwards: 70
ˇUser-Agent: N300 IP/42.076.00.000.000
ˇExpires: 180
ˇAllow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, REFER, SUBSCRIBE, NOTIFY
ˇContent-Length: 0
ˇ
ˇ<------------->
[May 3 12:30:34] VERBOSE[12432] chan_sip.c: --- (13 headers 0 lines) ---
[May 3 12:30:34] VERBOSE[12432] chan_sip.c: Sending to 4.3.2.1:52548 (NAT)
[May 3 12:30:34] VERBOSE[12432] chan_sip.c: Reliably Transmitting (NAT) to 4.3.2.1:52548:
ˇOPTIONS sip:12101010@192.168.2.230:5060 SIP/2.0
ˇVia: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bK4adf6000;rport
ˇMax-Forwards: 70
ˇFrom: "Unknown" <sip:Unknown@1.2.3.4>;tag=as75dfe6bb
ˇTo: <sip:12101010@192.168.2.230:5060>
ˇContact: <sip:Unknown@1.2.3.4:5060>
ˇCall-ID: 5cd385ce676e60c159e968345277fcfc@1.2.3.4:5060
ˇCSeq: 102 OPTIONS
ˇUser-Agent: v Exchange (Asterisk 11)
ˇDate: Sat, 03 May 2014 11:30:34 GMT
ˇAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ˇSupported: replaces, timer
ˇContent-Length: 0
ˇ
ˇ
ˇ---
[May 3 12:30:34] VERBOSE[12432] chan_sip.c:
ˇ<--- Transmitting (NAT) to 4.3.2.1:52548 --->
ˇSIP/2.0 200 OK
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bK42b492a4f3036879570aa1ae6d7594da;received=4.3.2.1;rport=52548
ˇFrom: "1210 1010" <sip:12101010@sip.v.net>;tag=4173783066
ˇTo: "1210 1010" <sip:12101010@sip.v.net>;tag=as00c460d8
ˇCall-ID: 2890711642@192_168_2_230
ˇCSeq: 11726 REGISTER
ˇServer: v Exchange (Asterisk 11)
ˇAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ˇSupported: replaces, timer
ˇExpires: 180
ˇContact: <sip:12101010@192.168.2.230:5060>;expires=180
ˇDate: Sat, 03 May 2014 11:30:34 GMT
ˇContent-Length: 0
ˇ
ˇ
ˇ<------------>
[May 3 12:30:34] VERBOSE[12432] chan_sip.c: Scheduling destruction of SIP dialog '043d62477dbf4822545b63356f929f70@sip.v.net' in 6400 ms (Method: NOTIFY)
[May 3 12:30:34] VERBOSE[12432] chan_sip.c: Reliably Transmitting (NAT) to 4.3.2.1:52548:
ˇNOTIFY sip:12101010@192.168.2.230:5060 SIP/2.0
ˇVia: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bK0ae1909b;rport
ˇMax-Forwards: 70
ˇFrom: "Unknown" <sip:Unknown@sip.v.net>;tag=as33f35e26
ˇTo: <sip:12101010@192.168.2.230:5060>
ˇContact: <sip:Unknown@1.2.3.4:5060>
ˇCall-ID: 043d62477dbf4822545b63356f929f70@sip.v.net
ˇCSeq: 102 NOTIFY
ˇUser-Agent: v Exchange (Asterisk 11)
ˇEvent: message-summary
ˇContent-Type: application/simple-message-summary
ˇContent-Length: 89
ˇ
ˇMessages-Waiting: no
ˇMessage-Account: sip:1901@sip.v.net
ˇVoice-Message: 0/7 (0/0)
ˇ
ˇ---
[May 3 12:30:34] VERBOSE[12432] chan_sip.c: Scheduling destruction of SIP dialog '2890711642@192_168_2_230' in 32000 ms (Method: REGISTER)
[May 3 12:30:34] SECURITY[12414] res_security_log.c: SecurityEvent="SuccessfulAuth",EventTV="1399116634-812462",Severity="Informational",Service="SIP",EventVersion="1",AccountID="12101010",SessionID="0xb741f3bc",LocalAddress="IPV4/UDP/1.2.3.4/5060",RemoteAddress="IPV4/UDP/4.3.2.1/5060",UsingPassword="1"
[May 3 12:30:34] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:52548 --->
ˇSIP/2.0 486 Busy Here
ˇVia: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bK4adf6000;rport=5060
ˇFrom: "Unknown" <sip:Unknown@1.2.3.4>;tag=as75dfe6bb
ˇTo: <sip:12101010@192.168.2.230:5060>
ˇCall-ID: 5cd385ce676e60c159e968345277fcfc@1.2.3.4:5060
ˇCSeq: 102 OPTIONS
ˇUser-Agent: N300 IP/42.076.00.000.000
ˇContent-Length: 0
ˇ
ˇ<------------->
[May 3 12:30:34] VERBOSE[12432] chan_sip.c: --- (8 headers 0 lines) ---
[May 3 12:30:34] VERBOSE[12432] chan_sip.c: Really destroying SIP dialog '5cd385ce676e60c159e968345277fcfc@1.2.3.4:5060' Method: OPTIONS
[May 3 12:30:34] VERBOSE[12432] chan_sip.c: Retransmitting #1 (NAT) to 4.3.2.1:52548:
ˇNOTIFY sip:12101010@192.168.2.230:5060 SIP/2.0
ˇVia: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bK0ae1909b;rport
ˇMax-Forwards: 70
ˇFrom: "Unknown" <sip:Unknown@sip.v.net>;tag=as33f35e26
ˇTo: <sip:12101010@192.168.2.230:5060>
ˇContact: <sip:Unknown@1.2.3.4:5060>
ˇCall-ID: 043d62477dbf4822545b63356f929f70@sip.v.net
ˇCSeq: 102 NOTIFY
ˇUser-Agent: v Exchange (Asterisk 11)
ˇEvent: message-summary
ˇContent-Type: application/simple-message-summary
ˇContent-Length: 89
ˇ
ˇMessages-Waiting: no
ˇMessage-Account: sip:1901@sip.v.net
ˇVoice-Message: 0/7 (0/0)
ˇ
ˇ---
[May 3 12:30:34] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:52548 --->
ˇSIP/2.0 200 OK
ˇVia: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bK0ae1909b;rport=5060
ˇFrom: "Unknown" <sip:Unknown@sip.v.net>;tag=as33f35e26
ˇTo: <sip:12101010@192.168.2.230:5060>;tag=ar22g24d37
ˇCall-ID: 043d62477dbf4822545b63356f929f70@sip.v.net
ˇCSeq: 102 NOTIFY
ˇUser-Agent: N300 IP/42.076.00.000.000
ˇContent-Length: 0
ˇ
ˇ<------------->
[May 3 12:30:34] VERBOSE[12432] chan_sip.c: --- (8 headers 0 lines) ---
[May 3 12:30:34] VERBOSE[12432] chan_sip.c: Really destroying SIP dialog '043d62477dbf4822545b63356f929f70@sip.v.net' Method: NOTIFY
[May 3 12:30:35] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:52548 --->
ˇSIP/2.0 200 OK
ˇVia: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bK0ae1909b;rport=5060
ˇFrom: "Unknown" <sip:Unknown@sip.v.net>;tag=as33f35e26
ˇTo: <sip:12101010@192.168.2.230:5060>;tag=ar22g24d37
ˇCall-ID: 043d62477dbf4822545b63356f929f70@sip.v.net
ˇCSeq: 102 NOTIFY
ˇUser-Agent: N300 IP/42.076.00.000.000
ˇContent-Length: 0
ˇ
ˇ<------------->
[May 3 12:30:35] VERBOSE[12432] chan_sip.c: --- (8 headers 0 lines) ---
[May 3 12:30:36] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:52548 --->
ˇINVITE sip:12101012@1.2.3.4:5060 SIP/2.0
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bKad5e96f75d58e327ac23408f8e7a375;rport
ˇFrom: <sip:12101010@192.168.2.230:5060>;tag=2686082741
ˇTo: "Chris A" <sip:12101012@sip.v.net>;tag=as48e4883b
ˇCall-ID: 55f6abe042b3103748b652a55cb011d3@sip.v.net
ˇCSeq: 104 INVITE
ˇContact: <sip:12101010@192.168.2.230:5060>
ˇMax-Forwards: 70
ˇUser-Agent: N300 IP/42.076.00.000.000
ˇSupported: replaces
ˇAllow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, REFER, SUBSCRIBE, NOTIFY
ˇContent-Type: application/sdp
ˇContent-Length: 202
ˇ
ˇv=0
ˇo=12101010 5020 21 IN IP4 192.168.2.230
ˇs=Mapping
ˇc=IN IP4 192.168.2.230
ˇt=0 0
ˇm=audio 5020 RTP/AVP 8 101
ˇa=rtpmap:8 PCMA/8000
ˇa=rtpmap:101 telephone-event/8000
ˇa=fmtp:101 0-16
ˇa=ptime:20
ˇ<------------->
[May 3 12:30:36] VERBOSE[12432] chan_sip.c: --- (13 headers 10 lines) ---
[May 3 12:30:36] VERBOSE[12432][C-000000d1] chan_sip.c: Sending to 4.3.2.1:52548 (NAT)
[May 3 12:30:36] VERBOSE[12432][C-000000d1] chan_sip.c: Found RTP audio format 8
[May 3 12:30:36] VERBOSE[12432][C-000000d1] chan_sip.c: Found RTP audio format 101
[May 3 12:30:36] VERBOSE[12432][C-000000d1] chan_sip.c: Found audio description format PCMA for ID 8
[May 3 12:30:36] VERBOSE[12432][C-000000d1] chan_sip.c: Found audio description format telephone-event for ID 101
[May 3 12:30:36] VERBOSE[12432][C-000000d1] chan_sip.c: Capabilities: us - (ulaw|alaw|g726), peer - audio=(alaw)/video=(nothing)/text=(nothing), combined - (alaw)
[May 3 12:30:36] VERBOSE[12432][C-000000d1] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[May 3 12:30:36] VERBOSE[12432][C-000000d1] chan_sip.c: Peer audio RTP is at port 192.168.2.230:5020
[May 3 12:30:36] VERBOSE[12432][C-000000d1] chan_sip.c:
ˇ<--- Transmitting (NAT) to 4.3.2.1:52548 --->
ˇSIP/2.0 100 Trying
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bKad5e96f75d58e327ac23408f8e7a375;received=4.3.2.1;rport=52548
ˇFrom: <sip:12101010@192.168.2.230:5060>;tag=2686082741
ˇTo: "Chris A" <sip:12101012@sip.v.net>;tag=as48e4883b
ˇCall-ID: 55f6abe042b3103748b652a55cb011d3@sip.v.net
ˇCSeq: 104 INVITE
ˇServer: v Exchange (Asterisk 11)
ˇAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ˇSupported: replaces, timer
ˇContact: <sip:12101012@1.2.3.4:5060>
ˇContent-Length: 0
ˇ
ˇ
ˇ<------------>
[May 3 12:30:36] VERBOSE[12432][C-000000d1] chan_sip.c: Audio is at 11088
[May 3 12:30:36] VERBOSE[12432][C-000000d1] chan_sip.c: Adding codec 100004 (alaw) to SDP
[May 3 12:30:36] VERBOSE[12432][C-000000d1] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[May 3 12:30:36] VERBOSE[12432][C-000000d1] chan_sip.c:
ˇ<--- Reliably Transmitting (NAT) to 4.3.2.1:52548 --->
ˇSIP/2.0 200 OK
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bKad5e96f75d58e327ac23408f8e7a375;received=4.3.2.1;rport=52548
ˇFrom: <sip:12101010@192.168.2.230:5060>;tag=2686082741
ˇTo: "Chris A" <sip:12101012@sip.v.net>;tag=as48e4883b
ˇCall-ID: 55f6abe042b3103748b652a55cb011d3@sip.v.net
ˇCSeq: 104 INVITE
ˇServer: v Exchange (Asterisk 11)
ˇAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ˇSupported: replaces, timer
ˇContact: <sip:12101012@1.2.3.4:5060>
ˇContent-Type: application/sdp
ˇContent-Length: 235
ˇ
ˇv=0
ˇo=root 1513933244 1513933246 IN IP4 1.2.3.4
ˇs=Asterisk PBX 11.8.1
ˇc=IN IP4 1.2.3.4
ˇt=0 0
ˇm=audio 11088 RTP/AVP 8 101
ˇa=rtpmap:8 PCMA/8000
ˇa=rtpmap:101 telephone-event/8000
ˇa=fmtp:101 0-16
ˇa=ptime:20
ˇa=sendrecv
ˇ
ˇ<------------>
[May 3 12:30:36] VERBOSE[27202][C-000000d1] res_musiconhold.c: -- Stopped music on hold on SIP/12101012-00000181
[May 3 12:30:36] VERBOSE[12432] chan_sip.c: Retransmitting #1 (NAT) to 4.3.2.1:52548:
ˇSIP/2.0 200 OK
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bKad5e96f75d58e327ac23408f8e7a375;received=4.3.2.1;rport=52548
ˇFrom: <sip:12101010@192.168.2.230:5060>;tag=2686082741
ˇTo: "Chris A" <sip:12101012@sip.v.net>;tag=as48e4883b
ˇCall-ID: 55f6abe042b3103748b652a55cb011d3@sip.v.net
ˇCSeq: 104 INVITE
ˇServer: v Exchange (Asterisk 11)
ˇAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ˇSupported: replaces, timer
ˇContact: <sip:12101012@1.2.3.4:5060>
ˇContent-Type: application/sdp
ˇContent-Length: 235
ˇ
ˇv=0
ˇo=root 1513933244 1513933246 IN IP4 1.2.3.4
ˇs=Asterisk PBX 11.8.1
ˇc=IN IP4 1.2.3.4
ˇt=0 0
ˇm=audio 11088 RTP/AVP 8 101
ˇa=rtpmap:8 PCMA/8000
ˇa=rtpmap:101 telephone-event/8000
ˇa=fmtp:101 0-16
ˇa=ptime:20
ˇa=sendrecv
ˇ
ˇ---
[May 3 12:30:36] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:52548 --->
ˇACK sip:12101012@1.2.3.4:5060 SIP/2.0
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bK56ce7abe234453686ad237c66766540;rport
ˇFrom: <sip:12101010@192.168.2.230:5060>;tag=2686082741
ˇTo: "Chris A" <sip:12101012@sip.v.net>;tag=as48e4883b
ˇCall-ID: 55f6abe042b3103748b652a55cb011d3@sip.v.net
ˇCSeq: 104 ACK
ˇContact: <sip:12101010@192.168.2.230:5060>
ˇMax-Forwards: 70
ˇUser-Agent: N300 IP/42.076.00.000.000
ˇContent-Length: 0
ˇ
ˇ<------------->
[May 3 12:30:36] VERBOSE[12432] chan_sip.c: --- (10 headers 0 lines) ---
[May 3 12:30:36] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:52548 --->
ˇ
ˇ
ˇ<------------->
[May 3 12:30:36] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:52548 --->
ˇACK sip:12101012@1.2.3.4:5060 SIP/2.0
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bK96af1570dc919172662ead274d37cc;rport
ˇFrom: <sip:12101010@192.168.2.230:5060>;tag=2686082741
ˇTo: "Chris A" <sip:12101012@sip.v.net>;tag=as48e4883b
ˇCall-ID: 55f6abe042b3103748b652a55cb011d3@sip.v.net
ˇCSeq: 104 ACK
ˇContact: <sip:12101010@192.168.2.230:5060>
ˇMax-Forwards: 70
ˇUser-Agent: N300 IP/42.076.00.000.000
ˇContent-Length: 0
ˇ
ˇ<------------->
[May 3 12:30:36] VERBOSE[12432] chan_sip.c: --- (10 headers 0 lines) ---
[May 3 12:30:37] VERBOSE[12432] chan_sip.c: Reliably Transmitting (NAT) to 192.168.2.11:49340:
ˇOPTIONS sip:12101012@192.168.2.11:49340;ob SIP/2.0
ˇVia: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bK1eb1991c;rport
ˇMax-Forwards: 70
ˇFrom: "Unknown" <sip:Unknown@1.2.3.4>;tag=as4ca4db16
ˇTo: <sip:12101012@192.168.2.11:49340;ob>
ˇContact: <sip:Unknown@1.2.3.4:5060>
ˇCall-ID: 5fdcd4bb7a087cb232c2de61595dbcff@1.2.3.4:5060
ˇCSeq: 102 OPTIONS
ˇUser-Agent: v Exchange (Asterisk 11)
ˇDate: Sat, 03 May 2014 11:30:37 GMT
ˇAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ˇSupported: replaces, timer
ˇContent-Length: 0
ˇ
ˇ
ˇ---
[May 3 12:30:37] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:52548 --->
ˇBYE sip:12101012@1.2.3.4:5060 SIP/2.0
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bK5031d2c01115a09be5950215d786b548;rport
ˇFrom: <sip:12101010@192.168.2.230:5060>;tag=2686082741
ˇTo: "Chris A" <sip:12101012@sip.v.net>;tag=as48e4883b
ˇCall-ID: 55f6abe042b3103748b652a55cb011d3@sip.v.net
ˇCSeq: 105 BYE
ˇContact: <sip:12101010@192.168.2.230:5060>
ˇMax-Forwards: 70
ˇUser-Agent: N300 IP/42.076.00.000.000
ˇContent-Length: 0
ˇ
ˇ<------------->
[May 3 12:30:37] VERBOSE[12432] chan_sip.c: --- (10 headers 0 lines) ---
[May 3 12:30:37] VERBOSE[12432][C-000000d1] chan_sip.c: Sending to 4.3.2.1:52548 (NAT)
[May 3 12:30:37] VERBOSE[12432][C-000000d1] chan_sip.c: Scheduling destruction of SIP dialog '55f6abe042b3103748b652a55cb011d3@sip.v.net' in 6400 ms (Method: BYE)
[May 3 12:30:37] VERBOSE[12432][C-000000d1] chan_sip.c:
ˇ<--- Transmitting (NAT) to 4.3.2.1:52548 --->
ˇSIP/2.0 200 OK
ˇVia: SIP/2.0/UDP 192.168.2.230:5060;branch=z9hG4bK5031d2c01115a09be5950215d786b548;received=4.3.2.1;rport=52548
ˇFrom: <sip:12101010@192.168.2.230:5060>;tag=2686082741
ˇTo: "Chris A" <sip:12101012@sip.v.net>;tag=as48e4883b
ˇCall-ID: 55f6abe042b3103748b652a55cb011d3@sip.v.net
ˇCSeq: 105 BYE
ˇServer: v Exchange (Asterisk 11)
ˇAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ˇSupported: replaces, timer
ˇContent-Length: 0
ˇ
ˇ
ˇ<------------>
[May 3 12:30:37] VERBOSE[27202][C-000000d1] pbx.c: -- Executing [h@12101010-dial-alt:1] Hangup("SIP/12101012-00000181", "16") in new stack
[May 3 12:30:37] VERBOSE[27202][C-000000d1] pbx.c: == Spawn extension (12101010-dial-alt, h, 1) exited non-zero on 'SIP/12101012-00000181'
[May 3 12:30:37] VERBOSE[27202][C-000000d1] pbx.c: == Spawn extension (12101010-dial-alt, s, 2) exited non-zero on 'SIP/12101012-00000181'
[May 3 12:30:37] VERBOSE[27202][C-000000d1] chan_sip.c: Scheduling destruction of SIP dialog 'h4sZAlZjAfB-MDPiLIp8hQQSs1YcM54O' in 6400 ms (Method: ACK)
[May 3 12:30:37] VERBOSE[27202][C-000000d1] chan_sip.c: set_destination: Parsing <sip:12101012@192.168.2.11:49340;ob> for address/port to send to
[May 3 12:30:37] VERBOSE[27202][C-000000d1] chan_sip.c: set_destination: set destination to 192.168.2.11:49340
[May 3 12:30:37] VERBOSE[27202][C-000000d1] chan_sip.c: Reliably Transmitting (NAT) to 4.3.2.1:50044:
ˇBYE sip:12101012@192.168.2.11:49340;ob SIP/2.0
ˇVia: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bK54e7cbda;rport
ˇMax-Forwards: 70
ˇFrom: <sip:12101010@sip12.v.net>;tag=as1ebfaf08
ˇTo: "Chris A" <sip:12101012@sip12.v.net>;tag=xYBUh7AEsrbZv9mWgYGa7dVrkzzqDbbJ
ˇCall-ID: h4sZAlZjAfB-MDPiLIp8hQQSs1YcM54O
ˇCSeq: 102 BYE
ˇUser-Agent: v Exchange (Asterisk 11)
ˇProxy-Authorization: Digest username="12101012", realm="asterisk", algorithm=MD5, uri="sip:sip12.v.net", nonce="75e4fb1b", response="49fca69dde4c688ba232aaaee970dd5d"
ˇX-Asterisk-HangupCause: Normal Clearing
ˇX-Asterisk-HangupCauseCode: 16
ˇContent-Length: 0
ˇ
ˇ
ˇ---
[May 3 12:30:37] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:50044 --->
ˇSIP/2.0 200 OK
ˇVia: SIP/2.0/UDP 1.2.3.4:5060;rport=5060;received=1.2.3.4;branch=z9hG4bK54e7cbda
ˇCall-ID: h4sZAlZjAfB-MDPiLIp8hQQSs1YcM54O
ˇFrom: <sip:12101010@sip12.v.net>;tag=as1ebfaf08
ˇTo: "Chris A" <sip:12101012@sip12.v.net>;tag=xYBUh7AEsrbZv9mWgYGa7dVrkzzqDbbJ
ˇCSeq: 102 BYE
ˇContent-Length: 0
ˇ
ˇ<------------->
[May 3 12:30:37] VERBOSE[12432] chan_sip.c: --- (7 headers 0 lines) ---
[May 3 12:30:37] VERBOSE[12432][C-000000d1] chan_sip.c: SIP Response message for INCOMING dialog BYE arrived
[May 3 12:30:37] VERBOSE[12432] chan_sip.c: Really destroying SIP dialog 'h4sZAlZjAfB-MDPiLIp8hQQSs1YcM54O' Method: ACK
[May 3 12:30:38] VERBOSE[12432] chan_sip.c: Retransmitting #1 (NAT) to 192.168.2.11:49340:
ˇOPTIONS sip:12101012@192.168.2.11:49340;ob SIP/2.0
ˇVia: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bK1eb1991c;rport
ˇMax-Forwards: 70
ˇFrom: "Unknown" <sip:Unknown@1.2.3.4>;tag=as4ca4db16
ˇTo: <sip:12101012@192.168.2.11:49340;ob>
ˇContact: <sip:Unknown@1.2.3.4:5060>
ˇCall-ID: 5fdcd4bb7a087cb232c2de61595dbcff@1.2.3.4:5060
ˇCSeq: 102 OPTIONS
ˇUser-Agent: v Exchange (Asterisk 11)
ˇDate: Sat, 03 May 2014 11:30:37 GMT
ˇAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ˇSupported: replaces, timer
ˇContent-Length: 0
ˇ
ˇ
ˇ---
[May 3 12:30:39] VERBOSE[12432] chan_sip.c: Retransmitting #2 (NAT) to 192.168.2.11:49340:
ˇOPTIONS sip:12101012@192.168.2.11:49340;ob SIP/2.0
ˇVia: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bK1eb1991c;rport
ˇMax-Forwards: 70
ˇFrom: "Unknown" <sip:Unknown@1.2.3.4>;tag=as4ca4db16
ˇTo: <sip:12101012@192.168.2.11:49340;ob>
ˇContact: <sip:Unknown@1.2.3.4:5060>
ˇCall-ID: 5fdcd4bb7a087cb232c2de61595dbcff@1.2.3.4:5060
ˇCSeq: 102 OPTIONS
ˇUser-Agent: v Exchange (Asterisk 11)
ˇDate: Sat, 03 May 2014 11:30:37 GMT
ˇAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ˇSupported: replaces, timer
ˇContent-Length: 0
ˇ
ˇ
ˇ---
[May 3 12:30:40] VERBOSE[12432] chan_sip.c: Retransmitting #3 (NAT) to 192.168.2.11:49340:
ˇOPTIONS sip:12101012@192.168.2.11:49340;ob SIP/2.0
ˇVia: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bK1eb1991c;rport
ˇMax-Forwards: 70
ˇFrom: "Unknown" <sip:Unknown@1.2.3.4>;tag=as4ca4db16
ˇTo: <sip:12101012@192.168.2.11:49340;ob>
ˇContact: <sip:Unknown@1.2.3.4:5060>
ˇCall-ID: 5fdcd4bb7a087cb232c2de61595dbcff@1.2.3.4:5060
ˇCSeq: 102 OPTIONS
ˇUser-Agent: v Exchange (Asterisk 11)
ˇDate: Sat, 03 May 2014 11:30:37 GMT
ˇAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ˇSupported: replaces, timer
ˇContent-Length: 0
ˇ
ˇ
ˇ---
[May 3 12:30:41] VERBOSE[12432] chan_sip.c: Retransmitting #4 (NAT) to 192.168.2.11:49340:
ˇOPTIONS sip:12101012@192.168.2.11:49340;ob SIP/2.0
ˇVia: SIP/2.0/UDP 1.2.3.4:5060;branch=z9hG4bK1eb1991c;rport
ˇMax-Forwards: 70
ˇFrom: "Unknown" <sip:Unknown@1.2.3.4>;tag=as4ca4db16
ˇTo: <sip:12101012@192.168.2.11:49340;ob>
ˇContact: <sip:Unknown@1.2.3.4:5060>
ˇCall-ID: 5fdcd4bb7a087cb232c2de61595dbcff@1.2.3.4:5060
ˇCSeq: 102 OPTIONS
ˇUser-Agent: v Exchange (Asterisk 11)
ˇDate: Sat, 03 May 2014 11:30:37 GMT
ˇAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ˇSupported: replaces, timer
ˇContent-Length: 0
ˇ
ˇ
ˇ---
[May 3 12:30:41] VERBOSE[12432] chan_sip.c: Really destroying SIP dialog '5fdcd4bb7a087cb232c2de61595dbcff@1.2.3.4:5060' Method: OPTIONS
[May 3 12:30:44] VERBOSE[12432] chan_sip.c: Really destroying SIP dialog '55f6abe042b3103748b652a55cb011d3@sip.v.net' Method: BYE
[May 3 12:30:45] VERBOSE[12432] chan_sip.c:
ˇ<--- SIP read from UDP:4.3.2.1:50044 --->
ˇ
ˇ<------------->