Problem in URA (External links)

luisvagner1 · December 5, 2018, 12:14pm

Good morning to everyone!

I have a problem in the URA, when I make an internal connection through the softphone it works cool the options of the URA, however when I dial out and I type any option (In case I typed Option 2), it gives error.

I’ve already checked everything and can not find where the problem is occurring, I need your help.

Below is the log of outbound connections to the URA (the problem occurs), and the log when it is an internal (working) extension.

Note I put xxxx in front of the numbers to hide here.

OUTLINE DISCUSSION FOR THE URA:
[Dec 4 15:39:24] VERBOSE[20011][C-00000066] pbx.c: Executing [xxxx3401@default:1] NoOp(“SIP/10.6.10.250-0000005a”, “LIGACAO DE 11xxxxx8883 PARA xxxx3401 NO CANAL SIP/10.6.10.250-0000005a”) in new stack

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] pbx.c: Executing [xxxx3401@default:2] Set(“SIP/10.6.10.250-0000005a”, “CHANNEL(language)=pt_BR”) in new stack

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] pbx.c: Executing [xxxx3401@default:3] Set(“SIP/10.6.10.250-0000005a”, “DSTORIGINAL=xxxx3401”) in new stack

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] pbx.c: Executing [xxxx3401@default:4] Set(“SIP/10.6.10.250-0000005a”, “AGISIGHUP=no”) in new stack

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] pbx.c: Executing [xxxx3401@default:5] UserEvent(“SIP/10.6.10.250-0000005a”, “SnepDial, Caller:11xxxxx8883,Dest:xxxx3401”) in new stack

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] pbx.c: Executing [xxxx3401@default:6] GotoIf(“SIP/10.6.10.250-0000005a”, “1?snep”) in new stack

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] pbx_builtins.c: Goto (default,xxxx3401,10)

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] pbx.c: Executing [xxxx3401@default:10] AGI(“SIP/10.6.10.250-0000005a”, “snep/snep.php”) in new stack

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/snep/snep.php

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] res_agi.c: snep/snep.php: 11xxxxx8883 -> xxxx3401 INFO (6):Connection attempt from 11xxxxx8883 (SIP/10.6.10.250-0000005a) to xxxx3401

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] res_agi.c: snep/snep.php: 11xxxxx8883 -> xxxx3401 INFO (6):Rule Date is Valid

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] res_agi.c: snep/snep.php: 11xxxxx8883 -> xxxx3401 INFO (6):Running the rule 64:Entrada URA (Externa)

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] res_agi.c: snep/snep.php: 11xxxxx8883 -> xxxx3401 INFO (6):Definindo centro de custos para 1.

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] res_agi.c: snep/snep.php: 11xxxxx8883 -> xxxx3401 INFO (6):Reescrevendo destino para s

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] res_agi.c: AGI Script Executing Application: (Goto) Options: (ura,s,1)

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] pbx_builtins.c: Goto (ura,s,1)

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] res_agi.c: snep/snep.php: 11xxxxx8883 -> xxxx3401 INFO (6):End of running the rule 64:Entrada URA (Externa) -> billsec: 0 -> duration: 0

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] res_agi.c: <SIP/10.6.10.250-0000005a>AGI Script snep/snep.php completed, returning 0

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] pbx.c: Executing [s@ura:1] NoOp(“SIP/10.6.10.250-0000005a”, “\\\\\---------- Entrada URA PRINCIPAL ----------//////////”) in new stack

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] pbx.c: Executing [s@ura:2] Playback(“SIP/10.6.10.250-0000005a”, “URA_SaudacaoMedcel”) in new stack

[Dec 4 15:39:24] VERBOSE[20011][C-00000066] file.c: <SIP/10.6.10.250-0000005a> Playing ‘URA_SaudacaoMedcel.slin’ (language ‘pt_BR’)

[Dec 4 15:39:27] VERBOSE[20011][C-00000066] pbx.c: Executing [s@ura:3] BackGround(“SIP/10.6.10.250-0000005a”, “URA_Opcao1”) in new stack

