Paging Failure

Peri · August 8, 2007, 6:57pm

I’m running Freepbx 2.3.0beta2.10 on Asterisk 1.2.22 and paging has stopped working. I dial 610 (my first paging group) and get “call failed”.

Here’s the CLI output.

[code:1]
Verbosity is at least 6
– Executing Set(“SIP/236-b740ce80”, “_FORCE_PAGE=0”) in new stack
– Executing Macro(“SIP/236-b740ce80”, “user-callerid|”) in new stack
– Executing NoOp(“SIP/236-b740ce80”, “user-callerid: device 236”) in new stack
– Executing Set(“SIP/236-b740ce80”, “AMPUSER=236”) in new stack
– Executing GotoIf(“SIP/236-b740ce80”, “0?report”) in new stack
– Executing GotoIf(“SIP/236-b740ce80”, “0?start”) in new stack
– Executing Set(“SIP/236-b740ce80”, “REALCALLERIDNUM=236”) in new stack
– Executing NoOp(“SIP/236-b740ce80”, “REALCALLERIDNUM is 236”) in new stack
– Executing Set(“SIP/236-b740ce80”, “AMPUSER=236”) in new stack
– Executing Set(“SIP/236-b740ce80”, “AMPUSERCIDNAME=Clint Sheridan”) in new stack
– Executing GotoIf(“SIP/236-b740ce80”, “0?report”) in new stack
– Executing Set(“SIP/236-b740ce80”, “AMPUSERCID=236”) in new stack
– Executing Set(“SIP/236-b740ce80”, “CALLERID(all)=“Clint Sheridan” <236>”) in new stack
– Executing Set(“SIP/236-b740ce80”, “REALCALLERIDNUM=236”) in new stack
– Executing NoOp(“SIP/236-b740ce80”, "TTL: ARG1: ") in new stack
– Executing GotoIf(“SIP/236-b740ce80”, “0?continue”) in new stack
– Executing Set(“SIP/236-b740ce80”, “__TTL=64”) in new stack
– Executing GotoIf(“SIP/236-b740ce80”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,23)
– Executing NoOp(“SIP/236-b740ce80”, “Using CallerID “Clint Sheridan” <236>”) in new stack
– Executing Set(“SIP/236-b740ce80”, “_AMPUSER=236”) in new stack
== Spawn extension (from-internal, 610, 4) exited non-zero on ‘SIP/236-b740ce80’
– Executing Macro(“SIP/236-b740ce80”, “hangupcall”) in new stack
– Executing ResetCDR(“SIP/236-b740ce80”, “w”) in new stack
– Executing NoCDR(“SIP/236-b740ce80”, “”) in new stack
– Executing GotoIf(“SIP/236-b740ce80”, “1?skiprg”) in new stack
– Goto (macro-hangupcall,s,6)
– Executing GotoIf(“SIP/236-b740ce80”, “1?skipblkvm”) in new stack
– Goto (macro-hangupcall,s,9)
– Executing GotoIf(“SIP/236-b740ce80”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,11)
– Executing Hangup(“SIP/236-b740ce80”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/236-b740ce80’ in macro ‘hangupcall’
[/code:1]

And here’s the paging group out of extensions_additional.conf

[code:1]
exten => 610,1,Set(_FORCE_PAGE=0)
exten => 610,n,Macro(user-callerid,)
exten => 610,n,Set(_AMPUSER=${AMPUSER})
exten => 610,n,Page(LOCAL/PAGE290@ext-paging&LOCAL/PAGE280@ext-paging&LOCAL/PAGE279@ext-paging&LOCAL/PAGE278@ext-paging&LOCAL/PAGE277@ext-paging&LOCAL/PAGE262@ext-paging&LOCAL/PAGE261@ext-paging&LOCAL/PAGE260@ext-paging&LOCAL/PAGE257@ext
-paging&LOCAL/PAGE256@ext-paging&LOCAL/PAGE255@ext-paging&LOCAL/PAGE254@ext-paging&LOCAL/PAGE253@ext-paging&LOCAL/PAGE251@ext-paging&LOCAL/PAGE250@ext-paging&LOCAL/PAGE249@ext-paging&LOCAL/PAGE2480@ext-paging&LOCAL/PAGE248@ext-paging&LOC
AL/PAGE247@ext-paging&LOCAL/PAGE246@ext-paging&LOCAL/PAGE2450@ext-paging&LOCAL/PAGE245@ext-paging&LOCAL/PAGE244@ext-paging&LOCAL/PAGE243@ext-paging&LOCAL/PAGE242@ext-paging&LOCAL/PAGE241@ext-paging&LOCAL/PAGE240@ext-paging&LOCAL/PAGE239@
ext-paging&LOCAL/PAGE238@ext-paging&LOCAL/PAGE237@ext-paging&LOCAL/PAGE2360@ext-paging&LOCAL/PAGE236@ext-paging&LOCAL/PAGE235@ext-paging&LOCAL/PAGE234@ext-paging&LOCAL/PAGE233@ext-paging&LOCAL/PAGE232@ext-paging&LOCAL/PAGE231@ext-paging&
LOCAL/PAGE230@ext-paging&LOCAL/PAGE229@ext-paging&LOCAL/PAGE228@ext-paging&LOCAL/PAGE227@ext-paging&LOCAL/PAGE226@ext-paging&LOCAL/PAGE225@ext-paging&LOCAL/PAGE224@ext-paging&LOCAL/PAGE223@ext-paging&LOCAL/PAGE222@ext-paging&LOCAL/PAGE22
1@ext-paging)
[/code:1]

habile · August 8, 2007, 7:12pm

Did you recently add another extension to the page group?

Looks like Page() is bombing out - is anything logged in the Asterisk log file? You might get more info with some debug turned on.

Create a new page group with a few extensions - does that work?

If so, try removing extensions one by one from the 610 group (if you had added recently).

Can’t think of anything else.

C.

Peri · August 8, 2007, 8:12pm

Here’s the asterisk/full log.

[code:1]Aug 8 16:04:19 DEBUG[3066] chan_sip.c: Checking SIP call limits for device 236
Aug 8 16:04:19 DEBUG[3066] chan_sip.c: build_route: Contact hop: Admin Phone sip:[email protected]
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing Set(“SIP/236-b740f7a0”, “_FORCE_PAGE=0”) in new stack
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing Macro(“SIP/236-b740f7a0”, “user-callerid|”) in new stack
Aug 8 16:04:19 DEBUG[20225] pbx.c: Function result is 'device’
Aug 8 16:04:19 DEBUG[20225] pbx.c: Function result is '236’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing NoOp(“SIP/236-b740f7a0”, “user-callerid: device 236”) in new stack
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: Noop
Aug 8 16:04:19 DEBUG[20225] pbx.c: Expression result is '1’
Aug 8 16:04:19 DEBUG[20225] pbx.c: Function result is '236’
Aug 8 16:04:19 DEBUG[20225] pbx.c: Function result is '236’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing Set(“SIP/236-b740f7a0”, “AMPUSER=236”) in new stack
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: Set
Aug 8 16:04:19 DEBUG[20225] pbx.c: Expression result is '0’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing GotoIf(“SIP/236-b740f7a0”, “0?report”) in new stack
Aug 8 16:04:19 DEBUG[20225] pbx.c: Not taking any branch
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: GotoIf
Aug 8 16:04:19 DEBUG[20225] pbx.c: Expression result is '0’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing GotoIf(“SIP/236-b740f7a0”, “0?start”) in new stack
Aug 8 16:04:19 DEBUG[20225] pbx.c: Not taking any branch
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: GotoIf
Aug 8 16:04:19 DEBUG[20225] pbx.c: Function result is '236’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing Set(“SIP/236-b740f7a0”, “REALCALLERIDNUM=236”) in new stack
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: Set
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing NoOp(“SIP/236-b740f7a0”, “REALCALLERIDNUM is 236”) in new stack
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: NoOp
Aug 8 16:04:19 DEBUG[20225] pbx.c: Function result is '236’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing Set(“SIP/236-b740f7a0”, “AMPUSER=236”) in new stack
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: Set
Aug 8 16:04:19 DEBUG[20225] pbx.c: Function result is 'Admin Phone’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing Set(“SIP/236-b740f7a0”, “AMPUSERCIDNAME=Admin Phone”) in new stack
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: Set
Aug 8 16:04:19 DEBUG[20225] pbx.c: Expression result is '0’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing GotoIf(“SIP/236-b740f7a0”, “0?report”) in new stack
Aug 8 16:04:19 DEBUG[20225] pbx.c: Not taking any branch
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: GotoIf
Aug 8 16:04:19 DEBUG[20225] db.c: Unable to find key ‘236/cidnum’ in family 'AMPUSER’
Aug 8 16:04:19 DEBUG[20225] pbx.c: Function result is '0’
Aug 8 16:04:19 DEBUG[20225] pbx.c: Expression result is '0’
Aug 8 16:04:19 DEBUG[20225] pbx.c: Function result is '236’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing Set(“SIP/236-b740f7a0”, “AMPUSERCID=236”) in new stack
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: Set
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing Set(“SIP/236-b740f7a0”, “CALLERID(all)=“Admin Phone” <236>”) in new stack
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: Set
Aug 8 16:04:19 DEBUG[20225] pbx.c: Function result is '236’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing Set(“SIP/236-b740f7a0”, “REALCALLERIDNUM=236”) in new stack
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: Set
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing NoOp(“SIP/236-b740f7a0”, "TTL: ARG1: ") in new stack
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: Noop
Aug 8 16:04:19 DEBUG[20225] pbx.c: Expression result is '0’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing GotoIf(“SIP/236-b740f7a0”, “0?continue”) in new stack
Aug 8 16:04:19 DEBUG[20225] pbx.c: Not taking any branch
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: GotoIf
Aug 8 16:04:19 DEBUG[20225] pbx.c: Expression result is '1’
Aug 8 16:04:19 DEBUG[20225] pbx.c: Expression result is '-1’
Aug 8 16:04:19 DEBUG[20225] pbx.c: Function result is '64’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing Set(“SIP/236-b740f7a0”, “__TTL=64”) in new stack
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: Set
Aug 8 16:04:19 DEBUG[20225] pbx.c: Expression result is ‘1’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing GotoIf(“SIP/236-b740f7a0”, “1?continue”) in new stack
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Goto (macro-user-callerid,s,23)
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: GotoIf
Aug 8 16:04:19 DEBUG[20225] pbx.c: Function result is ‘“Admin Phone” <236>‘
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing NoOp(“SIP/236-b740f7a0”, “Using CallerID “Admin Phone” <236>”) in new stack
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: NoOp
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing Set(“SIP/236-b740f7a0”, “_AMPUSER=236”) in new stack
Aug 8 16:04:19 WARNING[20225] pbx.c: No application ‘Page’ for extension (from-internal, 610, 4)
Aug 8 16:04:19 VERBOSE[20225] logger.c: == Spawn extension (from-internal, 610, 4) exited non-zero on ‘SIP/236-b740f7a0’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing Macro(“SIP/236-b740f7a0”, “hangupcall”) in new stack
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing ResetCDR(“SIP/236-b740f7a0”, “w”) in new stack
Aug 8 16:04:19 DEBUG[20225] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Aug 8 16:04:19 DEBUG[20225] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode) VALUES (‘2007-08-08 16:04:19’,’“Admin Phone” <236>’,‘236’,‘610’,‘from-internal’, ‘SIP/236-b740f7a0’,’’,‘ResetCDR’,‘w’,0,0,‘NO ANSWER’,3,‘aci’)
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: ResetCDR
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing NoCDR(“SIP/236-b740f7a0”, “”) in new stack
Aug 8 16:04:19 NOTICE[20225] cdr.c: CDR on channel ‘SIP/236-b740f7a0’ not posted
Aug 8 16:04:19 NOTICE[20225] cdr.c: CDR on channel ‘SIP/236-b740f7a0’ lacks end
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: NoCDR
Aug 8 16:04:19 DEBUG[20225] pbx.c: Expression result is '1’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing GotoIf(“SIP/236-b740f7a0”, “1?skiprg”) in new stack
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Goto (macro-hangupcall,s,6)
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: GotoIf
Aug 8 16:04:19 DEBUG[20225] pbx.c: Expression result is '1’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing GotoIf(“SIP/236-b740f7a0”, “1?skipblkvm”) in new stack
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Goto (macro-hangupcall,s,9)
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: GotoIf
Aug 8 16:04:19 DEBUG[20225] pbx.c: Expression result is '1’
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing GotoIf(“SIP/236-b740f7a0”, “1?theend”) in new stack
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Goto (macro-hangupcall,s,11)
Aug 8 16:04:19 DEBUG[20225] app_macro.c: Executed application: GotoIf
Aug 8 16:04:19 VERBOSE[20225] logger.c: – Executing Hangup(“SIP/236-b740f7a0”, “”) in new stack
Aug 8 16:04:19 VERBOSE[20225] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/236-b740f7a0’ in macro 'hangupcall’
Aug 8 16:04:19 VERBOSE[20225] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/236-b740f7a0’
Aug 8 16:04:19 DEBUG[20225] chan_sip.c: update_call_counter(236) - decrement call limit counter
Aug 8 16:04:19 DEBUG[20225] chan_sip.c: AST hangup cause 16 (no match found in SIP)
Aug 8 16:04:19 DEBUG[3066] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Response 2070640856: Match Found
[/code:1]

The line that pops out at me is:
Aug 8 16:04:19 WARNING[20225] pbx.c: No application ‘Page’ for extension (from-internal, 610, 4)

I’ve tried removing all extensions except 1 or 2 that i know are valid (our extensions have been static for a few months now and hte problem is only 2 weeks old tops) still the same thing.

habile · August 8, 2007, 9:02pm

I don’t think I can help much further - but I would check if app_page got loaded ok.

I’m not sure what the 1.2 syntax is to check modules, on 1.4 it is ‘module show like app_page’ – maybe ‘show modules’.

Also try from the CLI: module unload/load app_page and see if you get any errors.

Does /usr/lib/asterisk/modules/app_page.so exist? Is it readable?

Otherwise I’m stuck (and still quite new to this) - perhaps someone else can help more.

C.

plindheimer · August 8, 2007, 9:18pm

Your issue is as you noted:

[code:1]Aug 8 16:04:19 WARNING[20225] pbx.c: No application ‘Page’ for extension (from-internal, 610, 4)[/code:1]
something is wrong with your Asterisk installation

Peri · August 8, 2007, 9:26pm

ah, indeed thank you habile, somehow my asterisk 1.2.22 source doesn’t have app_page.