Need help with Callback on freepbx 2.3.0alpha & Asterisk

My Callback on freepbx 2.2.0beta1 used to work, but it was sketchy. Eventually it stopped working entirely for mysterious reasons, the only things I was ever modifying with freepbx was extensions, inbound routes, and trunks. So it was disappointing to see the Callback function whither away, since I use it the most.

I was running freepbx 2.2.0beta1 and Asterisk 1.2 for a year, when I caught wind that freepbx 2.2.1 is released, I thought I’d go into my freepbx directory and do an SVN update and installed freepbx 2.3.0alpha by mistake. No worries, I was hoping to upgrade the Callback module in the offchance it would work again. I had to manually edit my manager.conf file and retype my Asterisk Manager’s username and password. Then freepbx could connect to Asterisk. I connected to the online module repository and downloaded all the modules available. Very nice interface!

After setting up a Callback with a DISA, I thought I would be home free. Turns out I was encountering the same problem I always had with Callback. Here is a snippet of my CLI:

[code:1] == Parsing ‘/etc/asterisk/manager.conf’: Found
== Manager ‘rpatel’ logged on from 127.0.0.1
== Manager ‘rpatel’ logged off from 127.0.0.1
== Parsing ‘/etc/asterisk/manager.conf’: Found
== Manager ‘rpatel’ logged on from 127.0.0.1
== Manager ‘rpatel’ logged off from 127.0.0.1
== Parsing ‘/etc/asterisk/manager.conf’: Found
== Manager ‘rpatel’ logged on from 127.0.0.1
== Manager ‘rpatel’ logged off from 127.0.0.1
– Accepting AUTHENTICATED call from 199.172.228.206:
> requested format = gsm,
> requested prefs = (),
> actual format = ulaw,
> host prefs = (ulaw|alaw|gsm),
> priority = mine
– Executing Macro(“IAX2/104-5”, “dialout-trunk|21|0013605153566||”) in new stack
– Executing Set(“IAX2/104-5”, “DIAL_TRUNK=21”) in new stack
– Executing Set(“IAX2/104-5”, “DIAL_NUMBER=0013605153566”) in new stack
– Executing Set(“IAX2/104-5”, “ROUTE_PASSWD=”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?noauth”) in new stack
– Goto (macro-dialout-trunk,s,6)
– Executing GotoIf(“IAX2/104-5”, “0?disabletrunk|1”) in new stack
– Executing Set(“IAX2/104-5”, “_NODEST=”) in new stack
– Executing Set(“IAX2/104-5”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
– Executing Set(“IAX2/104-5”, “GROUP()=OUT_21”) in new stack
– Executing Macro(“IAX2/104-5”, “user-callerid|SKIPTTL”) in new stack
– Executing NoOp(“IAX2/104-5”, “user-callerid: zzzRajan Patel 104”) in new stack
– Executing GotoIf(“IAX2/104-5”, “0?report”) in new stack
– Executing GotoIf(“IAX2/104-5”, “0?start”) in new stack
– Executing Set(“IAX2/104-5”, “REALCALLERIDNUM=104”) in new stack
– Executing NoOp(“IAX2/104-5”, “REALCALLERIDNUM is 104”) in new stack
– Executing Set(“IAX2/104-5”, “AMPUSER=104”) in new stack
– Executing Set(“IAX2/104-5”, “AMPUSERCIDNAME=zzzRajan Patel”) in new stack
– Executing GotoIf(“IAX2/104-5”, “0?report”) in new stack
– Executing Set(“IAX2/104-5”, “AMPUSERCID=104”) in new stack
– Executing Set(“IAX2/104-5”, “CALLERID(all)=zzzRajan Patel <104>”) in new stack
– Executing Set(“IAX2/104-5”, “REALCALLERIDNUM=104”) in new stack
– Executing NoOp(“IAX2/104-5”, “TTL: ARG1: SKIPTTL”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,22)
– Executing NoOp(“IAX2/104-5”, “Using CallerID “zzzRajan Patel” <104>”) in new stack
– Executing Macro(“IAX2/104-5”, “record-enable|104|OUT”) in new stack
– Executing GotoIf(“IAX2/104-5”, “0?2:4”) in new stack
– Goto (macro-record-enable,s,4)
– Executing DeadAGI(“IAX2/104-5”, “recordingcheck|20070524-215113|1180057873.600”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
recordingcheck|20070524-215113|1180057873.600: Outbound recording not enabled
– AGI Script recordingcheck completed, returning 0
– Executing NoOp(“IAX2/104-5”, “No recording needed”) in new stack
– Executing GotoIf(“IAX2/104-5”, “0?skipoutcid”) in new stack
– Executing Set(“IAX2/104-5”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
– Executing Macro(“IAX2/104-5”, “outbound-callerid|21”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?start”) in new stack
– Goto (macro-outbound-callerid,s,3)
– Executing NoOp(“IAX2/104-5”, “REALCALLERIDNUM is 104”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?normcid”) in new stack
– Goto (macro-outbound-callerid,s,9)
– Executing Set(“IAX2/104-5”, “USEROUTCID=“Rajan Patel” <3604880489>”) in new stack
– Executing Set(“IAX2/104-5”, “EMERGENCYCID=”) in new stack
– Executing Set(“IAX2/104-5”, “TRUNKOUTCID=”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?trunkcid”) in new stack
– Goto (macro-outbound-callerid,s,16)
– Executing GotoIf(“IAX2/104-5”, “1?usercid”) in new stack
– Goto (macro-outbound-callerid,s,18)
– Executing GotoIf(“IAX2/104-5”, “0?report”) in new stack
– Executing Set(“IAX2/104-5”, “CALLERID(all)=“Rajan Patel” <3604880489>”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?report:hidecid”) in new stack
– Goto (macro-outbound-callerid,s,22)
– Executing NoOp(“IAX2/104-5”, “CallerID set to “Rajan Patel” <3604880489>”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?nomax”) in new stack
– Goto (macro-dialout-trunk,s,17)
– Executing DeadAGI(“IAX2/104-5”, “fixlocalprefix”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
> fixlocalprefix: Using pattern 001345+XXXXXXX
> fixlocalprefix: Using pattern 001+NXXNXXXXXX
> fixlocalprefix: Using pattern 00+1NXXNXXXXXX
> fixlocalprefix: Using pattern 001NXXNXXXXXX
== fixlocalprefix: Dialpattern 001NXXNXXXXXX matched. 0013605153566 -> 0013605153566
– AGI Script fixlocalprefix completed, returning 0
– Executing Set(“IAX2/104-5”, “OUTNUM=0013605153566”) in new stack
– Executing Set(“IAX2/104-5”, “custom=SIP/VBKN”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?gocall”) in new stack
– Goto (macro-dialout-trunk,s,22)
– Executing GotoIf(“IAX2/104-5”, “0?customtrunk”) in new stack
– Executing Dial(“IAX2/104-5”, “SIP/VBKN/0013605153566|300|tr”) in new stack
– Called VBKN/0013605153566
– SIP/VBKN-08cf0b98 is making progress passing it to IAX2/104-5
– Executing NoOp(“SIP/66.54.140.46-b7d125f0”, “Received incoming SIP connection from unknown peer to 3605153566”) in new stack
– Executing Set(“SIP/66.54.140.46-b7d125f0”, “DID=3605153566”) in new stack
– Executing Goto(“SIP/66.54.140.46-b7d125f0”, “s|1”) in new stack
– Goto (from-sip-external,s,1)
– Executing Ringing(“SIP/66.54.140.46-b7d125f0”, “”) in new stack
– Executing GotoIf(“SIP/66.54.140.46-b7d125f0”, “1?from-trunk|3605153566|1”) in new stack
– Goto (from-trunk,3605153566,1)
– Executing Set(“SIP/66.54.140.46-b7d125f0”, “__FROM_DID=3605153566”) in new stack
– Executing Gosub(“SIP/66.54.140.46-b7d125f0”, “app-blacklist-check|s|1”) in new stack
– Executing LookupBlacklist(“SIP/66.54.140.46-b7d125f0”, “”) in new stack
– Executing GotoIf(“SIP/66.54.140.46-b7d125f0”, “0?blacklisted”) in new stack
– Executing Return(“SIP/66.54.140.46-b7d125f0”, “”) in new stack
– Executing GotoIf(“SIP/66.54.140.46-b7d125f0”, “1 ?cidok”) in new stack
– Goto (from-trunk,3605153566,5)
– Executing NoOp(“SIP/66.54.140.46-b7d125f0”, "CallerID is “Unknown” ") in new stack
– Executing Goto(“SIP/66.54.140.46-b7d125f0”, “callback|2|1”) in new stack
– Goto (callback,2,1)
– Executing Set(“SIP/66.54.140.46-b7d125f0”, “CALL=17329830228”) in new stack
– Executing Set(“SIP/66.54.140.46-b7d125f0”, “DESTINATION=disa.4.1”) in new stack
– Executing Set(“SIP/66.54.140.46-b7d125f0”, “SLEEP=5”) in new stack
– Executing System(“SIP/66.54.140.46-b7d125f0”, “/var/lib/asterisk/bin/callback 17329830228 disa.4.1 5 &”) in new stack
– Executing Hangup(“SIP/66.54.140.46-b7d125f0”, “”) in new stack
== Spawn extension (callback, 2, 5) exited non-zero on ‘SIP/66.54.140.46-b7d125f0’
[/code:1]

I made the call with my IDEFISK (extension 104) to a Voipbuster trunk, which gives me the best rates to my cell phone device. My cell phone bill is through the roof, since I use it to call my parents back in the states - the sooner I can get this resolved, the faster I begin saving some money.

Thanks all for your time and reading through this; if we can resolve the problem here on the forum - I hope this information can help someone else who has similar issues.

is there anything in the retrieve_conf log showing it failed, would be in /var/log/asterisk/freepbx-retrieve.log?

not really, all that is in there is the following:

[code:1]Checking for PEAR DB…OK
Checking for PEAR Console::Getopt…OK
Checking for /etc/amportal.conf…OK
Reading /etc/amportal.conf…OK
Reading /etc/asterisk/asterisk.conf…OK
Connecting to database…OK
Connecting to Asterisk manager interface…OK[/code:1]

after updating all the modules in freepbx 2.3.0alpha today, none of the changes i make within freepbx actually go into effect… even though the changes appear in the mysql database. it’s like asterisk somehow remembers all the old settings and won’t budge…

Philippe,

I upgraded some modules today and thought I’d give the callback module another whack. I was able to successfully make the callback script call my cell phone when I manually type in

[code:1]/var/lib/asterisk/bin/callback 8213453280286 disa.6.1 5 &[/code:1]

while logged onto the server as user ‘asterisk’ via SSH.

I have a DID dedicated to handling my callback requests, here is what happens in the Asterisk CLI when I try to do it

[code:1] – Executing NoOp(“SIP/08157609-b7d17dd0”, “Received incoming SIP connection from unknown peer to 3475349345”) in new stack
– Executing Set(“SIP/08157609-b7d17dd0”, “DID=3475349345”) in new stack
– Executing Goto(“SIP/08157609-b7d17dd0”, “s|1”) in new stack
– Goto (from-sip-external,s,1)
– Executing Ringing(“SIP/08157609-b7d17dd0”, “”) in new stack
– Executing GotoIf(“SIP/08157609-b7d17dd0”, “1?from-trunk|3475349345|1”) in new stack
– Goto (from-trunk,3475349345,1)
– Executing Set(“SIP/08157609-b7d17dd0”, “__FROM_DID=3475349345”) in new stack
– Executing Gosub(“SIP/08157609-b7d17dd0”, “app-blacklist-check|s|1”) in new stack
– Executing LookupBlacklist(“SIP/08157609-b7d17dd0”, “”) in new stack
– Executing GotoIf(“SIP/08157609-b7d17dd0”, “0?blacklisted”) in new stack
– Executing Return(“SIP/08157609-b7d17dd0”, “”) in new stack
– Executing GotoIf(“SIP/08157609-b7d17dd0”, “0 ?cidok”) in new stack
– Executing Set(“SIP/08157609-b7d17dd0”, “CALLERID(name)=3453280286”) in new stack
– Executing NoOp(“SIP/08157609-b7d17dd0”, “CallerID is “3453280286” <3453280286>”) in new stack
– Executing Goto(“SIP/08157609-b7d17dd0”, “callback|7|1”) in new stack
– Goto (callback,7,1)
– Executing Set(“SIP/08157609-b7d17dd0”, “CALL=8213453280286”) in new stack
– Executing Set(“SIP/08157609-b7d17dd0”, “DESTINATION=disa.6.1”) in new stack
– Executing Set(“SIP/08157609-b7d17dd0”, “SLEEP=5”) in new stack
– Executing System(“SIP/08157609-b7d17dd0”, “/var/lib/asterisk/bin/callback 8213453280286 disa.6.1 5 &”) in new stack
– Executing Hangup(“SIP/08157609-b7d17dd0”, “”) in new stack
== Spawn extension (callback, 7, 5) exited non-zero on ‘SIP/08157609-b7d17dd0’
[/code:1]

And for good measure, here is the relevant portion of the Asterisk Debug Log

[code:1]Jun 12 19:59:08 DEBUG[3150] chan_sip.c: Setting NAT on RTP to 524288
Jun 12 19:59:08 DEBUG[3150] chan_sip.c: Checking SIP call limits for device 08157609
Jun 12 19:59:08 DEBUG[3150] chan_sip.c: build_route: Record-Route hop:
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing NoOp(“SIP/08157609-b7d17dd0”, “Received incoming SIP connection from unknown peer to 3475349345”) in new stack
Jun 12 19:59:08 DEBUG[22569] pbx.c: Expression result is '0’
Jun 12 19:59:08 DEBUG[22569] pbx.c: Function result is '3475349345’
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing Set(“SIP/08157609-b7d17dd0”, “DID=3475349345”) in new stack
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing Goto(“SIP/08157609-b7d17dd0”, “s|1”) in new stack
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Goto (from-sip-external,s,1)
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing Ringing(“SIP/08157609-b7d17dd0”, “”) in new stack
Jun 12 19:59:08 DEBUG[22569] pbx.c: Expression result is '1’
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing GotoIf(“SIP/08157609-b7d17dd0”, “1?from-trunk|3475349345|1”) in new stack
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Goto (from-trunk,3475349345,1)
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing Set(“SIP/08157609-b7d17dd0”, “__FROM_DID=3475349345”) in new stack
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing Gosub(“SIP/08157609-b7d17dd0”, “app-blacklist-check|s|1”) in new stack
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing LookupBlacklist(“SIP/08157609-b7d17dd0”, “”) in new stack
Jun 12 19:59:08 DEBUG[22569] db.c: Unable to find key ‘3453280286’ in family 'blacklist’
Jun 12 19:59:08 DEBUG[22569] pbx.c: Expression result is '0’
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing GotoIf(“SIP/08157609-b7d17dd0”, “0?blacklisted”) in new stack
Jun 12 19:59:08 DEBUG[22569] pbx.c: Not taking any branch
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing Return(“SIP/08157609-b7d17dd0”, “”) in new stack
Jun 12 19:59:08 DEBUG[22569] pbx.c: Function result is ''
Jun 12 19:59:08 DEBUG[22569] pbx.c: Expression result is '0’
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing GotoIf(“SIP/08157609-b7d17dd0”, “0 ?cidok”) in new stack
Jun 12 19:59:08 DEBUG[22569] pbx.c: Not taking any branch
Jun 12 19:59:08 DEBUG[22569] pbx.c: Function result is '3453280286’
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing Set(“SIP/08157609-b7d17dd0”, “CALLERID(name)=3453280286”) in new stack
Jun 12 19:59:08 DEBUG[22569] pbx.c: Function result is '“3453280286” <3453280286>'
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing NoOp(“SIP/08157609-b7d17dd0”, “CallerID is “3453280286” <3453280286>”) in new stack
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing Goto(“SIP/08157609-b7d17dd0”, “callback|7|1”) in new stack
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Goto (callback,7,1)
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing Set(“SIP/08157609-b7d17dd0”, “CALL=8213453280286”) in new stack
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing Set(“SIP/08157609-b7d17dd0”, “DESTINATION=disa.6.1”) in new stack
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing Set(“SIP/08157609-b7d17dd0”, “SLEEP=5”) in new stack
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing System(“SIP/08157609-b7d17dd0”, “/var/lib/asterisk/bin/callback 8213453280286 disa.6.1 5 &”) in new stack
Jun 12 19:59:08 VERBOSE[22569] logger.c: – Executing Hangup(“SIP/08157609-b7d17dd0”, “”) in new stack
Jun 12 19:59:08 VERBOSE[22569] logger.c: == Spawn extension (callback, 7, 5) exited non-zero on ‘SIP/08157609-b7d17dd0’[/code:1]

Unusual behavior… but perhaps the fact that it works in the command line but keeps crapping out in the CLI could mean something?

+++++++++++++++++++++++++++

Update: I updated the DID to no longer handle callback requests, and set it to play a recording. Even though these settings are being saved to the mySQL database from freepbx, Asterisk is still routing that DID to the callback instructions from earlier. I tried reloading in the CLI and this is after hitting the big red button at the top left in freepbx 2.3.0alpha

Frustration mounts; not sure if this situation is unique to me after updating all my modules today… or if this is something everyone else is experiencing.

I’m assuming the permissions are set with chmod? If you could tell me where the script is located and how to set the permission I’ll try immediately.

should be under /var/lib/asterisk/bin:

do an ‘ls -l’ command and see if the owner is asterisk and what the permissions are. And as mentioned, the log to see if it tried to connect (you won’t see that at the cli).

[quote=“p_lindheimer”]should be under /var/lib/asterisk/bin:

do an ‘ls -l’ command and see if the owner is asterisk and what the permissions are. And as mentioned, the log to see if it tried to connect (you won’t see that at the cli).[/quote]

The permissions seem to be set right; Asterisk is the owner of callback.
-rwxrwxr–

I did include the Asterisk Log above along with the corresponding CLI output. I’m not sure how to interpret the Log to find the ''connect" you’re referring to.

first on the cdr error which reports to your IRC discussion. Per the log, you have no cdr table, it appears to have gotten wiped out. You need to create a new one or restore an old one from a backup.

On the callback - have you gone through and deleted your callback entry in freepbx, and the disa entry, and then re-created them (disa first) to make sure something didn’t go astray?

After doing that - try the call again. If it fails, find the line that looks like:

[code:1]-- Executing System(“SIP/66.54.140.46-b7d125f0”, “/var/lib/asterisk/bin/callback 17329830228 disa.4.1 5 &”) in new stack[/code:1]
and then from the linux command line, try executing the callback and see what happens. You would so by simply typing:

[code:1]/var/lib/asterisk/bin/callback 17329830228 disa.4.1 5[/code:1]
but just like it is doing with your changed configuration if different. See what the cli and log say.

I just tested a callback/disa setup and it does work fine…[/code]

duplicate post - please see below

triplicate post - please see final one below… sigh

I deleted all the old DISA and all the old CALLBACK settings. I doublechecked they were indeed deleted in phpMyAdmin, they were no longer there. I made 1 new CALLBACK and 1 new DISA. Click the Red “apply changes” button on the top right, and tried to do the CALLBACK.

Here is what I realized. If I used an IAX2 extension or a SIP extension to initiate the CALLBACK, I never get a busy tone. It just rings forever. I don’t recall this being the case in 2.2.0beta1. If I use a POTS line to start the CALLBACK, I get the busy tone as I am supposed to.

I’m still encountering the same problems as before, the CALLBACK doesn’t go through. I had success for 1 attempt out of the many, when I tried to initiate the CALLBACK in the CLI directly. The CALLBACK worked for about 1 second - but I had no time to answer. The CALLBACK script hung up on me too quickly.

Here is how it looks in the CLI:

[code:1][[email protected] ~]$ /var/lib/asterisk/bin/callback 8213453280286 disa.6.1 5 &
[1] 1647
[[email protected] ~]$
Checking for PEAR Console::Getopt…OK
Reading /etc/amportal.conf…OK
Getting passed arguments:
Array
(
[0] => 8213453280286
[1] => disa.6.1
[2] => 5
)
Sat, 26 May 2007 13:26:33 -0400 - Got event… newchannel
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newchannel’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newchannel
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newchannel’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newcallerid
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newcallerid’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newexten
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newexten’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newchannel
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newchannel’
Sat, 26 May 2007 13:26:33 -0400 - Got event… dial
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'dial’
Sat, 26 May 2007 13:26:33 -0400 - Got event… newcallerid
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'newcallerid’
Sat, 26 May 2007 13:26:33 -0400 - Got event… registry
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'registry’
Sat, 26 May 2007 13:26:33 -0400 - Got event… registry
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'registry’
Sat, 26 May 2007 13:26:33 -0400 - Got event… registry
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'registry’
Sat, 26 May 2007 13:26:33 -0400 - Got event… registry
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'registry’
Sat, 26 May 2007 13:26:33 -0400 - Got event… registry
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'registry’
Sat, 26 May 2007 13:26:33 -0400 - Got event… registry
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event 'registry’
Sat, 26 May 2007 13:26:33 -0400 - Got event… hangup
Sat, 26 May 2007 13:26:33 -0400 - No event handler for event ‘hangup’
[/code:1]

I press CTRL+C to force it to quit at this point, it seems like it’s not going to do anything more. When I do this, it says:

[code:1][1]+ Done /var/lib/asterisk/bin/callback 8213453280286 disa.6.1 5
[/code:1]

Forgive me for including such a tremendous Asterisk Log, but I can’t make heads or tails of it - and I don’t want to cut out what could be an essential detail. I’m going to have to pastebin my Asterisk Log:

http://pastebin.ca/511989

well I must admin, having looked at the callback script, that it looks like it has room for improvment (when it makes it to the top of the list one day as a priority) - however, I think it should still work. Do you have the subsequent asterisk log to see if there is any sign of it trying to connect in and initiate the call - the errors may be there. Also - did you check your permissions on the callback script to make sure they are set properly?

I have obtained the CLI and the Asterisk Log. While looking through the Asterisk Log I thought of a possible reason why my CDR wasn’t updating, have there been some changes to the MySQL table structure which were not done via SVN UPDATE?

Here are the relevant portions of the Asterisk Log regarding the Callback specifically:

[code:1]May 25 10:53:16 DEBUG[3133] channel.c: Avoiding initial deadlock for 'SIP/66.54.140.46-b7d26768’
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing NoOp(“SIP/66.54.140.46-b7d26768”, “Received incoming SIP connection from unknown peer to 3605153566”) in new stack
May 25 10:53:16 DEBUG[16513] pbx.c: Expression result is '0’
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is '3605153566’
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing Set(“SIP/66.54.140.46-b7d26768”, “DID=3605153566”) in new stack
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing Goto(“SIP/66.54.140.46-b7d26768”, “s|1”) in new stack
May 25 10:53:16 VERBOSE[16513] logger.c: – Goto (from-sip-external,s,1)
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing Ringing(“SIP/66.54.140.46-b7d26768”, “”) in new stack
May 25 10:53:16 DEBUG[16513] pbx.c: Expression result is '1’
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing GotoIf(“SIP/66.54.140.46-b7d26768”, “1?from-trunk|3605153566|1”) in new stack
May 25 10:53:16 VERBOSE[16513] logger.c: – Goto (from-trunk,3605153566,1)
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing Set(“SIP/66.54.140.46-b7d26768”, “__FROM_DID=3605153566”) in new stack
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing Gosub(“SIP/66.54.140.46-b7d26768”, “app-blacklist-check|s|1”) in new stack
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing LookupBlacklist(“SIP/66.54.140.46-b7d26768”, “”) in new stack
May 25 10:53:16 DEBUG[16513] db.c: Unable to find key ‘Unknown’ in family 'blacklist’
May 25 10:53:16 DEBUG[16513] db.c: Unable to find key ‘Unknown’ in family 'blacklist’
May 25 10:53:16 DEBUG[16513] pbx.c: Expression result is ‘0’
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing GotoIf(“SIP/66.54.140.46-b7d26768”, “0?blacklisted”) in new stack
May 25 10:53:16 DEBUG[16513] pbx.c: Not taking any branch
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing Return(“SIP/66.54.140.46-b7d26768”, “”) in new stack
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is ‘Unknown’
May 25 10:53:16 DEBUG[16513] pbx.c: Expression result is ‘1’
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing GotoIf(“SIP/66.54.140.46-b7d26768”, “1 ?cidok”) in new stack
May 25 10:53:16 VERBOSE[16513] logger.c: – Goto (from-trunk,3605153566,5)
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is ‘“Unknown” ‘
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing NoOp(“SIP/66.54.140.46-b7d26768”, "CallerID is “Unknown” ") in new stack
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing Goto(“SIP/66.54.140.46-b7d26768”, “callback|2|1”) in new stack
May 25 10:53:16 VERBOSE[16513] logger.c: – Goto (callback,2,1)
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing Set(“SIP/66.54.140.46-b7d26768”, “CALL=17329830228”) in new stack
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing Set(“SIP/66.54.140.46-b7d26768”, “DESTINATION=disa.4.1”) in new stack
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing Set(“SIP/66.54.140.46-b7d26768”, “SLEEP=5”) in new stack
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing System(“SIP/66.54.140.46-b7d26768”, “/var/lib/asterisk/bin/callback 17329830228 disa.4.1 5 &”) in new stack
May 25 10:53:16 VERBOSE[16513] logger.c: – Executing Hangup(“SIP/66.54.140.46-b7d26768”, “”) in new stack
May 25 10:53:16 VERBOSE[16513] logger.c: == Spawn extension (callback, 2, 5) exited non-zero on ‘SIP/66.54.140.46-b7d26768’
May 25 10:53:16 DEBUG[16513] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
May 25 10:53:16 DEBUG[16513] 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-05-25 10:53:16’,’“Unknown” ‘,‘Unknown’,‘2’,‘callback’, ‘SIP/66.54.140.46-b7d26768’,’’,‘Hangup’,’’,0,0,‘NO ANSWER’,3,’’)
May 25 10:53:16 ERROR[16513] cdr_addon_mysql.c: mysql_cdr: Failed to insert into database: (1146) Table ‘asterisk.cdr’ doesn’t existMay 25 10:53:16 DEBUG[16513] pbx.c: Function result is '“Unknown” '
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is 'Unknown’
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is '2’
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is 'callback’
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is 'SIP/66.54.140.46-b7d26768’
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is '(null)'
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is 'Hangup’
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is '(null)'
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is '2007-05-25 10:53:16’
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is '(null)'
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is '2007-05-25 10:53:16’
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is '0’
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is '0’
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is 'NO ANSWER’
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is 'DOCUMENTATION’
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is '(null)'
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is '1180104796.616’
May 25 10:53:16 DEBUG[16513] pbx.c: Function result is '(null)'
May 25 10:53:16 DEBUG[16513] chan_sip.c: update_call_counter() - decrement call limit counter
May 25 10:53:16 DEBUG[16513] chan_sip.c: AST hangup cause 16 (no match found in SIP)
May 25 10:53:16 DEBUG[3150] chan_sip.c: Auto destroying call '[email protected]
May 25 10:53:16 DEBUG[3150] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Response 102: Match Found[/code:1]

And here is the CLI output

[code:1] – Accepting AUTHENTICATED call from 199.172.228.206:
> requested format = gsm,
> requested prefs = (),
> actual format = ulaw,
> host prefs = (ulaw|alaw|gsm),
> priority = mine
– Executing Macro(“IAX2/104-5”, “dialout-trunk|11|13605153566||”) in new stack
– Executing Set(“IAX2/104-5”, “DIAL_TRUNK=11”) in new stack
– Executing Set(“IAX2/104-5”, “DIAL_NUMBER=13605153566”) in new stack
– Executing Set(“IAX2/104-5”, “ROUTE_PASSWD=”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?noauth”) in new stack
– Goto (macro-dialout-trunk,s,6)
– Executing GotoIf(“IAX2/104-5”, “0?disabletrunk|1”) in new stack
– Executing Set(“IAX2/104-5”, “_NODEST=”) in new stack
– Executing Set(“IAX2/104-5”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
– Executing Set(“IAX2/104-5”, “GROUP()=OUT_11”) in new stack
– Executing Macro(“IAX2/104-5”, “user-callerid|SKIPTTL”) in new stack
– Executing NoOp(“IAX2/104-5”, “user-callerid: zzzRajan Patel 104”) in new stack
– Executing GotoIf(“IAX2/104-5”, “0?report”) in new stack
– Executing GotoIf(“IAX2/104-5”, “0?start”) in new stack
– Executing Set(“IAX2/104-5”, “REALCALLERIDNUM=104”) in new stack
– Executing NoOp(“IAX2/104-5”, “REALCALLERIDNUM is 104”) in new stack
– Executing Set(“IAX2/104-5”, “AMPUSER=104”) in new stack
– Executing Set(“IAX2/104-5”, “AMPUSERCIDNAME=zzzRajan Patel”) in new stack
– Executing GotoIf(“IAX2/104-5”, “0?report”) in new stack
– Executing Set(“IAX2/104-5”, “AMPUSERCID=104”) in new stack
– Executing Set(“IAX2/104-5”, “CALLERID(all)=zzzRajan Patel <104>”) in new stack
– Executing Set(“IAX2/104-5”, “REALCALLERIDNUM=104”) in new stack
– Executing NoOp(“IAX2/104-5”, “TTL: ARG1: SKIPTTL”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,22)
– Executing NoOp(“IAX2/104-5”, “Using CallerID “zzzRajan Patel” <104>”) in new stack
– Executing Macro(“IAX2/104-5”, “record-enable|104|OUT”) in new stack
– Executing GotoIf(“IAX2/104-5”, “0?2:4”) in new stack
– Goto (macro-record-enable,s,4)
– Executing DeadAGI(“IAX2/104-5”, “recordingcheck|20070525-105313|1180104793.614”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
recordingcheck|20070525-105313|1180104793.614: Outbound recording not enabled
– AGI Script recordingcheck completed, returning 0
– Executing NoOp(“IAX2/104-5”, “No recording needed”) in new stack
– Executing GotoIf(“IAX2/104-5”, “0?skipoutcid”) in new stack
– Executing Set(“IAX2/104-5”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
– Executing Macro(“IAX2/104-5”, “outbound-callerid|11”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?start”) in new stack
– Goto (macro-outbound-callerid,s,3)
– Executing NoOp(“IAX2/104-5”, “REALCALLERIDNUM is 104”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?normcid”) in new stack
– Goto (macro-outbound-callerid,s,9)
– Executing Set(“IAX2/104-5”, “USEROUTCID=“Rajan Patel” <3604880489>”) in new stack
– Executing Set(“IAX2/104-5”, “EMERGENCYCID=”) in new stack
– Executing Set(“IAX2/104-5”, “TRUNKOUTCID=”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?trunkcid”) in new stack
– Goto (macro-outbound-callerid,s,16)
– Executing GotoIf(“IAX2/104-5”, “1?usercid”) in new stack
– Goto (macro-outbound-callerid,s,18)
– Executing GotoIf(“IAX2/104-5”, “0?report”) in new stack
– Executing Set(“IAX2/104-5”, “CALLERID(all)=“Rajan Patel” <3604880489>”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?report:hidecid”) in new stack
– Goto (macro-outbound-callerid,s,22)
– Executing NoOp(“IAX2/104-5”, “CallerID set to “Rajan Patel” <3604880489>”) in new stack
– Executing GotoIf(“IAX2/104-5”, “0?nomax”) in new stack
– Executing GotoIf(“IAX2/104-5”, “0?chanfull”) in new stack
– Executing DeadAGI(“IAX2/104-5”, “fixlocalprefix”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
> fixlocalprefix: Using pattern 1+NXXNXXXXXX
– AGI Script fixlocalprefix completed, returning 0
– Executing Set(“IAX2/104-5”, “OUTNUM=13605153566”) in new stack
– Executing Set(“IAX2/104-5”, “custom=SIP/viatalkIndaba”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?gocall”) in new stack
– Goto (macro-dialout-trunk,s,22)
– Executing GotoIf(“IAX2/104-5”, “0?customtrunk”) in new stack
– Executing Dial(“IAX2/104-5”, “SIP/viatalkIndaba/13605153566|300|tr”) in new stack
– Called viatalkIndaba/13605153566
– Executing NoOp(“SIP/66.54.140.46-b7d26768”, “Received incoming SIP connection from unknown peer to 3605153566”) in new stack
– Executing Set(“SIP/66.54.140.46-b7d26768”, “DID=3605153566”) in new stack
– Executing Goto(“SIP/66.54.140.46-b7d26768”, “s|1”) in new stack
– Goto (from-sip-external,s,1)
– Executing Ringing(“SIP/66.54.140.46-b7d26768”, “”) in new stack
– Executing GotoIf(“SIP/66.54.140.46-b7d26768”, “1?from-trunk|3605153566|1”) in new stack
– Goto (from-trunk,3605153566,1)
– Executing Set(“SIP/66.54.140.46-b7d26768”, “__FROM_DID=3605153566”) in new stack
– Executing Gosub(“SIP/66.54.140.46-b7d26768”, “app-blacklist-check|s|1”) in new stack
– Executing LookupBlacklist(“SIP/66.54.140.46-b7d26768”, “”) in new stack
– Executing GotoIf(“SIP/66.54.140.46-b7d26768”, “0?blacklisted”) in new stack
– Executing Return(“SIP/66.54.140.46-b7d26768”, “”) in new stack
– Executing GotoIf(“SIP/66.54.140.46-b7d26768”, “1 ?cidok”) in new stack
– Goto (from-trunk,3605153566,5)
– Executing NoOp(“SIP/66.54.140.46-b7d26768”, "CallerID is “Unknown” ") in new stack
– Executing Goto(“SIP/66.54.140.46-b7d26768”, “callback|2|1”) in new stack
– Goto (callback,2,1)
– Executing Set(“SIP/66.54.140.46-b7d26768”, “CALL=17329830228”) in new stack
– Executing Set(“SIP/66.54.140.46-b7d26768”, “DESTINATION=disa.4.1”) in new stack
– Executing Set(“SIP/66.54.140.46-b7d26768”, “SLEEP=5”) in new stack
– Executing System(“SIP/66.54.140.46-b7d26768”, “/var/lib/asterisk/bin/callback 17329830228 disa.4.1 5 &”) in new stack
– Executing Hangup(“SIP/66.54.140.46-b7d26768”, “”) in new stack
== Spawn extension (callback, 2, 5) exited non-zero on ‘SIP/66.54.140.46-b7d26768’
– SIP/viatalkIndaba-08cf0d20 is making progress passing it to IAX2/104-5
== Spawn extension (macro-dialout-trunk, s, 23) exited non-zero on ‘IAX2/104-5’ in macro ‘dialout-trunk’
== Spawn extension (macro-dialout-trunk, s, 23) exited non-zero on ‘IAX2/104-5’
– Executing Macro(“IAX2/104-5”, “hangupcall”) in new stack
– Executing ResetCDR(“IAX2/104-5”, “w”) in new stack
– Executing NoCDR(“IAX2/104-5”, “”) in new stack
– Executing GotoIf(“IAX2/104-5”, “1?skiprg”) in new stack
– Goto (macro-hangupcall,s,6)
– Executing GotoIf(“IAX2/104-5”, “1?skipblkvm”) in new stack
– Goto (macro-hangupcall,s,9)
– Executing GotoIf(“IAX2/104-5”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,11)
– Executing Hangup(“IAX2/104-5”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘IAX2/104-5’ in macro ‘hangupcall’
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘IAX2/104-5’
– Hungup ‘IAX2/104-5’
– Registered IAX2 ‘104’ (AUTHENTICATED) at 199.172.228.206:1282[/code:1]

you need to provide a trace (cli and probably log) of the callback script attempting to call you. This shows that the callback script was successfully initiated - but not more wrt to what happened to it - unless it never runs beyond this. (In which case it may be a permission issue although shouldn’t).

Actually, any lines following would be generated when I hang up the call which was supposed to initiate the Callback. (I was still listening to the busy tone on the receiver after calling the number to initiate the callback. You are correct in stating that callback script was successfully initiated - but it was never completed. Please refer to the boldface lines in the CLI snippet below:

[code:1] – Executing NoOp(“SIP/66.54.140.46-b7d125f0”, "CallerID is “Unknown” ") in new stack
– Executing Goto(“SIP/66.54.140.46-b7d125f0”, “callback|2|1”) in new stack
– Goto (callback,2,1)
– Executing Set(“SIP/66.54.140.46-b7d125f0”, “CALL=17329830228”) in new stack
– Executing Set(“SIP/66.54.140.46-b7d125f0”, “DESTINATION=disa.4.1”) in new stack
– Executing Set(“SIP/66.54.140.46-b7d125f0”, “SLEEP=5”) in new stack
– Executing System(“SIP/66.54.140.46-b7d125f0”, “/var/lib/asterisk/bin/callback 17329830228 disa.4.1 5 &”) in new stack
– Executing Hangup(“SIP/66.54.140.46-b7d125f0”, “”) in new stack
== Spawn extension (callback, 2, 5) exited non-zero on ‘SIP/66.54.140.46-b7d125f0’
[/code:1]

It says it hung up, and that it exited non-zero. This happens immediately, there is no pause before that non-zero hangup line pops up…

I will obtain a Asterisk Log when this occurs and include it here with the CLI.

I think in the upgrade, a lot of .conf files which had usernames/passwords were replaced. I had to manually edit amportal.conf so my freepbx could connect to Asterisk Manager.

My CDR Records no longer update, I suppose there is a .conf file I need to modify for that too. Is it cdr_mysql.conf?