[Dec 4 15:39:27] VERBOSE[20011][C-00000066] file.c: <SIP/10.6.10.250-0000005a> Playing ‘URA_Opcao1.slin’ (language ‘pt_BR’)

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] pbx.c: Executing [2222@ura:1] NoOp(“SIP/10.6.10.250-0000005a”, “\\\\\---------- URA: Opcao DIGITOU O RAMAL ----------//////////”) in new stack

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] pbx.c: Executing [2222@ura:2] Goto(“SIP/10.6.10.250-0000005a”, “default,1”) in new stack

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] pbx_builtins.c: Goto (default,2222,1)

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] pbx.c: Executing [2222@default:1] NoOp(“SIP/10.6.10.250-0000005a”, “LIGACAO DE 11xxxxx8883 PARA 2222 NO CANAL SIP/10.6.10.250-0000005a”) in new stack

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] pbx.c: Executing [2222@default:2] Set(“SIP/10.6.10.250-0000005a”, “CHANNEL(language)=pt_BR”) in new stack

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] pbx.c: Executing [2222@default:3] Set(“SIP/10.6.10.250-0000005a”, “DSTORIGINAL=2222”) in new stack

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] pbx.c: Executing [2222@default:4] Set(“SIP/10.6.10.250-0000005a”, “AGISIGHUP=no”) in new stack

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] pbx.c: Executing [2222@default:5] UserEvent(“SIP/10.6.10.250-0000005a”, “SnepDial, Caller:11xxxxx8883,Dest:2222”) in new stack

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] pbx.c: Executing [2222@default:6] GotoIf(“SIP/10.6.10.250-0000005a”, “1?snep”) in new stack

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] pbx_builtins.c: Goto (default,2222,10)

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] pbx.c: Executing [2222@default:10] AGI(“SIP/10.6.10.250-0000005a”, “snep/snep.php”) in new stack

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/snep/snep.php

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] res_agi.c: snep/snep.php: 11xxxxx8883 -> 2222 INFO (6):Connection attempt from 11xxxxx8883 (SIP/10.6.10.250-0000005a) to 2222

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] res_agi.c: snep/snep.php: 11xxxxx8883 -> 2222 INFO (6):No rule found for this request: No rule found for this request

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] res_agi.c: <SIP/10.6.10.250-0000005a> Playing ‘invalid.slin’ (escape_digits=) (sample_offset 0) (language ‘pt_BR’)

[Dec 4 15:39:36] VERBOSE[20011][C-00000066] res_agi.c: snep/snep.php: Hanguping channel

[Dec 4 15:39:36] VERBOSE[20011][C-00000066] res_agi.c: <SIP/10.6.10.250-0000005a>AGI Script snep/snep.php completed, returning 4

[Dec 4 15:39:36] VERBOSE[20011][C-00000066] pbx.c: Spawn extension (default, 2222, 10) exited non-zero on ‘SIP/10.6.10.250-0000005a’

[Dec 4 15:39:36] VERBOSE[20011][C-00000066] pbx.c: Executing [h@default:1] Hangup(“SIP/10.6.10.250-0000005a”, “”) in new stack

[Dec 4 15:39:36] VERBOSE[20011][C-00000066] pbx.c: Spawn extension (default, h, 1) exited non-zero on ‘SIP/10.6.10.250-0000005a’

