Home » Forums » Community Edition » Trunks

need some help troubleshooting a PRI connection that randomly drops calls

jpcw
Posts: 15
 Member Since:
2007-12-30
Submitted by jpcw on Wed, 08/11/2010 - 5:53pm.

We recently upgraded our trixbox system from 4xBRI lines to 1xPRI 20 channel and now I need some help troubleshooting a PRI connection that randomly drops calls.

Asterisk log with pri debugging on I have marked the spot where I think the issue is occurring with a **.
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [04XXXXXXX@from-internal:1] Macro("SIP/204-0852ecd0", "user-callerid|SKIPTTL|") in new stack
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-user-callerid:1] NoOp("SIP/204-0852ecd0", "user-callerid: device 204") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Noop
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-user-callerid:2] Set("SIP/204-0852ecd0", "AMPUSER=204") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-user-callerid:3] GotoIf("SIP/204-0852ecd0", "0?report") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-user-callerid:4] ExecIf("SIP/204-0852ecd0", "1|Set|REALCALLERIDNUM=204") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: ExecIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-user-callerid:5] NoOp("SIP/204-0852ecd0", "REALCALLERIDNUM is 204") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Noop
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-user-callerid:6] Set("SIP/204-0852ecd0", "AMPUSER=204") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-user-callerid:7] Set("SIP/204-0852ecd0", "AMPUSERCIDNAME=Carolanne van Leeuwen") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-user-callerid:8] GotoIf("SIP/204-0852ecd0", "0?report") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-user-callerid:9] Set("SIP/204-0852ecd0", "AMPUSERCID=204") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-user-callerid:10] Set("SIP/204-0852ecd0", "CALLERID(all)="Carolanne van Leeuwen" ") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-user-callerid:11] Set("SIP/204-0852ecd0", "REALCALLERIDNUM=204") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] DEBUG[12476] func_db.c: DB: AMPUSER/204/language not found in database.
[Aug 12 07:56:28] DEBUG[12476] func_db.c: DB: AMPUSER/204/language not found in database.
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-user-callerid:12] ExecIf("SIP/204-0852ecd0", "0|Set|CHANNEL(language)=") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: ExecIf
[Aug 12 07:56:28] DEBUG[12476] func_db.c: DB: AMPUSER/204/language not found in database.
[Aug 12 07:56:28] DEBUG[12476] func_db.c: DB: AMPUSER/204/language not found in database.
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-user-callerid:13] NoOp("SIP/204-0852ecd0", "TTL: ARG1: SKIPTTL") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Noop
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-user-callerid:14] GotoIf("SIP/204-0852ecd0", "1?continue") in new stack
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Goto (macro-user-callerid,s,23)
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-user-callerid:23] NoOp("SIP/204-0852ecd0", "Using CallerID "Carolanne van Leeuwen" ") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Noop
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [04XXXXXXX@from-internal:2] Set("SIP/204-0852ecd0", "_NODEST=") in new stack
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [04XXXXXXX@from-internal:3] Macro("SIP/204-0852ecd0", "record-enable|204|OUT|") in new stack
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-record-enable:1] GotoIf("SIP/204-0852ecd0", "0?2:4") in new stack
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Goto (macro-record-enable,s,4)
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-record-enable:4] AGI("SIP/204-0852ecd0", "recordingcheck|20100812-075628|1281563788.194") in new stack
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Aug 12 07:56:28] VERBOSE[12476] logger.c: recordingcheck|20100812-075628|1281563788.194: Outbound recording not enabled
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- AGI Script recordingcheck completed, returning 0
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: AGI
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-record-enable:5] NoOp("SIP/204-0852ecd0", "No recording needed") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Noop
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [04XXXXXXX@from-internal:4] Macro("SIP/204-0852ecd0", "dialout-trunk|6|47572340||") in new stack
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:1] Set("SIP/204-0852ecd0", "DIAL_TRUNK=6") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] DEBUG[12476] func_db.c: DB: AMPUSER/204/pinless not found in database.
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:2] ExecIf("SIP/204-0852ecd0", "0|Authenticate|") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: ExecIf
[Aug 12 07:56:28] DEBUG[12476] func_db.c: DB: AMPUSER/204/pinless not found in database.
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/204-0852ecd0", "0?disabletrunk|1") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:4] Set("SIP/204-0852ecd0", "DIAL_NUMBER=47572340") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:5] Set("SIP/204-0852ecd0", "DIAL_TRUNK_OPTIONS=tr") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:6] Set("SIP/204-0852ecd0", "GROUP()=OUT_6") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/204-0852ecd0", "0?nomax") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:8] GotoIf("SIP/204-0852ecd0", "0?chanfull") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/204-0852ecd0", "0?skipoutcid") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:10] Set("SIP/204-0852ecd0", "DIAL_TRUNK_OPTIONS=r") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:11] Macro("SIP/204-0852ecd0", "outbound-callerid|6") in new stack
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/204-0852ecd0", "0|SetCallerPres|") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: ExecIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-outbound-callerid:2] GotoIf("SIP/204-0852ecd0", "1?start") in new stack
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Goto (macro-outbound-callerid,s,4)
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-outbound-callerid:4] NoOp("SIP/204-0852ecd0", "REALCALLERIDNUM is 204") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Noop
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-outbound-callerid:5] GotoIf("SIP/204-0852ecd0", "1?normcid") in new stack
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Goto (macro-outbound-callerid,s,10)
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] DEBUG[12476] func_db.c: DB: AMPUSER/204/outboundcid not found in database.
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-outbound-callerid:10] Set("SIP/204-0852ecd0", "USEROUTCID=") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] DEBUG[12476] func_db.c: DB: DEVICE/204/emergency_cid not found in database.
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-outbound-callerid:11] Set("SIP/204-0852ecd0", "EMERGENCYCID=") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-outbound-callerid:12] Set("SIP/204-0852ecd0", "TRUNKOUTCID=29XXXXXXX") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-outbound-callerid:13] GotoIf("SIP/204-0852ecd0", "1?trunkcid") in new stack
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Goto (macro-outbound-callerid,s,17)
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-outbound-callerid:17] GotoIf("SIP/204-0852ecd0", "0?usercid") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-outbound-callerid:18] Set("SIP/204-0852ecd0", "CALLERID(all)=29XXXXXXX") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-outbound-callerid:19] GotoIf("SIP/204-0852ecd0", "1?report") in new stack
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Goto (macro-outbound-callerid,s,23)
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-outbound-callerid:23] NoOp("SIP/204-0852ecd0", "CallerID set to "" ") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Noop
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Macro
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:12] AGI("SIP/204-0852ecd0", "fixlocalprefix") in new stack
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- AGI Script fixlocalprefix completed, returning 0
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: AGI
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:13] Set("SIP/204-0852ecd0", "OUTNUM=47572340") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:14] Set("SIP/204-0852ecd0", "custom=ZAP/g0") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Set
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:15] GotoIf("SIP/204-0852ecd0", "1?gocall") in new stack
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Goto (macro-dialout-trunk,s,17)
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:17] Macro("SIP/204-0852ecd0", "dialout-trunk-predial-hook|") in new stack
[Aug 12 07:56:28] WARNING[12476] app_macro.c: Context 'macro-dialout-trunk-predial-hook' for macro 'dialout-trunk-predial-hook' lacks 's' extension, priority 1
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: Macro
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/204-0852ecd0", "0?bypass|1") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:19] GotoIf("SIP/204-0852ecd0", "0?customtrunk") in new stack
[Aug 12 07:56:28] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Executing [s@macro-dialout-trunk:20] Dial("SIP/204-0852ecd0", "ZAP/g0/47572340|300|r") in new stack
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Making new call for cr 32797
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Requested transfer capability: 0x00 - SPEECH
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > Protocol Discriminator: Q.931 (8) len=40
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > Call Ref: len= 2 (reference 29/0x1D) (Originator)
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > Message type: SETUP (5)
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > [04 03 80 90 a3]
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > Bearer Capability (len= 5) [ Ext: 1 Q.931 Std: 0 Info transfer capability: Speech (0)
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16)
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > User information layer 1: A-Law (35)
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > [18 03 a9 83 81]
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > Channel ID (len= 5) [ Ext: 1 IntID: Implicit PRI Spare: 0 Exclusive Dchan: 0
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > ChanSel: As indicated in following octets
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > Ext: 1 Coding: 0 Number Specified Channel Type: 3
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > Ext: 1 Channel: 1 ]
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > [6c 0b 00 80 32 39 34 36 37 39 32 30 30]
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > Calling Number (len=13) [ Ext: 0 TON: Unknown Number Type (0) NPI: Unknown Number Plan (0)
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > Presentation: Presentation permitted, user number not screened (0) '29XXXXXXX' ]
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > [70 09 80 34 37 35 37 32 33 34 30]
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > Called Number (len=11) [ Ext: 1 TON: Unknown Number Type (0) NPI: Unknown Number Plan (0) '47572340' ]
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > [a1]
[Aug 12 07:56:28] VERBOSE[12476] logger.c: > Sending Complete (len= 1)
[Aug 12 07:56:28] VERBOSE[12476] logger.c: q931.c:3092 q931_setup: call 32797 on channel 1 enters state 1 (Call Initiated)
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Called g0/47572340
[Aug 12 07:56:28] VERBOSE[11440] logger.c: [Aug 12 07:56:28] VERBOSE[11440] logger.c: [Aug 12 07:56:28] VERBOSE[11440] logger.c: [Aug 12 07:56:28] VERBOSE[11440] logger.c: [Aug 12 07:56:28] VERBOSE[11440] logger.c: [Aug 12 07:56:28] VERBOSE[11440] logger.c: [Aug 12 07:56:28] VERBOSE[11440] logger.c: [Aug 12 07:56:28] VERBOSE[11440] logger.c: [Aug 12 07:56:28] VERBOSE[11440] logger.c: -- Processing IE 24 (cs0, Channel Identification)
[Aug 12 07:56:28] VERBOSE[11440] logger.c: q931.c:3641 q931_receive: call 32797 on channel 1 enters state 3 (Outgoing call Proceeding)
[Aug 12 07:56:28] DEBUG[11440] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 1
[Aug 12 07:56:28] VERBOSE[12476] logger.c: -- Zap/1-1 is proceeding passing it to SIP/204-0852ecd0
[Aug 12 07:56:29] VERBOSE[11440] logger.c: [Aug 12 07:56:29] VERBOSE[11440] logger.c: [Aug 12 07:56:29] VERBOSE[11440] logger.c: [Aug 12 07:56:29] VERBOSE[11440] logger.c: [Aug 12 07:56:29] VERBOSE[11440] logger.c: [Aug 12 07:56:29] VERBOSE[11440] logger.c: [Aug 12 07:56:29] VERBOSE[11440] logger.c: [Aug 12 07:56:29] VERBOSE[11440] logger.c: [Aug 12 07:56:29] VERBOSE[11440] logger.c: [Aug 12 07:56:29] VERBOSE[11440] logger.c: -- Processing IE 30 (cs0, Progress Indicator)
[Aug 12 07:56:29] VERBOSE[11440] logger.c: -- Processing IE 30 (cs0, Progress Indicator)
[Aug 12 07:56:29] VERBOSE[11440] logger.c: q931.c:3554 q931_receive: call 32797 on channel 1 enters state 4 (Call Delivered)
[Aug 12 07:56:29] VERBOSE[12476] logger.c: -- Zap/1-1 is ringing
[Aug 12 07:56:43] VERBOSE[11440] logger.c: [Aug 12 07:56:43] VERBOSE[11440] logger.c: [Aug 12 07:56:43] VERBOSE[11440] logger.c: [Aug 12 07:56:43] VERBOSE[11440] logger.c: [Aug 12 07:56:43] VERBOSE[11440] logger.c: [Aug 12 07:56:43] VERBOSE[11440] logger.c: -- Processing IE 41 (cs0, Date/Time)
[Aug 12 07:56:43] VERBOSE[11440] logger.c: q931.c:3584 q931_receive: call 32797 on channel 1 enters state 10 (Active)
[Aug 12 07:56:43] VERBOSE[11440] logger.c: > Protocol Discriminator: Q.931 (8) len=5
[Aug 12 07:56:43] VERBOSE[11440] logger.c: > Call Ref: len= 2 (reference 29/0x1D) (Originator)
[Aug 12 07:56:43] VERBOSE[11440] logger.c: > Message type: CONNECT ACKNOWLEDGE (15)
[Aug 12 07:56:43] DEBUG[11440] chan_zap.c: Echo cancellation already on
**[Aug 12 07:56:43] VERBOSE[12476] logger.c: -- Zap/1-1 answered SIP/204-0852ecd0
**[Aug 12 08:03:37] DEBUG[12476] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/1-1
**[Aug 12 08:03:37] DEBUG[12476] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call
**[Aug 12 08:03:37] VERBOSE[12476] logger.c: NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Active, peerstate Connect Request
[Aug 12 08:03:37] VERBOSE[12476] logger.c: q931.c:2973 q931_disconnect: call 32797 on channel 1 enters state 11 (Disconnect Request)
[Aug 12 08:03:37] VERBOSE[12476] logger.c: > Protocol Discriminator: Q.931 (8) len=9
[Aug 12 08:03:37] VERBOSE[12476] logger.c: > Call Ref: len= 2 (reference 29/0x1D) (Originator)
[Aug 12 08:03:37] VERBOSE[12476] logger.c: > Message type: DISCONNECT (69)
[Aug 12 08:03:37] VERBOSE[12476] logger.c: > [08 02 81 90]
[Aug 12 08:03:37] VERBOSE[12476] logger.c: > Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1)
[Aug 12 08:03:37] VERBOSE[12476] logger.c: > Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ]
[Aug 12 08:03:37] DEBUG[12476] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/1-1
[Aug 12 08:03:37] VERBOSE[12476] logger.c: -- Hungup 'Zap/1-1'
[Aug 12 08:03:37] VERBOSE[12476] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'SIP/204-0852ecd0' in macro 'dialout-trunk'
[Aug 12 08:03:37] VERBOSE[12476] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'SIP/204-0852ecd0'
[Aug 12 08:03:37] VERBOSE[12476] logger.c: -- Executing [h@macro-dialout-trunk:1] Macro("SIP/204-0852ecd0", "hangupcall|") in new stack
[Aug 12 08:03:37] VERBOSE[12476] logger.c: -- Executing [s@macro-hangupcall:1] ResetCDR("SIP/204-0852ecd0", "w") in new stack
[Aug 12 08:03:37] DEBUG[12476] app_macro.c: Executed application: ResetCDR
[Aug 12 08:03:37] VERBOSE[12476] logger.c: -- Executing [s@macro-hangupcall:2] NoCDR("SIP/204-0852ecd0", "") in new stack
[Aug 12 08:03:37] DEBUG[12476] app_macro.c: Executed application: NoCDR
[Aug 12 08:03:37] VERBOSE[12476] logger.c: -- Executing [s@macro-hangupcall:3] GotoIf("SIP/204-0852ecd0", "1?skiprg") in new stack
[Aug 12 08:03:37] VERBOSE[12476] logger.c: -- Goto (macro-hangupcall,s,6)
[Aug 12 08:03:37] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 08:03:37] VERBOSE[12476] logger.c: -- Executing [s@macro-hangupcall:6] GotoIf("SIP/204-0852ecd0", "1?skipblkvm") in new stack
[Aug 12 08:03:37] VERBOSE[12476] logger.c: -- Goto (macro-hangupcall,s,9)
[Aug 12 08:03:37] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 08:03:37] VERBOSE[12476] logger.c: -- Executing [s@macro-hangupcall:9] GotoIf("SIP/204-0852ecd0", "1?theend") in new stack
[Aug 12 08:03:37] VERBOSE[12476] logger.c: -- Goto (macro-hangupcall,s,11)
[Aug 12 08:03:37] DEBUG[12476] app_macro.c: Executed application: GotoIf
[Aug 12 08:03:37] VERBOSE[12476] logger.c: -- Executing [s@macro-hangupcall:11] Hangup("SIP/204-0852ecd0", "") in new stack
[Aug 12 08:03:37] VERBOSE[12476] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/204-0852ecd0' in macro 'hangupcall'
[Aug 12 08:03:37] VERBOSE[12476] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/204-0852ecd0'
[Aug 12 08:03:37] VERBOSE[11440] logger.c: [Aug 12 08:03:37] VERBOSE[11440] logger.c: [Aug 12 08:03:37] VERBOSE[11440] logger.c: [Aug 12 08:03:37] VERBOSE[11440] logger.c: q931.c:3759 q931_receive: call 32797 on channel 1 enters state 0 (Null)
[Aug 12 08:03:37] VERBOSE[11440] logger.c: NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Release Request
[Aug 12 08:03:37] VERBOSE[11440] logger.c: > Protocol Discriminator: Q.931 (8) len=9
[Aug 12 08:03:37] VERBOSE[11440] logger.c: > Call Ref: len= 2 (reference 29/0x1D) (Originator)
[Aug 12 08:03:37] VERBOSE[11440] logger.c: > Message type: RELEASE COMPLETE (90)
[Aug 12 08:03:37] VERBOSE[11440] logger.c: > [08 02 81 90]
[Aug 12 08:03:37] VERBOSE[11440] logger.c: > Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1)
[Aug 12 08:03:37] VERBOSE[11440] logger.c: > Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ]
[Aug 12 08:03:37] VERBOSE[11440] logger.c: NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Null
[Aug 12 08:03:37] VERBOSE[11440] logger.c: NEW_HANGUP DEBUG: Destroying the call, ourstate Null, peerstate Null

