Hey guys I was hoping I could get a few pointers on a problem I have been trying to debug for the last couple of months regarding asterisk AGI scripts and unexpected termination.<br>I have this agi script that accepts incoming faxes using RxFax on the latest asterisk 1.4 branch. Its written with perl and it works fine except for one line that causes the entire script to terminate unexpectedly.<br>
<br>The script always terminates at the point where I use the 'system' command or backticks to run a system command.<br>Example:<br>system( "/usr/bin/tiff2pdf -f -p letter -o $faxpath/$unique.pdf $faxpath/$unique.tiff" );<br>
<br>The asterisk log with agi debugging on is pasted below<br><br>I have tried everything I can think of over the past few months, taking a break every so often obviously, but now I feel like I really need outside eyes.<br>
<br>Its worth noting that the script runs fine without running the system command, and it does not matter which system command I run. I tried just doing a simple copy of the file and it failed in the same place.<br>Asterisk leaves me with little help, just explaining that the script returned non-zero.<br>
<br>Are there any issues I should be aware of when running system commands from an AGI script? I did check permissions and made sure my asterisk user can write to /tmp and use the converting commands. I did a lot more testing of course but that is probably the biggest face-palm error there could be.<br>
<br>Asterisk log:<br><br> -- Launched AGI Script /var/lib/asterisk/agi-bin/fax.agi<br>AGI Tx >> agi_request: fax.agi<br>AGI Tx >> agi_channel: SIP/trunk-00000035<br>AGI Tx >> agi_language: en<br>AGI Tx >> agi_type: SIP<br>
AGI Tx >> agi_uniqueid: 1296624119.53<br>AGI Tx >> agi_callerid: anonymous<br>AGI Tx >> agi_calleridname: Anonymous<br>AGI Tx >> agi_callingpres: 32<br>AGI Tx >> agi_callingani2: 0<br>AGI Tx >> agi_callington: 0<br>
AGI Tx >> agi_callingtns: 0<br>AGI Tx >> agi_dnid: XXXXXXXXXX<br>AGI Tx >> agi_rdnis: unknown<br>AGI Tx >> agi_context: from-trunk<br>AGI Tx >> agi_extension: XXXXXXXXXX<br>AGI Tx >> agi_priority: 3<br>
AGI Tx >> agi_enhanced: 0.0<br>AGI Tx >> agi_accountcode:<br>AGI Tx >><br>AGI Rx << GET VARIABLE EXTEN<br>AGI Tx >> 200 result=1 (XXXXXXXXXX)<br>AGI Rx << GET VARIABLE CALLERID(num)<br>
AGI Tx >> 200 result=1 (anonymous)<br>AGI Rx << VERBOSE "DEBUG: EXTEN - XXXXXXXXXX CID - anonymous" 1<br> fax.agi: DEBUG: EXTEN - XXXXXXXXXX CID - anonymous<br>AGI Tx >> 200 result=1<br>AGI Rx << GET VARIABLE UNIQUEID<br>
AGI Tx >> 200 result=1 (1296624119.53)<br>AGI Rx << VERBOSE "RxFAX XXXXXXXXXX: /tmp/1296624119.53.tiff" 1<br> fax.agi: RxFAX XXXXXXXXXX: /tmp/1296624119.53.tiff<br>AGI Tx >> 200 result=1<br>AGI Rx << EXEC RxFAX "/tmp/1296624119.53.tiff"<br>
-- AGI Script Executing Application: (RxFAX) Options: (/tmp/1296624119.53.tiff)<br>Really destroying SIP dialog '6327EDB3@XXX' Method: OPTIONS<br>[Feb 1 23:22:18] ERROR[13753]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:214 phase_e_handler: [FaxReceived ERROR] result (13) Unexpected message received.<br>
[FaxReceived ERROR] result (13) Unexpected message received.<br>[Feb 1 23:22:18] WARNING[13753]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:478 fax_run: RXFAX: t30_call_active is FALSE.<br>AGI Tx >> 200 result=0<br>
AGI Rx << EXEC RxFAX "/tmp/1296624119.53.tiff"<br> -- AGI Script Executing Application: (RxFAX) Options: (/tmp/1296624119.53.tiff)<br>Really destroying SIP dialog '132f38cb284eef837df0038477511f55@XXX' Method: OPTIONS<br>
REGISTER attempt 1 to XXXXXXXXXX@trunk<br>Really destroying SIP dialog '33dff0b60f7ce29944351e446c2e7b5b@XXX' Method: REGISTER<br>Really destroying SIP dialog 'AE6C429F@XXX' Method: OPTIONS<br>[Feb 1 23:23:17] NOTICE[13753]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:230 phase_d_handler: [RXFAX NEW PAGE]: Channel: SIP/trunk-00000035 Pages: -1224970700 Speed: 14400<br>
[Feb 1 23:23:17] NOTICE[13753]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:231 phase_d_handler: Bad rows: 0 - Longest bad row run: 0 - Compression type: T.4 2-D<br>[Feb 1 23:23:17] NOTICE[13753]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:232 phase_d_handler: Image size bytes: 86071 - Image size: 1728 x 2156 - Image resolution: 8031 x 7700<br>
-- [RXFAX NEW PAGE]: Channel: SIP/trunk-00000035 Pages: -1224970700 Speed: 14400<br>[Feb 1 23:23:18] NOTICE[13752]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:230 phase_d_handler: [RXFAX NEW PAGE]: Channel: SIP/trunk-00000034 Pages: -1225599608 Speed: 14400<br>
[Feb 1 23:23:18] NOTICE[13752]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:231 phase_d_handler: Bad rows: 0 - Longest bad row run: 0 - Compression type: T.4 2-D<br>[Feb 1 23:23:18] NOTICE[13752]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:232 phase_d_handler: Image size bytes: 86072 - Image size: 1728 x 2156 - Image resolution: 8031 x 7700<br>
-- [RXFAX NEW PAGE]: Channel: SIP/trunk-00000034 Pages: -1225599608 Speed: 14400<br>Really destroying SIP dialog '439a2cca2a745a565a4e0aab56a054b8@XXX' Method: OPTIONS<br>Really destroying SIP dialog '49515A3F@XXX' Method: OPTIONS<br>
[Feb 1 23:23:59] NOTICE[13753]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:230 phase_d_handler: [RXFAX NEW PAGE]: Channel: SIP/trunk-00000035 Pages: -1224970700 Speed: 14400<br>[Feb 1 23:23:59] NOTICE[13753]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:231 phase_d_handler: Bad rows: 0 - Longest bad row run: 0 - Compression type: T.4 2-D<br>
[Feb 1 23:23:59] NOTICE[13753]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:232 phase_d_handler: Image size bytes: 70190 - Image size: 1728 x 2156 - Image resolution: 8031 x 7700<br> -- [RXFAX NEW PAGE]: Channel: SIP/trunk-00000035 Pages: -1224970700 Speed: 14400<br>
[Feb 1 23:24:00] NOTICE[13752]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:230 phase_d_handler: [RXFAX NEW PAGE]: Channel: SIP/trunk-00000034 Pages: -1225599608 Speed: 14400<br>[Feb 1 23:24:00] NOTICE[13752]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:231 phase_d_handler: Bad rows: 0 - Longest bad row run: 0 - Compression type: T.4 2-D<br>
[Feb 1 23:24:00] NOTICE[13752]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:232 phase_d_handler: Image size bytes: 70191 - Image size: 1728 x 2156 - Image resolution: 8031 x 7700<br> -- [RXFAX NEW PAGE]: Channel: SIP/trunk-00000034 Pages: -1225599608 Speed: 14400<br>
Really destroying SIP dialog '76CF8422@XXX' Method: OPTIONS<br>[Feb 1 23:24:02] NOTICE[13752]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:209 phase_e_handler: [FaxReceived OK] Remote: Local: Pages: 0 Speed: 14400<br>
[FaxReceived OK] Remote: Local: Pages: 0 Speed: 14400<br>[Feb 1 23:24:02] WARNING[13752]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:478 fax_run: TXFAX: t30_call_active is FALSE.<br>[Feb 1 23:24:02] WARNING[13752]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:599 fax_run: TXFAX: Fax Transmission INCOMPLETE, check error code<br>
[Feb 1 23:24:02] WARNING[13752]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:603 fax_run: TXFAX: Transmission RES error = -1<br>[Feb 1 23:24:02] NOTICE[13752]: pbx_spool.c:370 attempt_thread: Call completed to Sip/trunk/XXXXXXXXXX<br>
[Feb 1 23:24:02] NOTICE[13753]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:209 phase_e_handler: [FaxReceived OK] Remote: Local: Pages: 2 Speed: 14400<br> [FaxReceived OK] Remote: Local: Pages: 2 Speed: 14400<br>
[Feb 1 23:24:02] WARNING[13753]: /usr/src/asterisk/agx-ast-addons/app-spandsp/app_fax.c:478 fax_run: RXFAX: t30_call_active is FALSE.<br>AGI Tx >> 200 result=0<br>AGI Rx << VERBOSE "Converting /tmp/1296624119.53.tiff to /tmp/1296624119.53.pdf" 1<br>
fax.agi: Converting /tmp/1296624119.53.tiff to /tmp/1296624119.53.pdf<br>AGI Tx >> 200 result=1<br>Really destroying SIP dialog '371b80c6324ece0c779653c34d2e88a2@XXX' Method: INVITE<br> == Spawn extension (from-trunk, XXXXXXXXXX, 3) exited non-zero on 'SIP/trunk-00000035'<br>
<br>