INTERNAL DIALING FOR THE URA THROUGH THE SFTPHONE:

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] pbx.c: Executing [666@default:1] NoOp(“SIP/2000-00000059”, “LIGACAO DE 2000 PARA 666 NO CANAL SIP/2000-00000059”) in new stack

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] pbx.c: Executing [666@default:2] Set(“SIP/2000-00000059”, “CHANNEL(language)=pt_BR”) in new stack

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] pbx.c: Executing [666@default:3] Set(“SIP/2000-00000059”, “DSTORIGINAL=666”) in new stack

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] pbx.c: Executing [666@default:4] Set(“SIP/2000-00000059”, “AGISIGHUP=no”) in new stack

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] pbx.c: Executing [666@default:5] UserEvent(“SIP/2000-00000059”, “SnepDial, Caller:2000,Dest:666”) in new stack

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] pbx.c: Executing [666@default:6] GotoIf(“SIP/2000-00000059”, “1?snep”) in new stack

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] pbx_builtins.c: Goto (default,666,10)

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] pbx.c: Executing [666@default:10] AGI(“SIP/2000-00000059”, “snep/snep.php”) in new stack

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/snep/snep.php

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] res_agi.c: snep/snep.php: 2000 -> 666 INFO (6):Identified source: 2000 (Snep_Exten)

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] res_agi.c: snep/snep.php: 2000 -> 666 INFO (6):Connection attempt from 2000 (SIP/2000-00000059) to 666

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] res_agi.c: snep/snep.php: 2000 -> 666 INFO (6):Rule Date is Valid

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] res_agi.c: snep/snep.php: 2000 -> 666 INFO (6):Running the rule 58:Entrada URA

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] res_agi.c: snep/snep.php: 2000 -> 666 INFO (6):Definindo centro de custos para 1.

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] res_agi.c: snep/snep.php: 2000 -> 666 INFO (6):Reescrevendo destino para s

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] res_agi.c: AGI Script Executing Application: (Goto) Options: (ura,s,1)

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] pbx_builtins.c: Goto (ura,s,1)

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] res_agi.c: snep/snep.php: 2000 -> 666 INFO (6):End of running the rule 58:Entrada URA -> billsec: 0 -> duration: 0

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] res_agi.c: <SIP/2000-00000059>AGI Script snep/snep.php completed, returning 0

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] pbx.c: Executing [s@ura:1] NoOp(“SIP/2000-00000059”, “\\\\\---------- Entrada URA PRINCIPAL ----------//////////”) in new stack

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] pbx.c: Executing [s@ura:2] Playback(“SIP/2000-00000059”, “URA_SaudacaoMedcel”) in new stack

[Dec 4 15:37:56] VERBOSE[19858][C-00000065] file.c: <SIP/2000-00000059> Playing ‘URA_SaudacaoMedcel.slin’ (language ‘pt_BR’)

[Dec 4 15:37:59] VERBOSE[19858][C-00000065] pbx.c: Executing [s@ura:3] BackGround(“SIP/2000-00000059”, “URA_Opcao1”) in new stack

[Dec 4 15:37:59] VERBOSE[19858][C-00000065] file.c: <SIP/2000-00000059> Playing ‘URA_Opcao1.slin’ (language ‘pt_BR’)

[Dec 4 15:38:05] VERBOSE[19858][C-00000065] pbx.c: Executing [2@ura:1] NoOp(“SIP/2000-00000059”, “\\\\\---------- URA: Opcao 2 ----------//////////”) in new stack

[Dec 4 15:38:05] VERBOSE[19858][C-00000065] pbx.c: Executing [2@ura:2] Playback(“SIP/2000-00000059”, “URA_Opcao2-1”) in new stack

[Dec 4 15:38:05] VERBOSE[19858][C-00000065] file.c: <SIP/2000-00000059> Playing ‘URA_Opcao2-1.slin’ (language ‘pt_BR’)

jcolp · December 5, 2018, 12:31pm

This appears to be the result of the AGI:

[Dec 4 15:39:32] VERBOSE[20011][C-00000066] res_agi.c: snep/snep.php: 11xxxxx8883 -> 2222 INFO (6):No rule found for this request: No rule found for this request

As this is not something that is included the people here don’t have insight into it, so you would need to investigate yourself.

luisvagner1 · December 5, 2018, 12:59pm

I typed the number 2 but it’s like he added more numbers …

jcolp · December 5, 2018, 1:00pm

Use DTMF logging (dtmf in logger.conf to console) and look at the RTP debug (rtp set debug on) to see what DTMF is actually being received. It may entirely be possible they are actually sending duplicate DTMF. You also did not specify the version of Asterisk in use.