I can replicate this on my system (I'm running Asterisk 13 on -current at the moment), including with a simpler script that just touches a file in /tmp and doesn't deal with input at all; script doesn't appear to run at all.
The asterisk code involved in this hasn't been modified in 4 years or so. For anyone else interested, it looks like this: http://svnview.digium.com/svn/asterisk/branches/13/res/res_agi.c?view=markup#l1828 http://svnview.digium.com/svn/asterisk/branches/13/main/app.c?view=markup#l2904 I've given it a bit of a poke with added logging in Asterisk but not getting very far there, either I'm doing something wrong with my ast_log(..) additions, or the if (!pid) block after line 1893 in res_agi.c isn't getting run at all. On 2015/02/22 20:57, Alexey Suslikov wrote: > Hello. > > Found while migrating to 5.7 snap. > > Two systems: > * 5.6 (RELEASE) running Asterisk 11.11 > * 5.7 (Feb 22 snap) running Asterisk 11.16 (also tried with 11.11, 11.7, > 11.5.1) > > Both systems have same Asterisk setup. > > extensions.conf: > [from-trunk] > exten => _XXXXXXXXXX,1,Wait(1) > exten => _XXXXXXXXXX,n,AGI(test.agi) > exten => _XXXXXXXXXX,n,System(/bin/pwd) > exten => _XXXXXXXXXX,n,Hangup > > mount: > /dev/sd0a on / type ffs (local) > /dev/sd0d on /tmp type ffs (local, nodev, nosuid, softdep) > /dev/sd0f on /usr type ffs (local, nodev) > /dev/sd0e on /var type ffs (local, nodev, nosuid, softdep) > > ls -l /usr/local/share/asterisk/agi-bin/test.agi: > -rwxrwx--- 1 _asterisk _asterisk 246 Feb 22 18:58 > /usr/local/share/asterisk/agi-bin/test.agi > > test.agi: > #!/bin/sh > > readToFile() { > stdin="0" > > while [ "${stdin}" != "" ]; do > read stdin > if [ "${stdin}" != EOF ]; then > echo ${stdin} >> /tmp/agi.log > fi > done > } > > readToFile > echo "VERBOSE \"Output debug string to * cli\" 3" > read RESPONSE > > exit 0 > > But behavior of executing AGI/System is weirdly different (calling System > is provided to show a fact that problem maybe not in AGI itself but with > exec'ing external stuff). > > On 5.6/11.11: > > [Feb 22 18:02:17] VERBOSE[-1][C-00000017] netsock2.c: == Using SIP > RTP TOS bits 184 > [Feb 22 18:02:17] VERBOSE[-1][C-00000017] pbx.c: -- Executing > [XXXXXXXXXX@from-trunk:1] Wait("SIP/test-145-00000017", "1") in new > stack > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] pbx.c: -- Executing > [XXXXXXXXXX@from-trunk:2] AGI("SIP/test-145-00000017", "test.agi") in > new stack > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: -- Launched > AGI Script /usr/local/share/asterisk/agi-bin/test.agi > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_request: test.agi > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_channel: SIP/test-145-00000017 > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_language: ru > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_type: SIP > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_uniqueid: 1424620937.23 > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_version: 11.11.0 > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_callerid: asterisk > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_calleridname: anonymous > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_callingpres: 0 > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_callingani2: 0 > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_callington: 0 > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_callingtns: 0 > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_dnid: XXXXXXXXXX > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_rdnis: unknown > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_context: from-trunk > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_extension: XXXXXXXXXX > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_priority: 2 > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_enhanced: 0.0 > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_accountcode: > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> agi_threadid: 34529947892224 > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Rx << VERBOSE "Output debug string to * > cli" 3 > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: -- test.agi: > Output debug string to * cli > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: > <SIP/test-145-00000017>AGI Tx >> 200 result=1 > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] res_agi.c: -- > <SIP/test-145-00000017>AGI Script test.agi completed, returning 0 > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] pbx.c: -- Executing > [XXXXXXXXXX@from-trunk:3] System("SIP/test-145-00000017", "/bin/pwd") > in new stack > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] pbx.c: -- Executing > [XXXXXXXXXX@from-trunk:4] Hangup("SIP/test-145-00000017", "") in new > stack > [Feb 22 18:02:18] VERBOSE[-1][C-00000017] pbx.c: == Spawn extension > (from-trunk, XXXXXXXXXX, 4) exited non-zero on 'SIP/test-145-00000017' > > On 5.7/11.16 (and other mentioned above Asterisk versions): > > [Feb 22 18:05:40] VERBOSE[-1][C-00000007] netsock2.c: == Using SIP > RTP TOS bits 184 > [Feb 22 18:05:40] VERBOSE[-1][C-00000007] pbx.c: -- Executing > [XXXXXXXXXX@from-trunk:1] Wait("SIP/test-145-00000007", "1") in new > stack > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] pbx.c: -- Executing > [XXXXXXXXXX@from-trunk:2] AGI("SIP/test-145-00000007", "test.agi") in > new stack > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: -- Launched > AGI Script /usr/local/share/asterisk/agi-bin/test.agi > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_request: test.agi > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_channel: SIP/test-145-00000007 > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_language: ru > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_type: SIP > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_uniqueid: 1424621140.7 > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_version: 11.16.0 > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_callerid: asterisk > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_calleridname: anonymous > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_callingpres: 0 > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_callingani2: 0 > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_callington: 0 > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_callingtns: 0 > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_dnid: XXXXXXXXXX > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_rdnis: unknown > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_context: from-trunk > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_extension: XXXXXXXXXX > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_priority: 2 > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_enhanced: 0.0 > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_accountcode: > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> agi_threadid: 25204087336192 > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: > <SIP/test-145-00000007>AGI Tx >> > [Feb 22 18:05:41] ERROR[-1][C-00000007] utils.c: write() returned > error: Broken pipe > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] res_agi.c: -- > <SIP/test-145-00000007>AGI Script test.agi completed, returning 0 > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] pbx.c: -- Executing > [XXXXXXXXXX@from-trunk:3] System("SIP/test-145-00000007", "/bin/pwd") > in new stack > [Feb 22 18:05:41] WARNING[-1][C-00000007] app_system.c: Unable to > execute '/bin/pwd' > [Feb 22 18:05:41] VERBOSE[-1][C-00000007] pbx.c: == Spawn extension > (from-trunk, XXXXXXXXXX, 3) exited non-zero on 'SIP/test-145-00000007' > > Notice 'Broken pipe' and 'Unable to execute'. > > I'm out of ideas so any help is welcome. > > Cheers, > Alexey >
