Originate and priority with label

emabiz · March 13, 2023, 7:14pm

Hi,
is it possible to use originate application with a label?
I see in the documentation that:
Originate(tech_data,type,arg1,[arg2,[arg3,[timeout,[options]]]])
where arg3 is the priority.

I use it like this:
same => n,Originate(PJSIP/${ARG1},exten,join-conf,s,conf,10,a)

[join-conf]
exten => s,1,Verbose(“join-conf”)
exten => s,n,Playback(tt-monkeys)
exten => s,n(conf),ConfBridge(888)

then I expect to directly join in the conference, but I hear the monkeys before.
Is it expected?

Thank you

PitzKey · March 13, 2023, 10:05pm

Can you please share a call trace via pastebin?

emabiz · March 14, 2023, 7:17pm

[from-internal-custom]

include => call-everybody
include => add-conf
include => join-conf

[call-everybody]
exten => s,1,Verbose(“call everybody”)
#same => n,GotoIfTime(17:00-22:00,,,*?end)
#same => n,Gosub(add-conf,s,1(100))
#same => n,Gosub(add-conf,s,1(110))
same => n,Gosub(add-conf,s,1(120))
#same => n,Gosub(add-conf,s,1(124))
#same => n,Gosub(add-conf,s,1(130))
#same => n,Gosub(add-conf,s,1(150))
exten => s,n,Goto(join-conf,s,conf)

[add-conf]
exten => s,1,GotoIf($[${CALLERID(num)} = ${ARG1} ]?back)
#same => n,Verbose($["Send Originate cmd from “${CALLERID(num)}” to "${ARG1}])
same => n,Verbose(“foo1”)
#same => n,Originate(PJSIP/${ARG1},exten,join-conf,s,conf,10,a,c,n)
same => n,Originate(PJSIP/${ARG1},exten,join-conf,s,conf,10,a)
same => n,Verbose(“foo2”)
same => n(back),Return()

[join-conf]
exten => s,1,Verbose(“join-conf”)
same => n,Playback(tt-weasels)
exten => s,n(conf),ConfBridge(888)

The last Goto inside call-everybody context works as expected, the Originate doesn’t jump to conf but at the beginning of join-conf context

PitzKey · March 15, 2023, 6:31pm

This is a SIP trace. Please see wiki how to obtain a call trace: Providing Great Debug - Support Services - Documentation

emabiz · March 16, 2023, 6:02am

Hi,
first of all I discovered that CDR reports were not working (I am using a raspberry).
Then I compiled and configured mariadb odbc connector and I can see CDR now.
I made a call and I can see the call reported in CDR Reports.
But inside /var/log/asterisk/full I have only res_pjsip_logger.c logs.
Then if I follow the instructions to get the call trace I get no info.
Inside Settings>Asterisk LogFiles Settings it seems correctly configured (I didn’ touch the default)
How can I do to give you the requested info?
Maybe there is something else that was not correctly configured on raspberry during the installation…

PitzKey · March 16, 2023, 7:16am

I’m not familiar with RasPBX.

Does it show the Asterisk logs in the console?

emabiz · March 17, 2023, 5:29am

