Paging Pro Issues

Trying my luck here before creating a ticket.

[[email protected] ~]# fwconsole ma list | grep pag
| paging               | 13.0.26.15 | Enabled                           | GPLv3+     |
| pagingpro            | 13.0.19.13 | Enabled                           | Commercial |

Page 505 is scheduled for every day of the week besides Saturday.

However, it did not work yesterday Sunday Feb 9th 2020.

I checked CDR and the cron logs.

[[email protected] ~]# grep "p 505" /var/log/cron*
/var/log/cron:Feb 10 09:00:01 localhost CROND[9081]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 505 -t 1581343200 2>&1 >/dev/null)
/var/log/cron-20200202:Jan 28 09:00:01 localhost CROND[27724]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 505 -t 1580220000 2>&1 >/dev/null)
/var/log/cron-20200202:Jan 29 09:00:01 localhost CROND[9954]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 505 -t 1580306400 2>&1 >/dev/null)
/var/log/cron-20200202:Jan 30 09:00:01 localhost CROND[23279]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 505 -t 1580392800 2>&1 >/dev/null)
/var/log/cron-20200202:Jan 31 09:00:01 localhost CROND[31802]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 505 -t 1580479200 2>&1 >/dev/null)
/var/log/cron-20200209:Feb  2 09:00:01 localhost CROND[550]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 505 -t 1580652000 2>&1 >/dev/null)
/var/log/cron-20200209:Feb  3 09:00:01 localhost CROND[4866]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 505 -t 1580738400 2>&1 >/dev/null)
/var/log/cron-20200209:Feb  4 09:00:01 localhost CROND[15374]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 505 -t 1580824800 2>&1 >/dev/null)
/var/log/cron-20200209:Feb  5 09:00:01 localhost CROND[28919]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 505 -t 1580911200 2>&1 >/dev/null)
/var/log/cron-20200209:Feb  6 09:00:01 localhost CROND[2944]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 505 -t 1580997600 2>&1 >/dev/null)
/var/log/cron-20200209:Feb  7 09:00:01 localhost CROND[15794]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 505 -t 1581084000 2>&1 >/dev/null)

So I looked at the paging pro list from command line.

[[email protected] ~]# fwconsole pagingpro --list
+---------+------------+-------------+
| Page ID | Time       | Cron Exists |
+---------+------------+-------------+
| 506     | 1581348000 | No          |
| 505     | 1581429600 | No          |
| 523     | 1581379200 | No          |
| 521     | 1581346800 | No          |
| 510     | 1581429600 | No          |
| 516     | 1581388200 | No          |
| 522     | 1581357600 | No          |
| 514     | 1581373800 | No          |
| 515     | 1581383700 | No          |
| 513     | 1581354300 | No          |
| 511     | 1581348600 | No          |
| 507     | 1581354000 | No          |
| 508     | 1581373800 | No          |
| 509     | 1581386400 | No          |
+---------+------------+-------------+

505 Is there. However, I see scheduled pages like 510 which is not actually in the GUI is also listed.

510 is a scheduled page that was already deleted, but still seems to be running.