Chan_zap seems to be trying to disconnect the call.

‹ Trunk with webcalldirect ???? G729 license ›


solstars
Posts: 57
 Member Since:
2009-07-23
20 channel PRI? Is your D
Wed, 08/11/2010 - 10:36pm

20 channel PRI? Is your D channel set to the correct channel (usually 24) in your zap config? Did you set B channels 1-20 instead of 1-23? Which PRI card are you using?



jpcw
Posts: 15
 Member Since:
2007-12-30
T1's in Australia use 16 as
Wed, 08/11/2010 - 11:09pm

T1's in Australia use 16 as the D channel which is what is set.

Below are the relevant configs. Yes I realise I have 1-15,17-31. It was specifically said in other forum posts that I should define the entire 30 channel range even though I'm not using all. As the dropouts are occurring on valid channels (in the example above on channel 1) and after a call has been established for a few minutes I don't think this is causing a problem. At least 90% of the calls work perfectly fine without any dropouts which is what is really confusing me. PRI card is a Wildcard TE122 Card. Used to have a 4 port BRI card on the same indial number range so all the dialplan etc have not changed.

zaptel.conf
# Autogenerated by /usr/sbin/genzaptelconf -- do not hand edit
# Zaptel Configuration File
#
# This file is parsed by the Zaptel Configurator, ztcfg
#

