Asterisk AGI randomly returning 4 and failing to execute PHP

I’ve got a PHP script that I execute 2-3 times throughout a single calls life time, if it is inbound it will execute once for the queue, once for start of call and a last time for end of call. For outbound it skips the queue stage (obviously).

About 1 in every 1,000-2,000 calls the last event, end of call, errors, there does not seem to be a pattern in time or conditions of the call.

In the logs this is what I get (trimmed down the noise)

-- Executing [h@sub-queue-bookings:1] Set("SIP/CL-000298d4", "CALLWHEN=END") in new stack -- Executing [h@sub-queue-bookings:2] AGI("SIP/CL-000298d4", "presence_2.php") in new stack -- Launched AGI Script /var/lib/asterisk/agi-bin/presence_2.php AGI Tx >> agi_request: presence_2.php AGI Tx >> agi_channel: SIP/CL-000298d4 AGI Tx >> agi_language: en_AU AGI Tx >> agi_type: SIP AGI Tx >> agi_uniqueid: 1405038747.11111 AGI Tx >> agi_version: AGI Tx >> agi_callerid: anonymous AGI Tx >> agi_calleridname: NZ anonymous AGI Tx >> agi_callingpres: 0 AGI Tx >> agi_callingani2: 0 AGI Tx >> agi_callington: 0 AGI Tx >> agi_callingtns: 0 AGI Tx >> agi_dnid: anonymous AGI Tx >> agi_rdnis: unknown AGI Tx >> agi_context: sub-queue-bookings AGI Tx >> agi_extension: h AGI Tx >> agi_priority: 2 AGI Tx >> agi_enhanced: 0.0 AGI Tx >> agi_accountcode: AGI Tx >> agi_threadid: 139985928873744 AGI Tx >> -- AGI Script presence_2.php completed, returning 4
I added in a logging function on to the script to write to the script whenever it runs, before AGI library (PHPAgi) get’s included, when this error occurs it does not write to the log. So I don’t believe it has anything to do with the AGI communication on the script

The extension.conf that calls the script looks like this:

;Hangup Event exten => h,1,Set(CALLWHEN=END) exten => h,n,AGI(presence_2.php)
I have also included the following in the PHP script in an effort to prevent it being killed off (it didn’t seem to make a difference):

/* Evil Process Block Fixing Code */ declare(ticks = 1); pcntl_signal(SIGHUP, SIG_IGN); pcntl_signal(SIGPIPE, SIG_IGN); pcntl_signal(SIGILL, SIG_IGN); pcntl_signal(SIGQUIT, SIG_IGN); pcntl_signal(SIGABRT, SIG_IGN); pcntl_signal(SIGSEGV, SIG_IGN); pcntl_signal(SIGTERM, SIG_IGN);
What advice can someone give me to prevent this from happening? (Adding something to the PHP script, check x, rewrite the extensions.conf, log some extra information, etc). I’m fairly stumped, I’ve googled around and found a few people experiencing almost the exact same thing as me, but no solutions except for “deal with it”…

This is what a “regular” AGI execution looks like:

-- Executing [h@sub-queue-sales:1] Set("SIP/CL-00029e74", "CALLWHEN=END") in new stack -- Executing [h@sub-queue-sales:2] AGI("SIP/CL-00029e74", "presence_2.php") in new stack -- Launched AGI Script /var/lib/asterisk/agi-bin/presence_2.php <SIP/CL-00029e74>AGI Tx >> agi_request: presence_2.php <SIP/CL-00029e74>AGI Tx >> agi_channel: SIP/CL-00029e74 <SIP/CL-00029e74>AGI Tx >> agi_language: en_AU <SIP/CL-00029e74>AGI Tx >> agi_type: SIP <SIP/CL-00029e74>AGI Tx >> agi_uniqueid: 1405134386.171952 <SIP/CL-00029e74>AGI Tx >> agi_version: <SIP/CL-00029e74>AGI Tx >> agi_callerid: 000000000 <SIP/CL-00029e74>AGI Tx >> agi_calleridname: 000000000 <SIP/CL-00029e74>AGI Tx >> agi_callingpres: 0 <SIP/CL-00029e74>AGI Tx >> agi_callingani2: 0 <SIP/CL-00029e74>AGI Tx >> agi_callington: 0 <SIP/CL-00029e74>AGI Tx >> agi_callingtns: 0 <SIP/CL-00029e74>AGI Tx >> agi_dnid: 000000000 <SIP/CL-00029e74>AGI Tx >> agi_rdnis: unknown <SIP/CL-00029e74>AGI Tx >> agi_context: sub-queue-sales <SIP/CL-00029e74>AGI Tx >> agi_extension: h <SIP/CL-00029e74>AGI Tx >> agi_priority: 2 <SIP/CL-00029e74>AGI Tx >> agi_enhanced: 0.0 <SIP/CL-00029e74>AGI Tx >> agi_accountcode: <SIP/CL-00029e74>AGI Tx >> agi_threadid: 139987080693520 <SIP/CL-00029e74>AGI Tx >> <SIP/CL-00029e74>AGI Rx << GET VARIABLE UNIQUEID <SIP/CL-00029e74>AGI Tx >> 200 result=1 (1405134386.171952) <SIP/CL-00029e74>AGI Rx << GET VARIABLE UNIQUEID <SIP/CL-00029e74>AGI Tx >> 200 result=1 (1405134386.171952) <SIP/CL-00029e74>AGI Rx << VERBOSE "Started: 1405134386.171952" 1 presence_2.php: Started: 1405134386.171952 ........ lots of events and communcation with AGI ........ <SIP/CL-00029e74>AGI Tx >> 200 result=1 -- <SIP/CL-00029e74>AGI Script presence_2.php completed, returning 0

NOTE: I stripped out all identifying information from these logs
NOTE2: Using Asterisk 1.8.5


I experienced the same and found nothing. As a matter of testing, I changed AGI() to System() and I haven’t faced this issue afterwards.