[[email protected] ~]# grep "p 510" /var/log/cron*
/var/log/cron:Feb  9 09:00:01 localhost CROND[30680]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1581256800 2>&1 >/dev/null)
/var/log/cron:Feb 10 09:00:01 localhost CROND[9092]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1581343200 2>&1 >/dev/null)
/var/log/cron-20200119:Jan 12 09:00:01 localhost CROND[15872]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1578837600 2>&1 >/dev/null)
/var/log/cron-20200119:Jan 13 09:00:01 localhost CROND[25508]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1578924000 2>&1 >/dev/null)
/var/log/cron-20200119:Jan 14 09:00:01 localhost CROND[18253]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1579010400 2>&1 >/dev/null)
/var/log/cron-20200119:Jan 15 09:00:01 localhost CROND[31351]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1579096800 2>&1 >/dev/null)
/var/log/cron-20200119:Jan 16 09:00:01 localhost CROND[9173]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1579183200 2>&1 >/dev/null)
/var/log/cron-20200119:Jan 17 09:00:02 localhost CROND[5037]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1579269600 2>&1 >/dev/null)
/var/log/cron-20200126:Jan 19 09:00:01 localhost CROND[5416]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1579442400 2>&1 >/dev/null)
/var/log/cron-20200126:Jan 20 09:00:01 localhost CROND[30004]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1579528800 2>&1 >/dev/null)
/var/log/cron-20200126:Jan 21 09:00:01 localhost CROND[21461]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1579615200 2>&1 >/dev/null)
/var/log/cron-20200126:Jan 22 09:00:01 localhost CROND[30311]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1579701600 2>&1 >/dev/null)
/var/log/cron-20200126:Jan 23 09:00:01 localhost CROND[5702]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1579788000 2>&1 >/dev/null)
/var/log/cron-20200126:Jan 24 09:00:01 localhost CROND[8447]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1579874400 2>&1 >/dev/null)
/var/log/cron-20200202:Jan 26 09:00:01 localhost CROND[1442]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1580047200 2>&1 >/dev/null)
/var/log/cron-20200202:Jan 27 09:00:01 localhost CROND[10323]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1580133600 2>&1 >/dev/null)
/var/log/cron-20200202:Jan 28 09:00:01 localhost CROND[27727]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1580220000 2>&1 >/dev/null)
/var/log/cron-20200202:Jan 29 09:00:01 localhost CROND[9948]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1580306400 2>&1 >/dev/null)
/var/log/cron-20200202:Jan 30 09:00:01 localhost CROND[23274]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1580392800 2>&1 >/dev/null)
/var/log/cron-20200202:Jan 31 09:00:01 localhost CROND[31795]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1580479200 2>&1 >/dev/null)
/var/log/cron-20200209:Feb  2 09:00:01 localhost CROND[555]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1580652000 2>&1 >/dev/null)
/var/log/cron-20200209:Feb  3 09:00:01 localhost CROND[4869]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1580738400 2>&1 >/dev/null)
/var/log/cron-20200209:Feb  4 09:00:01 localhost CROND[15373]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1580824800 2>&1 >/dev/null)
/var/log/cron-20200209:Feb  5 09:00:01 localhost CROND[28920]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1580911200 2>&1 >/dev/null)
/var/log/cron-20200209:Feb  6 09:00:01 localhost CROND[2939]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1580997600 2>&1 >/dev/null)
/var/log/cron-20200209:Feb  7 09:00:01 localhost CROND[15792]: (asterisk) CMD (/var/lib/asterisk/bin/pagepro-scheduler.php -p 510 -t 1581084000 2>&1 >/dev/null)

I ran

fwconsole pagingpro --clean --verbose

But it still adds 510.

Any idea how I can remove 510 and see why 505 was not called yesterday?

As mentioned above, this is a FreePBX 13, and it seems like fwconsole job --list does not work on v13.

Appreciate any help.

Thanks

Hi ,
This looks like a issue to me.
Please open a commercial support ticket here!.

Thanks
Philip

1 Like

HI @PitzKey
There is an Edge version for clearing the stale cronjobs
pagingpro 13.0.19.16

Thanks
philip J

Hi @jphilip
It does not install, I’m getting the attached error.

@PitzKey

Please update your paging module 13.0.26.16 which there in EDGE.
then you will be able to install pagingpro 13.0.19.16

thanks
Philip

Now it seems like it’s running fine, but on certain pages it does not play the full audio.

