On 08/20/2014 12:04 PM, Andres wrote:
On 8/20/14, 11:28 AM, Steve Totaro wrote:
PRI intense debug should show all you need to fix this.

Right, the sooner you post this debug here the sooner we can help. Otherwise its just guesswork.

On Wed, Aug 20, 2014 at 12:13 PM, Jeff LaCoursiere <j...@jeff.net <mailto:j...@jeff.net>> wrote:


    Sadly none of these changes have made any difference. I'll report
    the resolution for posterity once we find it.

    Thanks,

    j




Ok, here is an intense debug trace. I've replaced the phone numbers to protect the innocent. The smoking gun seems to be this:

Ext: 1  Cause: Destination out of order (27)

Though I have no idea why... calling the same destination from my cell phone works fine. We only send seven digits for local "on-island" calls like this, and calls to other carriers work fine with the same format. I'm starting to doubt there is anything I can do to fix this... seems like an issue between my telco and Sprint?

Cheers,

j

astsouth*CLI> pri intense debug span 1
Enabled debugging on span 1
PRI Span: 1 t203_expire
PRI Span: 1
PRI Span: 1 > TEI: 0 State 7(Multi-frame established)
PRI Span: 1 > V(A)=17, V(S)=17, V(R)=73
PRI Span: 1 > K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0
PRI Span: 1 > T200_id=0, N200=3, T203_id=0
PRI Span: 1 > [ 00 01 01 93 ]
PRI Span: 1 > Supervisory frame:
PRI Span: 1 > SAPI: 00  C/R: 0 EA: 0
PRI Span: 1 >  TEI: 000        EA: 1
PRI Span: 1 > Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
PRI Span: 1 > N(R): 073 P/F: 1
PRI Span: 1 > 0 bytes of data
PRI Span: 1 -- Starting T200 timer
PRI Span: 1
PRI Span: 1 < TEI: 0 State 8(Timer recovery)
PRI Span: 1 < V(A)=17, V(S)=17, V(R)=73
PRI Span: 1 < K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0
PRI Span: 1 < T200_id=8192, N200=3, T203_id=0
PRI Span: 1 < [ 02 01 01 23 ]
PRI Span: 1 < Supervisory frame:
PRI Span: 1 < SAPI: 00  C/R: 1 EA: 0
PRI Span: 1 <  TEI: 000        EA: 1
PRI Span: 1 < Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
PRI Span: 1 < N(R): 017 P/F: 1
PRI Span: 1 < 0 bytes of data
PRI Span: 1
PRI Span: 1 > TEI: 0 State 8(Timer recovery)
PRI Span: 1 > V(A)=17, V(S)=17, V(R)=73
PRI Span: 1 > K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0
PRI Span: 1 > T200_id=8192, N200=3, T203_id=0
PRI Span: 1 > [ 02 01 01 93 ]
PRI Span: 1 > Supervisory frame:
PRI Span: 1 > SAPI: 00  C/R: 1 EA: 0
PRI Span: 1 >  TEI: 000        EA: 1
PRI Span: 1 > Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
PRI Span: 1 > N(R): 073 P/F: 1
PRI Span: 1 > 0 bytes of data
PRI Span: 1 -- Got ACK for N(S)=17 to (but not including) N(S)=17
PRI Span: 1 Done handling message for SAPI/TEI=0/0
PRI Span: 1
PRI Span: 1 < TEI: 0 State 8(Timer recovery)
PRI Span: 1 < V(A)=17, V(S)=17, V(R)=73
PRI Span: 1 < K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0
PRI Span: 1 < T200_id=8192, N200=3, T203_id=0
PRI Span: 1 < [ 00 01 01 23 ]
PRI Span: 1 < Supervisory frame:
PRI Span: 1 < SAPI: 00  C/R: 0 EA: 0
PRI Span: 1 <  TEI: 000        EA: 1
PRI Span: 1 < Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
PRI Span: 1 < N(R): 017 P/F: 1
PRI Span: 1 < 0 bytes of data
PRI Span: 1 -- Got ACK for N(S)=17 to (but not including) N(S)=17
PRI Span: 1 -- Stopping T200 timer
PRI Span: 1 -- Starting T203 timer
PRI Span: 1 Done handling message for SAPI/TEI=0/0
  == Using SIP RTP CoS mark 5
