1. This site uses cookies. By continuing to use this site, you are agreeing to our use of cookies. Learn More.
  2. If you had a PIAF Forum account in the vBulletin days, log in with your old credentials. Otherwise, sign up again and we'll get you back in business as soon as we can.
  3. Guest: We think the problem with locked threads from long message subjects has been resolved. Post a link here if you still see a problem.

Call dropping Rhino PRI

Discussion in 'Help' started by goblin, Jan 11, 2012.

  1. goblin Member

    System summary;

    PBX in a Flash Version = 1.7.5.7 Running on *HARDWARE*
    FreePBX Version = 2.8.1.4
    Running Asterisk Version = 1.8.6.0
    Dahdi Source Version = 2.5.0.2+2.5.0.2
    Kernel Version = 2.6.18-274.3.1.el5 - 32 Bit

    Hi there, i just installed a piaf system with a Rhino R1T1 PRI card and im experiencing call drops randomlly specially when the call is over 15 minutes, is there any whay that someone can point me in the right direction on how to star identifying where the issue is?

    I already spoke with my carrier COX and they se every thing ok in the T1 Circuit.

    Hope you guys can helpme out on this.
  2. atsak Guru

    You'll need to post the contents of the log (/var/logs/asterisk/full) which shows one of the dropped calls.
  3. gregc Guru

    15 minutes... sounds like session timer issues but that is sip related. What phones are you using? Perhaps there is an issue with the phone side of it with timer settings.

    -Greg
  4. goblin Member

    Hi there im using Aastra 6757i, 6731i



    This is the log where a call was disconected.



    2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Goto (macro-dial-one,s,23)
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [s@macro-dial-one:23] GotoIf("DAHDI/i1/9098390764-353", "1?next3:continue") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Goto (macro-dial-one,s,24)
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [s@macro-dial-one:24] ExecIf("DAHDI/i1/9098390764-353", "0?Set(DIALSTATUS_CW=BUSY)") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [s@macro-dial-one:25] GotoIf("DAHDI/i1/9098390764-353", "0?nodial") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [s@macro-dial-one:26] GosubIf("DAHDI/i1/9098390764-353", "1?dstring,1:dlocal,1") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [dstring@macro-dial-one:1] Set("DAHDI/i1/9098390764-353", "DSTRING=") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [dstring@macro-dial-one:2] Set("DAHDI/i1/9098390764-353", "DEVICES=317") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [dstring@macro-dial-one:3] ExecIf("DAHDI/i1/9098390764-353", "0?Return()") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [dstring@macro-dial-one:4] ExecIf("DAHDI/i1/9098390764-353", "0?Set(DEVICES=17)") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [dstring@macro-dial-one:5] Set("DAHDI/i1/9098390764-353", "LOOPCNT=1") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [dstring@macro-dial-one:6] Set("DAHDI/i1/9098390764-353", "ITER=1") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [dstring@macro-dial-one:7] Set("DAHDI/i1/9098390764-353", "THISDIAL=SIP/317") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [dstring@macro-dial-one:8] GosubIf("DAHDI/i1/9098390764-353", "1?zap2dahdi,1") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [zap2dahdi@macro-dial-one:1] ExecIf("DAHDI/i1/9098390764-353", "0?Return()") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [zap2dahdi@macro-dial-one:2] Set("DAHDI/i1/9098390764-353", "NEWDIAL=") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [zap2dahdi@macro-dial-one:3] Set("DAHDI/i1/9098390764-353", "LOOPCNT2=1") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [zap2dahdi@macro-dial-one:4] Set("DAHDI/i1/9098390764-353", "ITER2=1") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [zap2dahdi@macro-dial-one:5] Set("DAHDI/i1/9098390764-353", "THISPART2=SIP/317") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [zap2dahdi@macro-dial-one:6] ExecIf("DAHDI/i1/9098390764-353", "0?Set(THISPART2=DAHDI/317)") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [zap2dahdi@macro-dial-one:7] Set("DAHDI/i1/9098390764-353", "NEWDIAL=SIP/317&") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [zap2dahdi@macro-dial-one:8] Set("DAHDI/i1/9098390764-353", "ITER2=2") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [zap2dahdi@macro-dial-one:9] GotoIf("DAHDI/i1/9098390764-353", "0?begin2") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [zap2dahdi@macro-dial-one:10] Set("DAHDI/i1/9098390764-353", "THISDIAL=SIP/317") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [zap2dahdi@macro-dial-one:11] Return("DAHDI/i1/9098390764-353", "") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [dstring@macro-dial-one:9] Set("DAHDI/i1/9098390764-353", "DSTRING=SIP/317&") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [dstring@macro-dial-one:10] Set("DAHDI/i1/9098390764-353", "ITER=2") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [dstring@macro-dial-one:11] GotoIf("DAHDI/i1/9098390764-353", "0?begin") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [dstring@macro-dial-one:12] Set("DAHDI/i1/9098390764-353", "DSTRING=SIP/317") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [dstring@macro-dial-one:13] Return("DAHDI/i1/9098390764-353", "") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [s@macro-dial-one:27] GotoIf("DAHDI/i1/9098390764-353", "0?nodial") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [s@macro-dial-one:28] GotoIf("DAHDI/i1/9098390764-353", "1?skiptrace") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Goto (macro-dial-one,s,30)
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [s@macro-dial-one:30] Set("DAHDI/i1/9098390764-353", "D_OPTIONS=tr") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [s@macro-dial-one:31] ExecIf("DAHDI/i1/9098390764-353", "0?SIPAddHeader(Alert-Info: )") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [s@macro-dial-one:32] ExecIf("DAHDI/i1/9098390764-353", "0?SIPAddHeader()") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [s@macro-dial-one:33] ExecIf("DAHDI/i1/9098390764-353", "0?Set(CHANNEL(musicclass)=)") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [s@macro-dial-one:34] GosubIf("DAHDI/i1/9098390764-353", "0?qwait,1") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [s@macro-dial-one:35] Set("DAHDI/i1/9098390764-353", "__CWIGNORE=") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [s@macro-dial-one:36] Set("DAHDI/i1/9098390764-353", "__KEEPCID=TRUE") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] pbx.c: -- Executing [s@macro-dial-one:37] Dial("DAHDI/i1/9098390764-353", "SIP/317,45,tr") in new stack
    [2012-01-11 16:09:57] VERBOSE[1753] netsock.c: == Using UDPTL TOS bits 184
    [2012-01-11 16:09:57] VERBOSE[1753] netsock.c: == Using UDPTL CoS mark 5
    [2012-01-11 16:09:57] VERBOSE[1753] netsock2.c: == Using SIP RTP TOS bits 184
    [2012-01-11 16:09:57] VERBOSE[1753] netsock2.c: == Using SIP RTP CoS mark 5
    [2012-01-11 16:09:57] VERBOSE[1753] app_dial.c: -- Called SIP/317
  5. atsak Guru

    Close - need the hangup portion of the log :)
  6. goblin Member

    Sorry here is the last part.

    2012-01-11 16:09:57] VERBOSE[1753] app_dial.c: -- SIP/317-000008ff is ringing
    [2012-01-11 16:09:57] VERBOSE[1753] app_dial.c: -- SIP/317-000008ff is ringing
    [2012-01-11 16:10:00] VERBOSE[6173] netsock.c: == Using UDPTL TOS bits 184
    [2012-01-11 16:10:00] VERBOSE[6173] netsock.c: == Using UDPTL CoS mark 5
    [2012-01-11 16:10:00] VERBOSE[6173] netsock2.c: == Using SIP RTP TOS bits 184
    [2012-01-11 16:10:00] VERBOSE[6173] netsock2.c: == Using SIP RTP CoS mark 5
    [2012-01-11 16:10:00] VERBOSE[1797] pbx.c: -- Executing [308@from-internal:1] Macro("SIP/304-00000900", "exten-vm,308,308") in new stack
  7. atsak Guru

    No, that still doesn't show the actual hangup, thats where the call was initiated. Look for something that says "hangup" perhaps with the cause = XX after it.
  8. gregc Guru

    It could be a ways down the list. Find 1753 (which is that call's particular ID) and post up that just them.

    -Greg
  9. goblin Member

    Here is a part of a log where i see the hangup event, today we had a lot of dropped calls...

    Hope you guys can help me out on this.


    [2012-01-12 17:17:44] VERBOSE[325] pbx.c: -- Goto (macro-hangupcall,s,9)
    [2012-01-12 17:17:44] VERBOSE[325] pbx.c: -- Executing [s@macro-hangupcall:9] Hangup("Local/309@from-queue-c261;2", "") in new stack
    [2012-01-12 17:17:44] VERBOSE[325] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'Local/309@from-queue-c261;2' in macro 'hangupcall'
    [2012-01-12 17:17:44] VERBOSE[325] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'Local/309@from-queue-c261;2'
    [2012-01-12 17:17:44] VERBOSE[32504] app_queue.c: -- Nobody picked up in 0 ms
    [2012-01-12 17:17:44] VERBOSE[324] app_dial.c: -- Called SIP/306
    [2012-01-12 17:17:44] VERBOSE[32504] app_queue.c: -- Local/306@from-queue-5eb0;1 is ringing
    [2012-01-12 17:17:44] VERBOSE[32504] app_queue.c: -- Local/306@from-queue-5eb0;1 connected line has changed. Saving it until answer for DAHDI/i1/6198529616-69b
    [2012-01-12 17:17:44] VERBOSE[326] app_mixmonitor.c: == Begin MixMonitor Recording Local/309@from-queue-c261;2
    [2012-01-12 17:17:44] VERBOSE[326] app_mixmonitor.c: == End MixMonitor Recording Local/309@from-queue-c261;2
    [2012-01-12 17:17:44] VERBOSE[324] app_dial.c: -- SIP/306-0000112c is ringing
    [2012-01-12 17:17:44] VERBOSE[32504] app_queue.c: -- Local/306@from-queue-5eb0;1 is ringing
    [2012-01-12 17:17:56] VERBOSE[6154] sig_pri.c: -- Span 1: Channel 0/2 got hangup request, cause 16
    [2012-01-12 17:17:56] VERBOSE[314] res_musiconhold.c: -- Stopped music on hold on DAHDI/i1/6197786232-69f
    [2012-01-12 17:17:56] VERBOSE[314] pbx.c: == Spawn extension (ext-queues, 650, 11) exited non-zero on 'DAHDI/i1/6197786232-69f'
    [2012-01-12 17:17:56] VERBOSE[314] pbx.c: -- Executing [h@ext-queues:1] Macro("DAHDI/i1/6197786232-69f", "hangupcall,") in new stack
    [2012-01-12 17:17:56] VERBOSE[314] pbx.c: -- Executing [s@macro-hangupcall:1] GotoIf("DAHDI/i1/6197786232-69f", "1?skiprg") in new stack
    [2012-01-12 17:17:56] VERBOSE[314] pbx.c: -- Goto (macro-hangupcall,s,4)
    [2012-01-12 17:17:56] VERBOSE[314] pbx.c: -- Executing [s@macro-hangupcall:4] GotoIf("DAHDI/i1/6197786232-69f", "0?skipblkvm") in new stack
    [2012-01-12 17:17:56] VERBOSE[314] pbx.c: -- Executing [s@macro-hangupcall:5] NoOp("DAHDI/i1/6197786232-69f", "Cleaning Up Block VM Flag: BLKVM/650/DAHDI/i1/6197786232-69f") in new stack
    [2012-01-12 17:17:56] VERBOSE[314] pbx.c: -- Executing [s@macro-hangupcall:6] NoOp("DAHDI/i1/6197786232-69f", "Deleting: BLKVM/650/DAHDI/i1/6197786232-69f TRUE") in new stack
    [2012-01-12 17:17:56] VERBOSE[314] pbx.c: -- Executing [s@macro-hangupcall:7] GotoIf("DAHDI/i1/6197786232-69f", "1?theend") in new stack
    [2012-01-12 17:17:56] VERBOSE[314] pbx.c: -- Goto (macro-hangupcall,s,9)
    [2012-01-12 17:17:56] VERBOSE[314] pbx.c: -- Executing [s@macro-hangupcall:9] Hangup("DAHDI/i1/6197786232-69f", "") in new stack
    [2012-01-12 17:17:56] VERBOSE[314] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'DAHDI/i1/6197786232-69f' in macro 'hangupcall'
    [2012-01-12 17:17:56] VERBOSE[314] pbx.c: == Spawn extension (ext-queues, h, 1) exited non-zero on 'DAHDI/i1/6197786232-69f'
    [2012-01-12 17:17:56] DEBUG[314] sig_pri.c: sig_pri_hangup 2
    [2012-01-12 17:17:56] DEBUG[314] sig_pri.c: Not yet hungup... Calling hangup once with icause, and clearing call
    [2012-01-12 17:17:56] VERBOSE[314] chan_dahdi.c: -- Hungup 'DAHDI/i1/6197786232-69f'
    [2012-01-12 17:18:00] VERBOSE[6154] sig_pri.c: -- Accepting call from '6197786232' to '6881' on channel 0/2, span 1
    [2012-01-12 17:18:00] VERBOSE[327] pbx.c: -- Executing [6881@from-pstn:1] Set("DAHDI/i1/6197786232-6a0", "__FROM_DID=6881") in new stack
    [2012-01-12 17:18:00] VERBOSE[327] pbx.c: -- Executing [6881@from-pstn:2] Gosub("DAHDI/i1/6197786232-6a0", "app-blacklist-check,s,1") in new stack
    [2012-01-12 17:18:00] VERBOSE[327] pbx.c: -- Executing [s@app-blacklist-check:1] GotoIf("DAHDI/i1/6197786232-6a0", "0?blacklisted") in new stack
    [2012-01-12 17:18:00] VERBOSE
  10. atsak Guru

    Span 1: Channel 0/2 got hangup request, cause 16

    This means that it was a normal call clearing, which indicates a timer ended the call (ie Asterisk ended the call because it was supposed to). The rest of the log seems to show the person was on hold for too long and the system hung up but I still can't see quite enough of the log to know for sure. Are all the hangups cause 16?
  11. goblin Member

    Im not able to find the exact log for those kind of calls, but there was cause 47 to.

    Where to i can change the timer so we can reduce the cause 16??
  12. goblin Member

    Sorry for the delay heres a log of what im experiencing, know i have a lot of calls during the day that are getting disconnected even internal calls. And dont have a clue where the problem is.

    Attached Files:

  13. atsak Guru

    Cause 16 means the system is sending DAHDI a request to hang up the phone line. You're correct in your confusion about what is causing that. However, the log you sent still doesn't have the complete end to end call, it's just showing the inbound call and the hangup request, nothing before or after. What we really need is something like what you sent the first time, but combined with what you attached. This log is missing all kinds of information. Maybe it's because you touched it with a Mac and I don't use those.
  14. gregc Guru

    Not sure where or how to fix it, but if it is happening on internal calls as well, it sounds like a sip issue with your phones (be it a timer or otherwise).

    What is the topology like? PBX and phones all on the same switch? What model of switch? Reason I ask is I had a similar issue with flowroute (SIP connected) a while back. Here is some info on that:

    You can then view that dump file in wireshark.

    What was happening:

    Hope this helps.

    -Greg

Share This Page