[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] res_agi.c: <Local/[email protected];2>AGI Script cos.agi completed, returning 0
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:3] Return("Local/[email protected];2", "") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:4] Set("Local/[email protected];2", "_PAGEGROUP=507") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:5] Set("Local/[email protected];2", "ANNOUNCE_COUNT=1") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:6] GotoIf("Local/[email protected];2", "1?:busy") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:7] Set("Local/[email protected];2", "DEVICE_STATE(Custom:PAGE507)=INUSE") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:8] Gosub("Local/[email protected];2", "app-paging,ssetup,1()") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:1] Set("Local/[email protected];2", "_SIPURI=") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:2] Set("Local/[email protected];2", "_ALERTINFO=Ring Answer") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:3] Set("Local/[email protected];2", "_CALLINFO=<uri>;answer-after=0") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:4] Set("Local/[email protected];2", "_SIPURI=intercom=true") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:5] Set("Local/[email protected];2", "_DTIME=5") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:6] Set("Local/[email protected];2", "_ANSWERMACRO=") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:7] Set("Local/[email protected];2", "PAGE_CONF=1582131602559") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:8] Return("Local/[email protected];2", "") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:9] Set("Local/[email protected];2", "PAGEMODE=PAGE") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:10] Set("Local/[email protected];2", "PAGE_MEMBERS=7244") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:11] Set("Local/[email protected];2", "PAGE_CONF_OPTS=") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:12] Set("Local/[email protected];2", "ANNOUNCEMENT=") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:13] ExecIf("Local/[email protected];2", "1?Set(STREAM=custom/NewLunch12PM-Music):Set(STREAM=NONE)") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:14] AGI("Local/[email protected];2", "page.agi") in new stack
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/page.agi
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] res_agi.c: <Local/[email protected];2>AGI Script page.agi completed, returning 0
[2020-02-19 12:00:03] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:15] Set("Local/[email protected];2", "CONFBRIDGE(user,template)=page_user_duplex") in new stack
[2020-02-19 12:00:03] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:16] Set("Local/[email protected];2", "CONFBRIDGE(user,admin)=yes") in new stack
[2020-02-19 12:00:03] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:17] Set("Local/[email protected];2", "CONFBRIDGE(user,marked)=yes") in new stack
[2020-02-19 12:00:03] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:18] Answer("Local/[email protected];2", "") in new stack
[2020-02-19 12:00:03] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:19] ConfBridge("Local/[email protected];2", "1582131602559,,,admin_menu") in new stack
[2020-02-19 12:00:03] VERBOSE[20092][C-00000f49] bridge_channel.c: Channel CBAnn/1582131602559-0000053d;2 joined 'softmix' base-bridge <535bda43-32bf-4080-94e7-8f98c53c68a5>
[2020-02-19 12:00:03] VERBOSE[20042][C-00000f49] bridge_channel.c: Channel Local/[email protected];2 joined 'softmix' base-bridge <535bda43-32bf-4080-94e7-8f98c53c68a5>
[2020-02-19 12:00:04] VERBOSE[20042][C-00000f49] bridge_channel.c: Channel Local/[email protected];2 left 'softmix' base-bridge <535bda43-32bf-4080-94e7-8f98c53c68a5>
[2020-02-19 12:00:04] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:1] ExecIf("Local/[email protected];2", "1?Set(DEVICE_STATE(Custom:PAGE507)=NOT_INUSE)") in new stack
[2020-02-19 12:00:04] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:2] GosubIf("Local/[email protected];2", "0?record-page,1()") in new stack
[2020-02-19 12:00:04] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:3] ExecIf("Local/[email protected];2", "0?System(rm .sln)") in new stack
[2020-02-19 12:00:04] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:4] ExecIf("Local/[email protected];2", "0?System(rm -f /var/spool/asterisk/outgoing/)") in new stack
[2020-02-19 12:00:04] VERBOSE[20092][C-00000f49] bridge_channel.c: Channel CBAnn/1582131602559-0000053d;2 left 'softmix' base-bridge <535bda43-32bf-4080-94e7-8f98c53c68a5>

However, the below one (Page 506) did play the entire audio for 1:06