-- Executing [998XXXX@business:1] Dial("SIP/bolongo-00001c78", "DAHDI/g0/998XXXX,60") in new stack
PRI Span: 1 -- Making new call for cref 32897
    -- Requested transfer capability: 0x00 - SPEECH
PRI Span: 1
PRI Span: 1 > DL-DATA request
PRI Span: 1 > Protocol Discriminator: Q.931 (8)  len=56
PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 129/0x81) (Sent from originator)
PRI Span: 1 > Message Type: SETUP (5)
PRI Span: 1 TEI=0 Transmitting N(S)=17, window is open V(A)=17 K=7
PRI Span: 1
PRI Span: 1 > TEI: 0 State 7(Multi-frame established)
PRI Span: 1 > V(A)=17, V(S)=17, V(R)=73
PRI Span: 1 > K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0
PRI Span: 1 > T200_id=0, N200=3, T203_id=8192
PRI Span: 1 > [ 00 01 22 92 08 02 00 81 05 04 03 80 90 a2 18 03 a1 83 81 1e 02 80 83 28 0b b1 33 34 30 37 37 35 31 38 30 30 6c 0c 21 80 33 34 30 37 37 35 31 38 30 30 70 08 80 39 39 38 39 39 36 35 ]
PRI Span: 1 > Informational frame:
PRI Span: 1 > SAPI: 00  C/R: 0 EA: 0
PRI Span: 1 >  TEI: 000        EA: 1
PRI Span: 1 > N(S): 017   0: 0
PRI Span: 1 > N(R): 073   P: 0
PRI Span: 1 > 56 bytes of data
PRI Span: 1 > Protocol Discriminator: Q.931 (8)  len=56
PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 129/0x81) (Sent from originator)
PRI Span: 1 > Message Type: SETUP (5)
PRI Span: 1 > [04 03 80 90 a2]
PRI Span: 1 > Bearer Capability (len= 5) [ Ext: 1 Coding-Std: 0 Info transfer capability: Speech (0) PRI Span: 1 > Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16) PRI Span: 1 > User information layer 1: u-Law (34)
PRI Span: 1 > [18 03 a1 83 81]
PRI Span: 1 > Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Preferred Dchan: 0 PRI Span: 1 > ChanSel: As indicated in following octets PRI Span: 1 > Ext: 1 Coding: 0 Number Specified Channel Type: 3
PRI Span: 1 >                       Ext: 1  Channel: 1 Type: CPE]
PRI Span: 1 > [1e 02 80 83]
PRI Span: 1 > Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: User (0) PRI Span: 1 > Ext: 1 Progress Description: Calling equipment is non-ISDN. (3) ]
PRI Span: 1 > [28 0b b1 33 34 30 37 37 35 31 38 30 30]
PRI Span: 1 > Display (len=11) Charset: 31 [ 340NXXXXXX ]
PRI Span: 1 > [6c 0c 21 80 33 34 30 37 37 35 31 38 30 30]
PRI Span: 1 > Calling Party Number (len=14) [ Ext: 0 TON: National Number (2) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1) PRI Span: 1 > Presentation: Presentation allowed, User-provided, not screened (0) '340NXXXXXX' ]
PRI Span: 1 > [70 08 80 39 39 38 39 39 36 35]
PRI Span: 1 > Called Party Number (len=10) [ Ext: 1 TON: Unknown Number Type (0) NPI: Unknown Number Plan (0) '998XXXX' ]
PRI Span: 1 -- Stopping T203 timer
PRI Span: 1 -- Starting T200 timer
PRI Span: 1 q931.c:6350 q931_setup: Call 32897 enters state 1 (Call Initiated). Hold state: Idle
    -- Called DAHDI/g0/998XXXX