# It must be in the module loading order

# Span 1: WCT1/0 "Wildcard TE122 Card 0" (MASTER) HDB3/CCS/CRC4
span=1,1,0,ccs,hdb3,crc4
# termtype: te
bchan=1-15,17-31
dchan=16

# Global data

loadzone = au
defaultzone = au

zapata.conf
;

; Zapata telephony interface
;

; Configuration file

[trunkgroups]

[channels]
usedistinctiveringdetection=no

resetinterval=never
language=en
context=from-pstn
;signalling=fxs_ks
rxwink=300 ; Atlas seems to use long (250ms) winks
;

; Whether or not to do distinctive ring detection on FXO lines
;

;usedistinctiveringdetection=yes

switchtype=euroisdn
;If you connect to a hicom PBX set your ISDN Numbering Plan Identifier to unknown.
pridialplan=unknown
priindication=outofband
pridialplan=unknown
prilocaldialplan=unknown

signalling=pri_cpe

busydetect=no
priindication=outofband

callerid=asreceived

callprogress=yes

usecallerid=yes
hidecallerid=no
callwaiting=yes
usecallingpres=yes
callwaitingcallerid=yes
threewaycalling=yes
transfer=yes
cancallforward=yes
callreturn=yes
echocancel=yes
echocancelwhenbridged=yes
echotraining=yes
rxgain=0.0
txgain=0.0
group=1
callgroup=1
pickupgroup=1
immediate=no
pridialplan=unknown

channel=>1-15
channel=>17-31

;faxdetect=both
faxdetect=incoming
;faxdetect=outgoing
;faxdetect=no

;Include genzaptelconf configs
#include zapata-auto.conf



solstars
Posts: 57
 Member Since:
2009-07-23
It sounds like your PRI may
Thu, 08/12/2010 - 4:09pm

It sounds like your PRI may be taking errors. Did your carrier do intrusive testing? I suppose it could be a bad T1 card on your end, but I doubt it. There isn't much you can do in the software that would cause random dropoffs like that.



jpcw
Posts: 15
 Member Since:
2007-12-30
No they haven’t done
Fri, 08/13/2010 - 12:06am

No they haven’t done intrusive testing yet. I’ll ask them to do so. Can’t see any sign of errors, any recommendation of where to look? Zttools doesn’t show any.
I’ve fairly much narrowed the issue down to the following two lines in the log. Unfortunatly doesn’t help me much

[Aug 13 15:35:41] DEBUG[27261] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/2-1
[Aug 13 15:35:41] DEBUG[27261] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call



Comment viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.