[2020-02-19 10:20:02] VERBOSE[12765][C-00000e94] pbx.c: Executing [[email protected]:13] ExecIf("Local/[email protected];2", "1?Set(STREAM=custom/NewCheckingOut1020Week-Music):Set(STREAM=NONE)") in new stack
[2020-02-19 10:20:02] VERBOSE[12765][C-00000e94] pbx.c: Executing [[email protected]:14] AGI("Local/[email protected];2", "page.agi") in new stack
[2020-02-19 10:20:02] VERBOSE[12765][C-00000e94] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/page.agi
[2020-02-19 10:20:02] VERBOSE[12765][C-00000e94] res_agi.c: <Local/[email protected];2>AGI Script page.agi completed, returning 0
[2020-02-19 10:20:02] VERBOSE[12765][C-00000e94] pbx.c: Executing [[email protected]:15] Set("Local/[email protected];2", "CONFBRIDGE(user,template)=page_user_duplex") in new stack
[2020-02-19 10:20:02] VERBOSE[12765][C-00000e94] pbx.c: Executing [[email protected]:16] Set("Local/[email protected];2", "CONFBRIDGE(user,admin)=yes") in new stack
[2020-02-19 10:20:02] VERBOSE[12765][C-00000e94] pbx.c: Executing [[email protected]:17] Set("Local/[email protected];2", "CONFBRIDGE(user,marked)=yes") in new stack
[2020-02-19 10:20:02] VERBOSE[12765][C-00000e94] pbx.c: Executing [[email protected]:18] Answer("Local/[email protected];2", "") in new stack
[2020-02-19 10:20:02] VERBOSE[12765][C-00000e94] pbx.c: Executing [[email protected]:19] ConfBridge("Local/[email protected];2", "1582125602812,,,admin_menu") in new stack
[2020-02-19 10:20:02] VERBOSE[12823][C-00000e94] bridge_channel.c: Channel CBAnn/1582125602812-00000533;2 joined 'softmix' base-bridge <c89a484d-0e2e-4847-ac87-dc177ce956e1>
[2020-02-19 10:20:02] VERBOSE[12765][C-00000e94] bridge_channel.c: Channel Local/[email protected];2 joined 'softmix' base-bridge <c89a484d-0e2e-4847-ac87-dc177ce956e1>
[2020-02-19 10:20:03] VERBOSE[12765][C-00000e94] bridge_channel.c: Channel Local/[email protected];2 left 'softmix' base-bridge <c89a484d-0e2e-4847-ac87-dc177ce956e1>
[2020-02-19 10:20:03] VERBOSE[12765][C-00000e94] pbx.c: Executing [[email protected]:1] ExecIf("Local/[email protected];2", "1?Set(DEVICE_STATE(Custom:PAGE506)=NOT_INUSE)") in new stack
[2020-02-19 10:20:03] VERBOSE[12765][C-00000e94] pbx.c: Executing [[email protected]:2] GosubIf("Local/[email protected];2", "0?record-page,1()") in new stack
[2020-02-19 10:20:03] VERBOSE[12765][C-00000e94] pbx.c: Executing [[email protected]:3] ExecIf("Local/[email protected];2", "0?System(rm .sln)") in new stack
[2020-02-19 10:20:03] VERBOSE[12765][C-00000e94] pbx.c: Executing [[email protected]:4] ExecIf("Local/[email protected];2", "0?System(rm -f /var/spool/asterisk/outgoing/)") in new stack
[2020-02-19 10:21:09] VERBOSE[12823][C-00000e94] bridge_channel.c: Channel CBAnn/1582125602812-00000533;2 left 'softmix' base-bridge <c89a484d-0e2e-4847-ac87-dc177ce956e1>

Pages are set to:
image
So I don’t think the device being busy should be an issue.

Where do I take it from here?

Pastebin link for easier read: https://pastebin.freepbx.org/view/raw/18696fe9

By the way, the actual playing part does not have the Call ID, so it’s not included when grepping by the call id.

[[email protected] ~]# grep NewCheckingOut /var/log/asterisk/full-20200220
[2020-02-19 10:20:02] VERBOSE[12765][C-00000e94] pbx.c: Executing [[email protected]:13] ExecIf("Local/[email protected];2", "1?Set(STREAM=custom/NewCheckingOut1020Week-Music):Set(STREAM=NONE)") in new stack
[2020-02-19 10:20:03] VERBOSE[12814] file.c: <Local/[email protected];1> Playing 'custom/NewCheckingOut1020Week-Music.slin' (language 'en')
[2020-02-19 10:20:03] VERBOSE[12820] file.c: <Local/[email protected];1> Playing 'custom/NewCheckingOut1020Week-Music.slin' (language 'en')


[[email protected] ~]# grep NewLunch /var/log/asterisk/full-20200220
[2020-02-19 12:00:02] VERBOSE[20042][C-00000f49] pbx.c: Executing [[email protected]:13] ExecIf("Local/[email protected];2", "1?Set(STREAM=custom/NewLunch12PM-Music):Set(STREAM=NONE)") in new stack
[2020-02-19 12:00:04] VERBOSE[20084] file.c: <Local/[email protected];1> Playing 'custom/NewLunch12PM-Music.slin' (language 'en')
[2020-02-19 12:00:04] VERBOSE[20086] file.c: <Local/[email protected];1> Playing 'custom/NewLunch12PM-Music.slin' (language 'en')

Having this now at another client, the scheduled pages does not fully complete, it only plays the first few seconds.

Hi @PitzKey!

Open a commercial module support ticket so we can take a look. I say ‘we’ but I’m on break this week so someone smart will have to do.

Been a crazy week, we are overwhelmed with tickets.

I’ll hopefully get to it next week…

In the meantime, I created cronjobs which is generating and moving callfiles into /var/spool/asterisk/outgoing and once the channel (the overhead speakers) answers it goes to a custom context which plays the audio. So far no issues.

This topic was automatically closed 31 days after the last reply. New replies are no longer allowed.