PRI Span: 1
PRI Span: 1 < TEI: 0 State 7(Multi-frame established)
PRI Span: 1 < V(A)=17, V(S)=18, V(R)=73
PRI Span: 1 < K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0
PRI Span: 1 < T200_id=8192, N200=3, T203_id=0
PRI Span: 1 < [ 00 01 01 24 ]
PRI Span: 1 < Supervisory frame:
PRI Span: 1 < SAPI: 00  C/R: 0 EA: 0
PRI Span: 1 <  TEI: 000        EA: 1
PRI Span: 1 < Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
PRI Span: 1 < N(R): 018 P/F: 0
PRI Span: 1 < 0 bytes of data
PRI Span: 1 -- Got ACK for N(S)=17 to (but not including) N(S)=18
PRI Span: 1 -- ACKing N(S)=17, tx_queue head is N(S)=-1 (-1 is empty, -2 is not transmitted)
PRI Span: 1 -- Stopping T200 timer
PRI Span: 1 -- Starting T203 timer
PRI Span: 1 Done handling message for SAPI/TEI=0/0
PRI Span: 1
PRI Span: 1 < TEI: 0 State 7(Multi-frame established)
PRI Span: 1 < V(A)=18, V(S)=18, V(R)=73
PRI Span: 1 < K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0
PRI Span: 1 < T200_id=0, N200=3, T203_id=8192
PRI Span: 1 < [ 02 01 92 24 08 02 80 81 02 18 03 a9 83 81 ]
PRI Span: 1 < Informational frame:
PRI Span: 1 < SAPI: 00  C/R: 1 EA: 0
PRI Span: 1 <  TEI: 000        EA: 1
PRI Span: 1 < N(S): 073   0: 0
PRI Span: 1 < N(R): 018   P: 0
PRI Span: 1 < 10 bytes of data
PRI Span: 1 < Protocol Discriminator: Q.931 (8)  len=10
PRI Span: 1 < TEI=0 Call Ref: len= 2 (reference 129/0x81) (Sent to originator)
PRI Span: 1 < Message Type: CALL PROCEEDING (2)
PRI Span: 1 < [18 03 a9 83 81]
PRI Span: 1 < Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Exclusive Dchan: 0 PRI Span: 1 < ChanSel: As indicated in following octets PRI Span: 1 < Ext: 1 Coding: 0 Number Specified Channel Type: 3
PRI Span: 1 <                       Ext: 1  Channel: 1 Type: CPE]
PRI Span: 1 -- Got ACK for N(S)=18 to (but not including) N(S)=18
PRI Span: 1 -- T200 requested to stop when not started
PRI Span: 1 T203 requested to start without stopping first
PRI Span: 1 -- Starting T203 timer
PRI Span: 1 Received message for call 0x7f73b8003940 on link 0x7f73c0031500 TEI/SAPI 0/0
PRI Span: 1 -- Processing IE 24 (cs0, Channel ID)
PRI Span: 1 q931.c:8846 post_handle_q931_message: Call 32897 enters state 3 (Outgoing Call Proceeding). Hold state: Idle
PRI Span: 1
PRI Span: 1 > TEI: 0 State 7(Multi-frame established)
PRI Span: 1 > V(A)=18, V(S)=18, V(R)=74
PRI Span: 1 > K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0
PRI Span: 1 > T200_id=0, N200=3, T203_id=8192
PRI Span: 1 > [ 02 01 01 94 ]
PRI Span: 1 > Supervisory frame:
PRI Span: 1 > SAPI: 00  C/R: 1 EA: 0
PRI Span: 1 >  TEI: 000        EA: 1
PRI Span: 1 > Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
PRI Span: 1 > N(R): 074 P/F: 0
PRI Span: 1 > 0 bytes of data
PRI Span: 1 Done handling message for SAPI/TEI=0/0
Span 1: Processing event PRI_EVENT_PROCEEDING
    -- DAHDI/i1/998XXXX-fb is proceeding passing it to SIP/bolongo-00001c78