It is not RasPBX.
It is a plain raspbian where I installed Asterisk/FreePBX following some guides (mainly this https://francoconidi.it/asterisk-freepbx-su-raspberry-pi-4-e-raspberry-pi-os-buster/), adapting the versions to Asterisk 20/FreePbx 16.
I see only sip logs also in the console.
I checked this:
Bug in Asterisk Logfiles Module ver 15.0.4
But it seems not the case.

Permissisons on folder/files seem ok:

I am a bit lost

emabiz · March 17, 2023, 5:45am

I rebooted the raspberry and initially in the full lof file I see this:

Is it correct?

emabiz · March 17, 2023, 5:51am

This seems similar, but suggested solution at the end doesn’t work:

PitzKey · March 17, 2023, 7:24am

Which version of log files do you have?

emabiz · March 18, 2023, 7:23am

I have these versions related to reports:

This mornig I’ve seen some updates available for some modules (not related to logs) then I decided to update.
After reboot I can see the following in full log:

After that I see only sip logs reported in the file, nothing more

emabiz · March 18, 2023, 7:42am

I tried to enable security log in settings and it starts logging security info, then it seems that only call trace doesn’t work

emabiz · March 18, 2023, 7:48am

Is the sintax of above Originate correct, in your opinion?

david55 · March 18, 2023, 10:32am

Dialplan tracing requires at least verbosity 3. It is possible that RasPBX sets it lower to reduce wear on the SD card, but it can be turned up.

On the original question. I’m not surprised that it doesn’t work, and I would have tested it before relying on it. However, I can’t think of any fundamental reason for its not being possible to make it work. Without testing, I wouldn’t want to try to use it when the context changed - originate always implies a fresh context as there is no connection between the context that originate was issued, even if issued by dialplan, and the context used for execution of dialplan on the created channel.

The ability to jump to an internal label in another modules is not something that modern programming languages provide (I half remember COBOL allowing it). Dijkstra’s “Gotos considered harmful” paper was published in the 1960s, and the general view now is that the ability to arrive somewhere in the code without any indication of possible origins makes the code difficult to analyze, and therefore to maintain.

emabiz · March 19, 2023, 7:05am

Hi,
thank you for your suggestion, on raspberry verbosity is off.
Setting verbosity=3 I started see something.
Then I tried the following simplified example:


[from-internal-custom]

include => originate-test
include => originate-dest

[originate-test]
exten => 777,1,Verbose("originate-test")
same  => n,Originate(PJSIP/120,exten,originate-dest,s,m,20,a)

[originate-dest]
exten => s,1,Verbose("originate-dest")
exten => s,n(w),Playback(tt-weasels)
exten => s,n(m),Playback(tt-monkeys)

In the logs I see this:

[2023-03-19 07:45:00] VERBOSE[16836] dial.c: PJSIP/120-0000001c is ringing
[2023-03-19 07:45:06] VERBOSE[16836] dial.c: PJSIP/120-0000001c answered
[2023-03-19 07:45:06] VERBOSE[16836][C-0000001a] pbx.c: Executing [[email protected]:1] Verbose("PJSIP/120-0000001c", ""originate-dest"") in new stack
[2023-03-19 07:45:06] VERBOSE[16836][C-0000001a] pbx.c: Executing [[email protected]:2] Playback("PJSIP/120-0000001c", "tt-weasels") in new stack
[2023-03-19 07:45:06] VERBOSE[16836][C-0000001a] file.c: <PJSIP/120-0000001c> Playing 'tt-weasels.ulaw' (language 'en')
[2023-03-19 07:45:09] VERBOSE[16836][C-0000001a] pbx.c: Executing [[email protected]:3] Playback("PJSIP/120-0000001c", "tt-monkeys") in new stack
[2023-03-19 07:45:09] VERBOSE[16836][C-0000001a] file.c: <PJSIP/120-0000001c> Playing 'tt-monkeys.ulaw' (language 'en')
[2023-03-19 07:45:25] VERBOSE[16836][C-0000001a] pbx.c: Auto fallthrough, channel 'PJSIP/120-0000001c' status is 'UNKNOWN'

And I hear weasels instead of monkey.
If the syntax on my Originate is correct, but it is not possible to specify a priority, why is it possible to set arg3 as priority?

https://wiki.asterisk.org/wiki/display/AST/Asterisk+20+Application_Originate

Thank you

PitzKey · March 19, 2023, 11:02am

It looks like Asterisk is ignoring the label portion so it will start at the first priority of that context.

;extensions_custom.conf
[originate-alpha]
exten => s,1,Noop(Started Originate)
exten => s,n,Answer()
exten => s,n,Wait(5)
exten => s,n,Hangup()

[originate-label]
exten => s,1,Noop(Originate Label Context)
exten => s,n,Noop(This is the second line)
exten => s,n(bazinga),Noop(This is the third line with a label)
exten => s,n,Hangup()

;test2.call
Channel: local/[email protected]
Callerid: Mark <1018>
WaitTime: 5
Context: originate-label
Extension: s
Priority: bazinga

Asterisk log:

;Asterisk ignores the label 'bazinga'
[2023-03-19 06:45:59] WARNING[71138] pbx_spool.c: Invalid priority at line 6 of /var/spool/asterisk/outgoing/test2.call
[2023-03-19 06:45:59] WARNING[71138] pbx_spool.c: Unable to set utime on /var/spool/asterisk/outgoing/test2.call: Operation not permitted

;Asterisk calls the first leg
[2023-03-19 06:45:59] VERBOSE[48493] pbx_spool.c: Attempting call on local/[email protected] for [email protected]:1 (Retry 1)
[2023-03-19 06:45:59] VERBOSE[48493] dial.c: Called [email protected]
[2023-03-19 06:45:59] VERBOSE[48494][C-00000026] pbx.c: Executing [[email protected]:1] NoOp("Local/[email protected];2", "Started Originate") in new stack
[2023-03-19 06:45:59] VERBOSE[48494][C-00000026] pbx.c: Executing [[email protected]:2] Answer("Local/[email protected];2", "") in new stack
[2023-03-19 06:45:59] VERBOSE[48493] dial.c: Local/[email protected];1 answered

;Asterisk calls the second leg, note it will start with the first priority
[2023-03-19 06:45:59] VERBOSE[48493][C-00000027] pbx.c: Executing [[email protected]:1] NoOp("Local/[email protected];1", "Originate Label Context") in new stack
[2023-03-19 06:45:59] VERBOSE[48493][C-00000027] pbx.c: Executing [[email protected]:2] NoOp("Local/[email protected];1", "This is the second line") in new stack
[2023-03-19 06:45:59] VERBOSE[48493][C-00000027] pbx.c: Executing [[email protected]:3] NoOp("Local/[email protected];1", "This is the third line with a label") in new stack
[2023-03-19 06:45:59] VERBOSE[48493][C-00000027] pbx.c: Executing [[email protected]:4] Hangup("Local/[email protected];1", "") in new stack
[2023-03-19 06:45:59] VERBOSE[48493][C-00000027] pbx.c: Spawn extension (originate-label, s, 4) exited non-zero on 'Local/[email protected];1'
[2023-03-19 06:45:59] NOTICE[48493][C-00000027] pbx_spool.c: Call completed to local/[email protected]
[2023-03-19 06:45:59] VERBOSE[48494][C-00000026] pbx.c: Spawn extension (originate-alpha, s, 2) exited non-zero on 'Local/[email protected];2'

However, if you use Goto() it works fine, I suspect that this is a bug within Asterisk.

This is when using Goto

;extensions_custom.conf
[originate-alpha]
exten => s,1,Noop(Started Originate)
exten => s,n,Answer()
exten => s,n,Wait(5)
exten => s,n,Hangup()

[originate-mid]
exten => s,1,Noop(Originate Mid Context)
exten => s,n,Goto(originate-label,s,${OLABEL})

[originate-label]
exten => s,1,Noop(Originate Label Context)
exten => s,n,Noop(This is the second line)
exten => s,n(bazinga),Noop(This is the third line with a label)
exten => s,n,Hangup()

;test3.call
Channel: local/[email protected]
Callerid: Mark <1018>
WaitTime: 5
Context: originate-mid
Extension: s
Priority: 1
SetVar: OLABEL=bazinga

Asterisk logs:

;Asterisk calls the first leg
[2023-03-19 06:54:36] VERBOSE[49172] pbx_spool.c: Attempting call on local/[email protected] for [email protected]:1 (Retry 1)
[2023-03-19 06:54:36] VERBOSE[49172] dial.c: Called [email protected]
[2023-03-19 06:54:36] VERBOSE[49173][C-00000028] pbx.c: Executing [[email protected]:1] NoOp("Local/[email protected];2", "Started Originate") in new stack
[2023-03-19 06:54:36] VERBOSE[49173][C-00000028] pbx.c: Executing [[email protected]:2] Answer("Local/[email protected];2", "") in new stack
[2023-03-19 06:54:36] VERBOSE[49172] dial.c: Local/[email protected];1 answered
[2023-03-19 06:54:36] VERBOSE[49172][C-00000029] pbx.c: Executing [[email protected]:1] NoOp("Local/[email protected];1", "Originate Mid Context") in new stack

;The mid-originate sends the call to originate-label,s,bazinga (the label is used from the variable)
[2023-03-19 06:54:36] VERBOSE[49172][C-00000029] pbx.c: Executing [[email protected]:2] Goto("Local/[email protected];1", "originate-label,s,bazinga") in new stack
[2023-03-19 06:54:36] VERBOSE[49172][C-00000029] pbx_builtins.c: Goto (originate-label,s,3)

;It successfully goes to the label, which is priority 3
[2023-03-19 06:54:36] VERBOSE[49172][C-00000029] pbx.c: Executing [[email protected]:3] NoOp("Local/[email protected];1", "This is the third line with a label") in new stack
[2023-03-19 06:54:36] VERBOSE[49172][C-00000029] pbx.c: Executing [[email protected]:4] Hangup("Local/[email protected];1", "") in new stack
[2023-03-19 06:54:36] VERBOSE[49172][C-00000029] pbx.c: Spawn extension (originate-label, s, 4) exited non-zero on 'Local/[email protected];1'
[2023-03-19 06:54:36] NOTICE[49172][C-00000029] pbx_spool.c: Call completed to local/[email protected]
[2023-03-19 06:54:36] VERBOSE[49173][C-00000028] pbx.c: Spawn extension (originate-alpha, s, 2) exited non-zero on 'Local/[email protected]nate-alpha-00000005;2'

So again, this looks to be like an Asterisk bug. The workaround would be to use a “pre” context that handles the Goto with a Label.

david55 · March 19, 2023, 12:28pm

Looks to me like a missing feature, not a bug.

You haven’t shown that it doesn’t accept a priority, only that it doesn’t accept a label as a priority.

PitzKey · March 19, 2023, 12:53pm

https://wiki.asterisk.org/wiki/display/AST/Asterisk+Call+Files#:~:text=Priority%3A%20<priority>%20-%20The%20priority%20of%20the%20specified%20extension%3B%20(numeric%20or%20label)

Priority: <priority> - The priority of the specified extension; (numeric or label)

BlazeStudios · March 19, 2023, 1:02pm

Call files are not the same and do things differently. For the longest time the dialplan version of Originate was highly restricted feature wise compared to both its AMI and Call Files counterparts. Only in the last 2 years has dialplan based Originate been updated to match some of those feature sets (codecs and some other options). Possible the label hasn’t been part of that.

If you are originating to some code that is 10 lines you can just use priority numbers the enter time.

david55 · March 19, 2023, 1:38pm

The call file code cannot handle anything but positive integers:

github.com

asterisk/asterisk/blob/master/pbx/pbx_spool.c#L247


      
          			ast_log(LOG_WARNING, "Invalid max retries at line %d of %s\n", lineno, o->fn);
          			o->maxretries = 0;
          		}
          	} else if (!strcasecmp(line, "codecs")) {
          		ast_format_cap_update_by_allow_disallow(o->capabilities, c, 1);
          	} else if (!strcasecmp(line, "context")) {
          		ast_string_field_set(o, context, c);
          	} else if (!strcasecmp(line, "extension")) {
          		ast_string_field_set(o, exten, c);
          	} else if (!strcasecmp(line, "priority")) {
          		if ((sscanf(c, "%30d", &o->priority) != 1) || (o->priority < 1)) {
          			ast_log(LOG_WARNING, "Invalid priority at line %d of %s\n", lineno, o->fn);
          			o->priority = 1;
          		}
          	} else if (!strcasecmp(line, "retrytime")) {
          		if ((sscanf(c, "%30d", &o->retrytime) != 1) || (o->retrytime < 1)) {
          			ast_log(LOG_WARNING, "Invalid retrytime at line %d of %s\n", lineno, o->fn);
          			o->retrytime = 300;
          		}
          	} else if (!strcasecmp(line, "waittime")) {
          		if ((sscanf(c, "%30d", &o->waittime) != 1) || (o->waittime < 1)) {

This part of the code has been unchanged since version 1.0! It probably gets squatters’ rights. I presume that labels came in later.