Music on Hold starts randomly

Asterisk Asterisk Support
1

Hi

Here is something that has me stumped. Sometimes at the start or end of a call I have placed, music on hold is started and played to me and I don’t really no why.

Here is a call where music on hold starts just momentarily as the call finishes:

[Mar 24 17:17:29] VERBOSE[25157][C-00000072] res_agi.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/a2billing.php [Mar 24 17:17:29] VERBOSE[25157][C-00000072] res_agi.c: -- AGI Script Executing Application: (DIAL) Options: (SIP/voxbeam-out/0011102441xxxxxxxxx,120,XL(36000000:60000:30000)) [Mar 24 17:17:29] VERBOSE[25157][C-00000072] netsock2.c: == Using SIP RTP TOS bits 184 [Mar 24 17:17:29] VERBOSE[25157][C-00000072] netsock2.c: == Using SIP RTP CoS mark 5 [Mar 24 17:17:29] VERBOSE[25157][C-00000072] app_dial.c: -- Called SIP/voxbeam-out/0011102441xxxxxxxxx [Mar 24 17:17:30] VERBOSE[25157][C-00000072] app_dial.c: -- SIP/voxbeam-out-000000c7 is ringing [Mar 24 17:17:30] VERBOSE[25157][C-00000072] app_dial.c: -- SIP/voxbeam-out-000000c7 is making progress passing it to SIP/1235-000000c6 [Mar 24 17:17:42] VERBOSE[25157][C-00000072] app_dial.c: -- SIP/voxbeam-out-000000c7 answered SIP/1235-000000c6 [Mar 24 17:19:10] VERBOSE[25157][C-00000072] res_musiconhold.c: -- Started music on hold, class 'default', on SIP/1235-000000c6 [Mar 24 17:19:10] VERBOSE[25157][C-00000072] res_musiconhold.c: -- Stopped music on hold on SIP/12351001-000000c6 [Mar 24 17:19:10] VERBOSE[25157][C-00000072] res_agi.c: -- <SIP/1235-000000c6>AGI Script a2billing.php completed, returning 4

In itself, that’s not really a problem as the call is finished with. But here is an example where the called party picks up, and I here music. This is a problem as we can’t hear each other and the call has failed:

[Mar 24 17:38:27] VERBOSE[25197][C-00000073] res_agi.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/a2billing.php [Mar 24 17:38:27] VERBOSE[25197][C-00000073] res_agi.c: -- AGI Script Executing Application: (DIAL) Options: (SIP/voxbeam-out/0011102441xxxxxxxxx,120,XL(36000000:60000:30000)) [Mar 24 17:38:27] VERBOSE[25197][C-00000073] netsock2.c: == Using SIP RTP TOS bits 184 [Mar 24 17:38:27] VERBOSE[25197][C-00000073] netsock2.c: == Using SIP RTP CoS mark 5 [Mar 24 17:38:27] VERBOSE[25197][C-00000073] app_dial.c: -- Called SIP/voxbeam-out/0011102441xxxxxxxxx [Mar 24 17:38:28] VERBOSE[25197][C-00000073] app_dial.c: -- SIP/voxbeam-out-000000c9 is ringing [Mar 24 17:38:28] VERBOSE[25197][C-00000073] app_dial.c: -- SIP/voxbeam-out-000000c9 is making progress passing it to SIP/1235-000000c8 [Mar 24 17:38:35] VERBOSE[25197][C-00000073] app_dial.c: -- SIP/voxbeam-out-000000c9 answered SIP/1235-000000c8 [Mar 24 17:38:38] VERBOSE[25197][C-00000073] res_musiconhold.c: -- Started music on hold, class 'default', on SIP/1235-000000c8 [Mar 24 17:38:51] VERBOSE[25197][C-00000073] res_musiconhold.c: -- Stopped music on hold on SIP/1235-000000c8 [Mar 24 17:38:51] VERBOSE[25197][C-00000073] res_agi.c: -- <SIP/1235-000000c8>AGI Script a2billing.php completed, returning 4

A lot of calls are absolutely fine though:

[Mar 24 10:48:00] VERBOSE[24165][C-00000071] res_agi.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/a2billing.php [Mar 24 10:48:00] VERBOSE[24165][C-00000071] res_agi.c: -- AGI Script Executing Application: (DIAL) Options: (SIP/voxbeam-out/0011102441xxxxxxxxx,120,XL(36000000:60000:30000)) [Mar 24 10:48:00] VERBOSE[24165][C-00000071] netsock2.c: == Using SIP RTP TOS bits 184 [Mar 24 10:48:00] VERBOSE[24165][C-00000071] netsock2.c: == Using SIP RTP CoS mark 5 [Mar 24 10:48:00] VERBOSE[24165][C-00000071] app_dial.c: -- Called SIP/voxbeam-out/0011102441xxxxxxxxx [Mar 24 10:48:01] VERBOSE[24165][C-00000071] app_dial.c: -- SIP/voxbeam-out-000000c5 is ringing [Mar 24 10:48:01] VERBOSE[24165][C-00000071] app_dial.c: -- SIP/voxbeam-out-000000c5 is making progress passing it to SIP/1235-000000c4 [Mar 24 10:48:03] VERBOSE[24165][C-00000071] app_dial.c: -- SIP/voxbeam-out-000000c5 answered SIP/1235-000000c4 [Mar 24 10:50:23] VERBOSE[24165][C-00000071] res_agi.c: -- <SIP/1235-000000c4>AGI Script a2billing.php completed, returning 4

I’m guessing Asterisk is receiving a SIP message from each my end or the other end but I wonder if anyone else has experienced this phenomenon and can shed any light?

Many thanks.

Chris

2

Haven’t experienced this at all.

Can you do a “sip set debug all” and see what SIP messages are showing up when the problem happens?

3

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 ---> ˇ ˇ<------------->

4

Some ISDN gateways treat CLEAR as hold and only send BYE on RELEASE.

Landline destinations generally only send CLEAR and RELEASE follows later from the network.

5

Here’s the thing. All devices and routes here are known. In this case I have two SIP devices behind NAT (same NAT) and the server out on the WAN (okay I don’t actually know what happens between the various offices and the data centre but I think it’s safe to say nothing too packet changing!).

There isn’t anything else involved.

But the same thing happens when there is one SIP device (behind NAT), the server on the WAN and that server is proxying media for another WAN proxy.

It would seem the the problem is between my server and my SIP devices. I have one server and more than one office (all NAT).

The music is only heard in one direction and that direction can be either way. It can be caller or called party. Sometimes it occurs during call setup or completion (not too much to be worried about), but sometimes (a lot less frequently) it can happen as soon as the call is answered.

Something happens to trigger music on hold and there are no events after that (that the server receives) to stop it again. It’s quite bizarre.

I wonder if there is a nice list of all the conditions that can trigger music on hold? Or whether it will be too technical for me to understand!!

6

I’m experiencing the same problem. I’m using a Local channel to originate a call from call manager. One leg of the Local channel gets to the Dial() application, while the other plays a series of sound files to the called party. MOH starts randomly while the files are being played.
Has anybody solved or identified the problem?
Thanks.