PRI Span: 1
PRI Span: 1 < TEI: 0 State 7(Multi-frame established)
PRI Span: 1 < V(A)=18, V(S)=18, V(R)=74
PRI Span: 1 < K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0
PRI Span: 1 < T200_id=0, N200=3, T203_id=8192
PRI Span: 1 < [ 02 01 94 24 08 02 80 81 45 08 02 80 9b ]
PRI Span: 1 < Informational frame:
PRI Span: 1 < SAPI: 00  C/R: 1 EA: 0
PRI Span: 1 <  TEI: 000        EA: 1
PRI Span: 1 < N(S): 074   0: 0
PRI Span: 1 < N(R): 018   P: 0
PRI Span: 1 < 9 bytes of data
PRI Span: 1 < Protocol Discriminator: Q.931 (8)  len=9
PRI Span: 1 < TEI=0 Call Ref: len= 2 (reference 129/0x81) (Sent to originator)
PRI Span: 1 < Message Type: DISCONNECT (69)
PRI Span: 1 < [08 02 80 9b]
PRI Span: 1 < Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: User (0) PRI Span: 1 < Ext: 1 Cause: Destination out of order (27), class = Normal Event (1) ]
PRI Span: 1 -- Got ACK for N(S)=18 to (but not including) N(S)=18
PRI Span: 1 -- T200 requested to stop when not started
PRI Span: 1 T203 requested to start without stopping first
PRI Span: 1 -- Starting T203 timer
PRI Span: 1 Received message for call 0x7f73b8003940 on link 0x7f73c0031500 TEI/SAPI 0/0
PRI Span: 1 -- Processing IE 8 (cs0, Cause)
PRI Span: 1 -- Found active call: 0x7f73b8003940 cref:32897
PRI Span: 1 q931.c:9099 post_handle_q931_message: Call 32897 enters state 12 (Disconnect Indication). Hold state: Idle
PRI Span: 1
PRI Span: 1 > TEI: 0 State 7(Multi-frame established)
PRI Span: 1 > V(A)=18, V(S)=18, V(R)=75
PRI Span: 1 > K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0
PRI Span: 1 > T200_id=0, N200=3, T203_id=8192
PRI Span: 1 > [ 02 01 01 96 ]
PRI Span: 1 > Supervisory frame:
PRI Span: 1 > SAPI: 00  C/R: 1 EA: 0
PRI Span: 1 >  TEI: 000        EA: 1
PRI Span: 1 > Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
PRI Span: 1 > N(R): 075 P/F: 0
PRI Span: 1 > 0 bytes of data
PRI Span: 1 Done handling message for SAPI/TEI=0/0
Span 1: Processing event PRI_EVENT_HANGUP_REQ
    -- Span 1: Channel 0/1 got hangup request, cause 27
    -- DAHDI/i1/998XXXX-fb is circuit-busy
PRI Span: 1 q931.c:7151 q931_hangup: Hangup other cref:32897
PRI Span: 1 q931.c:6908 __q931_hangup: ourstate Disconnect Indication, peerstate Disconnect Request, hold-state Idle PRI Span: 1 q931.c:5946 q931_release: Call 32897 enters state 19 (Release Request). Hold state: Idle
PRI Span: 1
PRI Span: 1 > DL-DATA request
PRI Span: 1 > Protocol Discriminator: Q.931 (8)  len=9
PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 129/0x81) (Sent from originator)
PRI Span: 1 > Message Type: RELEASE (77)
PRI Span: 1 TEI=0 Transmitting N(S)=18, window is open V(A)=18 K=7
PRI Span: 1
PRI Span: 1 > TEI: 0 State 7(Multi-frame established)
PRI Span: 1 > V(A)=18, V(S)=18, V(R)=75
PRI Span: 1 > K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0
PRI Span: 1 > T200_id=0, N200=3, T203_id=8192
PRI Span: 1 > [ 00 01 24 96 08 02 00 81 4d 08 02 81 9b ]
PRI Span: 1 > Informational frame:
PRI Span: 1 > SAPI: 00  C/R: 0 EA: 0
PRI Span: 1 >  TEI: 000        EA: 1
PRI Span: 1 > N(S): 018   0: 0
PRI Span: 1 > N(R): 075   P: 0
PRI Span: 1 > 9 bytes of data
PRI Span: 1 > Protocol Discriminator: Q.931 (8)  len=9
PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 129/0x81) (Sent from originator)
PRI Span: 1 > Message Type: RELEASE (77)
PRI Span: 1 > [08 02 81 9b]
PRI Span: 1 > Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1) PRI Span: 1 > Ext: 1 Cause: Destination out of order (27), class = Normal Event (1) ]
PRI Span: 1 -- Stopping T203 timer
PRI Span: 1 -- Starting T200 timer
    -- Hungup 'DAHDI/i1/998XXXX-fb'
  == Everyone is busy/congested at this time (1:0/1/0)
