I did a little googling, but didn't seem to find anything specific to answer the question. I am trying to debug some calls on an Asterisk system (AsteriskNow) that are dropping, and when the general logs didn't nail anything I turned on SIP Debugging on the trunk to the provider. Basically the complaint is that when some call in, regardless of if the call is answered, or if Vmail answers it, it drops the calls in a matter of seconds. The strange thing is, that the system processes many hundreds of calls daily, but only a couple specific incoming callers are seeing the drops. I would have thought a NAT issue, but why does this only affect a specific group of incoming callers, the rest go about their business just fine. I think thinking bandwidth.com is mucking something up, but again I have no specific proof one way or another, so why the debugging.
When one of the problem callers is dropped, in the SIP debugging I see: chan_sip.c: Scheduling destruction of SIP dialog '285991942_79966325@192.168.27.72' in 6400 ms (Method: BYE) Is this the remote end (ie bandwidth.com) dropping the call, or is the local Asterisk server dropping the call? For any that care to look at all the gory details, here is a chunk of the debugging output: [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: <--- SIP read from UDP:216.82.224.202:5060 ---> ACK sip:4104159233@10.98.4.36:5060 SIP/2.0 Record-Route: <sip:216.82.224.202;lr;ftag=gK0e4bc97f> Record-Route: <sip:67.231.8.93;lr=on;ftag=gK0e4bc97f> Via: SIP/2.0/UDP 216.82.224.202;branch=z9hG4bKebf3.453cc5a5.2 Via: SIP/2.0/UDP 67.231.8.93;branch=z9hG4bKebf3.315d4e14.3 Via: SIP/2.0/UDP 192.168.37.72:5060;branch=z9hG4bK0eB7f5f0b80116aa493 From: <sip:2159470824@192.168.37.72;isup-oli=0>;tag=gK0e4bc97f To: <sip:+14104159233@67.231.8.93>;tag=as6974aee7 Call-ID: 353260172_48597606@192.168.37.72 CSeq: 11346 ACK Max-Forwards: 68 Content-Length: 0 <-------------> [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: --- (12 headers 0 lines) --- [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: <--- SIP read from UDP:216.82.224.202:5060 ---> INVITE sip:4104159233@10.98.4.36:5060 SIP/2.0 Record-Route: <sip:216.82.224.202;lr;ftag=gK0e4bc97f> Record-Route: <sip:67.231.8.93;lr=on;ftag=gK0e4bc97f> Via: SIP/2.0/UDP 216.82.224.202;branch=z9hG4bKfbf3.9d9b1065.0 Via: SIP/2.0/UDP 67.231.8.93;branch=z9hG4bKfbf3.c159a6a.0 Via: SIP/2.0/UDP 192.168.37.72:5060;branch=z9hG4bK0eB7f601a4d116aa493 From: <sip:2159470824@192.168.37.72;isup-oli=0>;tag=gK0e4bc97f To: <sip:+14104159233@67.231.8.93>;tag=as6974aee7 Call-ID: 353260172_48597606@192.168.37.72 CSeq: 11347 INVITE Max-Forwards: 68 Contact: <sip:+12159470824@192.168.37.72:5060> Content-Length: 235 Content-Disposition: session; handling=required Content-Type: application/sdp v=0 o=Sonus_UAC 22153 5058 IN IP4 192.168.37.72 s=SIP Media Capabilities c=IN IP4 67.231.8.102 t=0 0 m=audio 6576 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=maxptime:20 <-------------> [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: --- (15 headers 11 lines) --- [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: Sending to 216.82.224.202:5060 (NAT) [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: Found RTP audio format 0 [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: Found RTP audio format 101 [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: Found audio description format PCMU for ID 0 [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: Found audio description format telephone-event for ID 101 [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x4 (ulaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw) [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: Peer audio RTP is at port 67.231.8.102:6576 [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: <--- Transmitting (NAT) to 216.82.224.202:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 216.82.224.202;branch=z9hG4bKfbf3.9d9b1065.0;received=216.82.224.202;rport=5 060 Via: SIP/2.0/UDP 67.231.8.93;branch=z9hG4bKfbf3.c159a6a.0 Via: SIP/2.0/UDP 192.168.37.72:5060;branch=z9hG4bK0eB7f601a4d116aa493 Record-Route: <sip:216.82.224.202;lr;ftag=gK0e4bc97f> Record-Route: <sip:67.231.8.93;lr=on;ftag=gK0e4bc97f> From: <sip:2159470824@192.168.37.72;isup-oli=0>;tag=gK0e4bc97f To: <sip:+14104159233@67.231.8.93>;tag=as6974aee7 Call-ID: 353260172_48597606@192.168.37.72 CSeq: 11347 INVITE Server: FPBX-2.9.0(1.8.15.1) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces Contact: <sip:4104159233@10.98.4.36:5060> Content-Length: 0 <------------> [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: Audio is at 11444 [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: <--- Reliably Transmitting (NAT) to 216.82.224.202:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 216.82.224.202;branch=z9hG4bKfbf3.9d9b1065.0;received=216.82.224.202;rport=5 060 Via: SIP/2.0/UDP 67.231.8.93;branch=z9hG4bKfbf3.c159a6a.0 Via: SIP/2.0/UDP 192.168.37.72:5060;branch=z9hG4bK0eB7f601a4d116aa493 Record-Route: <sip:216.82.224.202;lr;ftag=gK0e4bc97f> Record-Route: <sip:67.231.8.93;lr=on;ftag=gK0e4bc97f> From: <sip:2159470824@192.168.37.72;isup-oli=0>;tag=gK0e4bc97f To: <sip:+14104159233@67.231.8.93>;tag=as6974aee7 Call-ID: 353260172_48597606@192.168.37.72 CSeq: 11347 INVITE Server: FPBX-2.9.0(1.8.15.1) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces Contact: <sip:4104159233@10.98.4.36:5060> Content-Type: application/sdp Content-Length: 233 v=0 o=root 1660074055 1660074056 IN IP4 10.98.4.36 s=Asterisk PBX 1.8.15.1 c=IN IP4 10.98.4.36 t=0 0 m=audio 11444 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv <------------> [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: Retransmitting #1 (NAT) to 216.82.224.202:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 216.82.224.202;branch=z9hG4bKfbf3.9d9b1065.0;received=216.82.224.202;rport=5 060 Via: SIP/2.0/UDP 67.231.8.93;branch=z9hG4bKfbf3.c159a6a.0 Via: SIP/2.0/UDP 192.168.37.72:5060;branch=z9hG4bK0eB7f601a4d116aa493 Record-Route: <sip:216.82.224.202;lr;ftag=gK0e4bc97f> Record-Route: <sip:67.231.8.93;lr=on;ftag=gK0e4bc97f> From: <sip:2159470824@192.168.37.72;isup-oli=0>;tag=gK0e4bc97f To: <sip:+14104159233@67.231.8.93>;tag=as6974aee7 Call-ID: 353260172_48597606@192.168.37.72 CSeq: 11347 INVITE Server: FPBX-2.9.0(1.8.15.1) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces Contact: <sip:4104159233@10.98.4.36:5060> Content-Type: application/sdp Content-Length: 233 v=0 o=root 1660074055 1660074056 IN IP4 10.98.4.36 s=Asterisk PBX 1.8.15.1 c=IN IP4 10.98.4.36 t=0 0 m=audio 11444 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv --- [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: Retransmitting #2 (NAT) to 216.82.224.202:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 216.82.224.202;branch=z9hG4bKfbf3.9d9b1065.0;received=216.82.224.202;rport=5 060 Via: SIP/2.0/UDP 67.231.8.93;branch=z9hG4bKfbf3.c159a6a.0 Via: SIP/2.0/UDP 192.168.37.72:5060;branch=z9hG4bK0eB7f601a4d116aa493 Record-Route: <sip:216.82.224.202;lr;ftag=gK0e4bc97f> Record-Route: <sip:67.231.8.93;lr=on;ftag=gK0e4bc97f> From: <sip:2159470824@192.168.37.72;isup-oli=0>;tag=gK0e4bc97f To: <sip:+14104159233@67.231.8.93>;tag=as6974aee7 Call-ID: 353260172_48597606@192.168.37.72 CSeq: 11347 INVITE Server: FPBX-2.9.0(1.8.15.1) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces Contact: <sip:4104159233@10.98.4.36:5060> Content-Type: application/sdp Content-Length: 233 v=0 o=root 1660074055 1660074056 IN IP4 10.98.4.36 s=Asterisk PBX 1.8.15.1 c=IN IP4 10.98.4.36 t=0 0 m=audio 11444 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv --- [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: <--- SIP read from UDP:216.82.224.202:5060 ---> BYE sip:4104159270@10.98.4.36:5060 SIP/2.0 Record-Route: <sip:216.82.224.202;lr;ftag=gK0b66d829> Record-Route: <sip:67.231.4.93;lr=on;ftag=gK0b66d829> Via: SIP/2.0/UDP 216.82.224.202;branch=z9hG4bKe902.53bde7e.0 Via: SIP/2.0/UDP 67.231.4.93;branch=z9hG4bKe902.32697e93.0 Via: SIP/2.0/UDP 192.168.27.72:5060;branch=z9hG4bK0bBac8c2c3cb90659df From: <sip:7173381800@192.168.27.72;isup-oli=0>;tag=gK0b66d829 To: <sip:+14104159270@67.231.4.93>;tag=as0850c6db Call-ID: 285991942_79966325@192.168.27.72 CSeq: 297 BYE Record-Route: <sip:67.231.8.93;lr=on;ftag=gK0e4bc97f> From: <sip:2159470824@192.168.37.72;isup-oli=0>;tag=gK0e4bc97f To: <sip:+14104159233@67.231.8.93>;tag=as6974aee7 Call-ID: 353260172_48597606@192.168.37.72 CSeq: 11347 INVITE Server: FPBX-2.9.0(1.8.15.1) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces Contact: <sip:4104159233@10.98.4.36:5060> Content-Type: application/sdp Content-Length: 233 v=0 o=root 1660074055 1660074056 IN IP4 10.98.4.36 s=Asterisk PBX 1.8.15.1 c=IN IP4 10.98.4.36 t=0 0 m=audio 11444 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv --- [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: <--- SIP read from UDP:216.82.224.202:5060 ---> BYE sip:4104159270@10.98.4.36:5060 SIP/2.0 Record-Route: <sip:216.82.224.202;lr;ftag=gK0b66d829> Record-Route: <sip:67.231.4.93;lr=on;ftag=gK0b66d829> Via: SIP/2.0/UDP 216.82.224.202;branch=z9hG4bKe902.53bde7e.0 Via: SIP/2.0/UDP 67.231.4.93;branch=z9hG4bKe902.32697e93.0 Via: SIP/2.0/UDP 192.168.27.72:5060;branch=z9hG4bK0bBac8c2c3cb90659df From: <sip:7173381800@192.168.27.72;isup-oli=0>;tag=gK0b66d829 To: <sip:+14104159270@67.231.4.93>;tag=as0850c6db Call-ID: 285991942_79966325@192.168.27.72 CSeq: 297 BYE Max-Forwards: 68 Content-Length: 0 <-------------> [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: --- (12 headers 0 lines) --- [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: Sending to 216.82.224.202:5060 (NAT) [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: Scheduling destruction of SIP dialog '285991942_79966325@192.168.27.72' in 6400 ms (Method: BYE) [Nov 23 15:43:13] VERBOSE[5127] chan_sip.c: <--- Transmitting (NAT) to 216.82.224.202:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 216.82.224.202;branch=z9hG4bKe902.53bde7e.0;received=216.82.224.202;rport=50 60 Via: SIP/2.0/UDP 67.231.4.93;branch=z9hG4bKe902.32697e93.0 Via: SIP/2.0/UDP 192.168.27.72:5060;branch=z9hG4bK0bBac8c2c3cb90659df Record-Route: <sip:216.82.224.202;lr;ftag=gK0b66d829> Record-Route: <sip:67.231.4.93;lr=on;ftag=gK0b66d829> From: <sip:7173381800@192.168.27.72;isup-oli=0>;tag=gK0b66d829 To: <sip:+14104159270@67.231.4.93>;tag=as0850c6db Call-ID: 285991942_79966325@192.168.27.72 CSeq: 297 BYE Server: FPBX-2.9.0(1.8.15.1) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces Content-Length: 0 <------------> [Nov 23 15:43:13] VERBOSE[26556] pbx.c: -- Executing [h@macro-dial-one:1] Macro("SIP/bandwidth_east-000001a4", "hangupcall,") in new stack [Nov 23 15:43:13] VERBOSE[26556] pbx.c: -- Executing [s@macro-hangupcall:1] GotoIf("SIP/bandwidth_east-000001a4", "1?theend") in new stack [Nov 23 15:43:13] VERBOSE[26556] pbx.c: -- Goto (macro-hangupcall,s,3) [Nov 23 15:43:13] VERBOSE[26556] pbx.c: -- Executing [s@macro-hangupcall:3] Hangup("SIP/bandwidth_east-000001a4", "") in new stack [Nov 23 15:43:13] VERBOSE[26556] app_macro.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on 'SIP/bandwidth_east-000001a4' in macro 'hangupcall' [Nov 23 15:43:13] VERBOSE[26556] features.c: == Spawn extension (macro-dial-one, h, 1) exited non-zero on 'SIP/bandwidth_east-000001a4' [Nov 23 15:43:13] VERBOSE[26556] app_macro.c: == Spawn extension (macro-dial-one, s, 42) exited non-zero on 'SIP/bandwidth_east-000001a4' in macro 'dial-one' [Nov 23 15:43:13] VERBOSE[26556] app_macro.c: == Spawn extension (macro-exten-vm, s, 14) exited non-zero on 'SIP/bandwidth_east-000001a4' in macro 'exten-vm' [Nov 23 15:43:13] VERBOSE[26556] pbx.c: == Spawn extension (from-did-direct, 9237, 2) exited non-zero on 'SIP/bandwidth_east-000001a4' [Nov 23 15:43:13] VERBOSE[26558] pbx.c: -- Executing [h@macro-dial-one:1] Macro("Local/9244@from-internal-d32c;2", "hangupcall,") in new stack [Nov 23 15:43:13] VERBOSE[26558] pbx.c: -- Executing [s@macro-hangupcall:1] GotoIf("Local/9244@from-internal-d32c;2", "1?theend") in new stack [Nov 23 15:43:13] VERBOSE[26558] pbx.c: -- Goto (macro-hangupcall,s,3) [Nov 23 15:43:13] VERBOSE[26558] pbx.c: -- Executing [s@macro-hangupcall:3] Hangup("Local/9244@from-internal-d32c;2", "") in new stack [Nov 23 15:43:13] VERBOSE[26558] app_macro.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on 'Local/9244@from-internal-d32c;2' in macro 'hangupcall' [Nov 23 15:43:13] VERBOSE[26558] features.c: == Spawn extension (macro-dial-one, h, 1) exited non-zero on 'Local/9244@from-internal-d32c;2' [Nov 23 15:43:13] VERBOSE[26558] app_macro.c: == Spawn extension (macro-dial-one, s, 42) exited non-zero on 'Local/9244@from-internal-d32c;2' in macro 'dial-one' [Nov 23 15:43:13] VERBOSE[26558] app_macro.c: == Spawn extension (macro-exten-vm, s, 14) exited non-zero on 'Local/9244@from-internal-d32c;2' in macro 'exten-vm' [Nov 23 15:43:13] VERBOSE[26558] pbx.c: == Spawn extension (from-internal, 9244, 2) exited non-zero on 'Local/9244@from-internal-d32c;2' [Nov 23 15:43:13] VERBOSE[2746] chan_sip.c: == Extension Changed 9244[ext-local] new state Idle for Notify User 9237 For sure any help or input on tracing this all down is most appreciated... --- Howard Leadmon -- _____________________________________________________________________ -- Bandwidth and Colocation Provided by http://www.api-digital.com -- New to Asterisk? Join us for a live introductory webinar every Thurs: http://www.asterisk.org/hello asterisk-users mailing list To UNSUBSCRIBE or update options visit: http://lists.digium.com/mailman/listinfo/asterisk-users