-- Executing [998XXXX@business:2] Hangup("SIP/bolongo-00001c78", "") in new stack == Spawn extension (business, 998XXXX, 2) exited non-zero on 'SIP/bolongo-00001c78'
PRI Span: 1
PRI Span: 1 < TEI: 0 State 7(Multi-frame established)
PRI Span: 1 < V(A)=18, V(S)=19, V(R)=75
PRI Span: 1 < K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0
PRI Span: 1 < T200_id=8192, N200=3, T203_id=0
PRI Span: 1 < [ 00 01 01 26 ]
PRI Span: 1 < Supervisory frame:
PRI Span: 1 < SAPI: 00  C/R: 0 EA: 0
PRI Span: 1 <  TEI: 000        EA: 1
PRI Span: 1 < Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
PRI Span: 1 < N(R): 019 P/F: 0
PRI Span: 1 < 0 bytes of data
PRI Span: 1 -- Got ACK for N(S)=18 to (but not including) N(S)=19
PRI Span: 1 -- ACKing N(S)=18, tx_queue head is N(S)=-1 (-1 is empty, -2 is not transmitted)
PRI Span: 1 -- Stopping T200 timer
PRI Span: 1 -- Starting T203 timer
PRI Span: 1 Done handling message for SAPI/TEI=0/0
PRI Span: 1
PRI Span: 1 < TEI: 0 State 7(Multi-frame established)
PRI Span: 1 < V(A)=19, V(S)=19, V(R)=75
PRI Span: 1 < K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0
PRI Span: 1 < T200_id=0, N200=3, T203_id=8192
PRI Span: 1 < [ 02 01 96 26 08 02 80 81 5a ]
PRI Span: 1 < Informational frame:
PRI Span: 1 < SAPI: 00  C/R: 1 EA: 0
PRI Span: 1 <  TEI: 000        EA: 1
PRI Span: 1 < N(S): 075   0: 0
PRI Span: 1 < N(R): 019   P: 0
PRI Span: 1 < 5 bytes of data
PRI Span: 1 < Protocol Discriminator: Q.931 (8)  len=5
PRI Span: 1 < TEI=0 Call Ref: len= 2 (reference 129/0x81) (Sent to originator)
PRI Span: 1 < Message Type: RELEASE COMPLETE (90)
PRI Span: 1 -- Got ACK for N(S)=19 to (but not including) N(S)=19
PRI Span: 1 -- T200 requested to stop when not started
PRI Span: 1 T203 requested to start without stopping first
PRI Span: 1 -- Starting T203 timer
PRI Span: 1 Received message for call 0x7f73b8003940 on link 0x7f73c0031500 TEI/SAPI 0/0 PRI Span: 1 q931.c:8959 post_handle_q931_message: Call 32897 enters state 0 (Null). Hold state: Idle
PRI Span: 1 q931.c:7151 q931_hangup: Hangup other cref:32897
PRI Span: 1 q931.c:6908 __q931_hangup: ourstate Null, peerstate Null, hold-state Idle PRI Span: 1 Destroying call 0x7f73b8003940, ourstate Null, peerstate Null, hold-state Idle
PRI Span: 1
PRI Span: 1 > TEI: 0 State 7(Multi-frame established)
PRI Span: 1 > V(A)=19, V(S)=19, V(R)=76
PRI Span: 1 > K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0
PRI Span: 1 > T200_id=0, N200=3, T203_id=8192
PRI Span: 1 > [ 02 01 01 98 ]
PRI Span: 1 > Supervisory frame:
PRI Span: 1 > SAPI: 00  C/R: 1 EA: 0
PRI Span: 1 >  TEI: 000        EA: 1
PRI Span: 1 > Zero: 0     S: 0 01: 1  [ RR (receive ready) ]
PRI Span: 1 > N(R): 076 P/F: 0
PRI Span: 1 > 0 bytes of data
PRI Span: 1 Done handling message for SAPI/TEI=0/0
Span 1: Processing event PRI_EVENT_HANGUP_ACK
astsouth*CLI> pri set debug off span 1
Disabled debugging on span 1

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

Reply via email to