[Home]

Summary:ASTERISK-14335: MixMonitor - utils.c: write() returned error: Broken pipe
Reporter:Vikas Varshney (astvikas)Labels:
Date Opened:2009-06-18 08:06:50Date Closed:2009-09-17 14:51:16
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Applications/app_mixmonitor
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) full.txt
Description:Whenever i use mixmonitor or call AGI in dialplan following error comes on asterisk CLI and i think because of this my D-Channel goes down and calls are getting disocnnected.

****** ADDITIONAL INFORMATION ******

[Jun 18 01:38:57] VERBOSE[16563] logger.c:   == Parsing '/etc/asterisk/unistim.conf': [Jun 18 01:38:57] VERBOSE[16563] logger.c:   == Found
[Jun 18 01:41:07] VERBOSE[16537] logger.c:     -- Accepting overlap call from '' to '<unspecified>' on channel 0/31, span 3
[Jun 18 01:41:07] VERBOSE[16575] logger.c:     -- Starting simple switch on 'DAHDI/93-1'
[Jun 18 01:41:18] VERBOSE[16575] logger.c:     -- Executing [9769098084@incoming:1] �[1;36;40mChanIsAvail�[0;37;40m("�[1;35;40mDAHDI/93-1�[0;37;40m", "�[1;35;40mDAHDI/r1&DAHDI/r2�[0;37;40m") in new stack
[Jun 18 01:41:18] VERBOSE[16575] logger.c:     -- Hungup 'DAHDI/1-1'
[Jun 18 01:41:18] VERBOSE[16575] logger.c:     -- Executing [9769098084@incoming:2] �[1;36;40mSet�[0;37;40m("�[1;35;40mDAHDI/93-1�[0;37;40m", "�[1;35;40mCALLTIME=18-Jun-2009-01-41-18�[0;37;40m") in new stack
[Jun 18 01:41:18] VERBOSE[16575] logger.c:     -- Executing [9769098084@incoming:3] �[1;36;40mSet�[0;37;40m("�[1;35;40mDAHDI/93-1�[0;37;40m", "�[1;35;40mRECSUBDIR=18Jun2009�[0;37;40m") in new stack
[Jun 18 01:41:18] VERBOSE[16575] logger.c:     -- Executing [9769098084@incoming:4] �[1;36;40mSet�[0;37;40m("�[1;35;40mDAHDI/93-1�[0;37;40m", "�[1;35;40mlength=10�[0;37;40m") in new stack
[Jun 18 01:41:18] VERBOSE[16575] logger.c:     -- Executing [9769098084@incoming:5] �[1;36;40mGotoIf�[0;37;40m("�[1;35;40mDAHDI/93-1�[0;37;40m", "�[1;35;40m1?A:B�[0;37;40m") in new stack
[Jun 18 01:41:18] VERBOSE[16575] logger.c:     -- Goto (incoming,9769098084,6)
[Jun 18 01:41:18] VERBOSE[16575] logger.c:     -- Executing [9769098084@incoming:6] �[1;36;40mMixMonitor�[0;37;40m("�[1;35;40mDAHDI/93-1�[0;37;40m", "�[1;35;40m/var/spool/asterisk/monitor/Recordings_1/18Jun2009/3-1_9769098084_18-Jun-2009-01-41-18.WAV�[0;37;40m") in new stack
[Jun 18 01:41:18] VERBOSE[16575] logger.c:     -- Executing [9769098084@incoming:7] �[1;36;40mAGI�[0;37;40m("�[1;35;40mDAHDI/93-1�[0;37;40m", "�[1;35;40mMonitor.agi,DAHDI/1-1,O,3-1_9769098084_18-Jun-2009-01-41-18.WAV,1245269467.0,18Jun2009�[0;37;40m") in new stack
[Jun 18 01:41:18] VERBOSE[16575] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/Monitor.agi
[Jun 18 01:41:18] VERBOSE[16576] logger.c:   == Begin MixMonitor Recording DAHDI/93-1
[Jun 18 01:41:18] NOTICE[16575] utils.c: Timed out trying to write
[Jun 18 01:41:18] NOTICE[16575] utils.c: Timed out trying to write
[Jun 18 01:41:18] NOTICE[16575] utils.c: Timed out trying to write
[Jun 18 01:41:18] NOTICE[16575] utils.c: Timed out trying to write
[Jun 18 01:41:19] NOTICE[16575] utils.c: Timed out trying to write
[Jun 18 01:41:19] NOTICE[16575] utils.c: Timed out trying to write
[Jun 18 01:41:19] NOTICE[16575] utils.c: Timed out trying to write
[Jun 18 01:41:19] NOTICE[16575] utils.c: Timed out trying to write
[Jun 18 01:41:19] NOTICE[16575] utils.c: Timed out trying to write
[Jun 18 01:41:19] NOTICE[16575] utils.c: Timed out trying to write
[Jun 18 01:41:19] NOTICE[16575] utils.c: Timed out trying to write
[Jun 18 01:41:19] NOTICE[16575] utils.c: Timed out trying to write
[Jun 18 01:41:19] ERROR[16575] utils.c: write() returned error: Broken pipe
[Jun 18 01:41:19] ERROR[16575] utils.c: write() returned error: Broken pipe
[Jun 18 01:41:19] ERROR[16575] utils.c: write() returned error: Broken pipe
[Jun 18 01:41:19] ERROR[16575] utils.c: write() returned error: Broken pipe
[Jun 18 01:41:19] ERROR[16575] utils.c: write() returned error: Broken pipe
[Jun 18 01:41:19] ERROR[16575] utils.c: write() returned error: Broken pipe
[Jun 18 01:41:19] ERROR[16575] utils.c: write() returned error: Broken pipe
[Jun 18 01:41:19] ERROR[16575] utils.c: write() returned error: Broken pipe
[Jun 18 01:41:19] ERROR[16575] utils.c: write() returned error: Broken pipe
[Jun 18 01:41:19] ERROR[16575] utils.c: write() returned error: Broken pipe
[Jun 18 01:41:19] ERROR[16575] utils.c: write() returned error: Broken pipe
[Jun 18 01:41:19] ERROR[16575] utils.c: write() returned error: Broken pipe
[Jun 18 01:41:19] ERROR[16575] utils.c: write() returned error: Broken pipe
[Jun 18 01:41:19] VERBOSE[16575] logger.c:     -- <DAHDI/93-1>AGI Script Monitor.agi completed, returning 0
[Jun 18 01:41:19] VERBOSE[16575] logger.c:     -- Executing [9769098084@incoming:8] �[1;36;40mSet�[0;37;40m("�[1;35;40mDAHDI/93-1�[0;37;40m", "�[1;35;40mChanLength=9�[0;37;40m") in new stack
[Jun 18 01:41:19] VERBOSE[16575] logger.c:     -- Executing [9769098084@incoming:9] �[1;36;40mSet�[0;37;40m("�[1;35;40mDAHDI/93-1�[0;37;40m", "�[1;35;40mNewChannel=DAHDI/1�[0;37;40m") in new stack
[Jun 18 01:41:19] VERBOSE[16575] logger.c:     -- Executing [9769098084@incoming:10] �[1;36;40mDial�[0;37;40m("�[1;35;40mDAHDI/93-1�[0;37;40m", "�[1;35;40mDAHDI/1/9769098084,60,tT�[0;37;40m") in new stack
[Jun 18 01:41:19] VERBOSE[16575] logger.c:     -- Requested transfer capability: 0x10 - 3K1AUDIO
[Jun 18 01:41:19] VERBOSE[16575] logger.c:     -- Called 1/9769098084
[Jun 18 01:41:19] VERBOSE[16575] logger.c:     -- DAHDI/1-1 is proceeding passing it to DAHDI/93-1
[Jun 18 01:41:20] VERBOSE[16575] logger.c:     -- DAHDI/1-1 is making progress passing it to DAHDI/93-1
Comments:By: rosa (rosa) 2009-06-19 02:41:57

Hi all

We have the same trouble when we execute an AGI, we have upgraded the system from 1.4.11 to 1.4.24 and all the logs are full with the same error.

And when is up 2 days the asterisk is 200% of CPU!

It's something strange because it doesn't happen before the upgrade, and it seems is related with the AGI execution.


[Jun 18 14:33:21] ERROR[9343] channel.c: ast_read() called with no recorded file descriptor.
[Jun 18 14:33:56] ERROR[9343] utils.c: write() returned error: Broken pipe
[Jun 18 14:33:56] ERROR[9343] utils.c: write() returned error: Broken pipe
[Jun 18 14:40:01] ERROR[9443] utils.c: write() returned error: Broken pipe
[Jun 18 14:40:01] ERROR[9449] utils.c: write() returned error: Broken pipe
[Jun 18 14:49:11] ERROR[9546] channel.c: ast_read() called with no recorded file descriptor.
[Jun 18 14:49:57] ERROR[9546] utils.c: write() returned error: Broken pipe
[Jun 18 14:49:57] ERROR[9546] utils.c: write() returned error: Broken pipe
[Jun 18 14:50:01] ERROR[9590] utils.c: write() returned error: Broken pipe
By: rosa (rosa) 2009-06-19 04:07:31

Ok, it seems the problem is with AMI connections, when we make a connection by AMI we have 3 erros in the messages all with broken pipe of the utils.c
By: Jon Bonilla (manwe) 2009-06-19 04:27:31

ROsa: I had those problems too using a munin plugin wich uses AMI to retreive information. After deleting last \n characters that message dissapeared.

I don't think those AMI connection messages (Broken Pipe) could cause 100% CPU usage.
By: rosa (rosa) 2009-06-19 06:02:19

Manwe: Ok, I've removed the \n and the error doesn't appear in the logs. Thanks!

I know that it shouldn't be the problem but I need the less errors to find out what is going on.
By: David Vossel (dvossel) 2009-07-15 12:31:18

can you include an example of the dialplan you are using to cause this?
By: Adam Azad (adam_pchl) 2009-07-20 10:51:06

I am having a similar issue with my PBX. Attached is a show dialplan:

sipsrv03*CLI> show dialplan
[ Context 'testpbx-outbound' created by 'pbx_config' ]
 '911' =>          1. GotoIf($[ "${CALLERIDNUM:0:3}" = "200" ]?1000) [pbx_config]
                   2. Dial(SIP/911@64.251.73.162:5061)           [pbx_config]
                   3. Dial(SIP/911@64.251.73.163:5061)           [pbx_config]
                   4. Dial(SIP/911@64.251.73.164:5061)           [pbx_config]
                   5. Dial(SIP/911@64.251.73.165:5061)           [pbx_config]
                   6. Dial(SIP/911@64.251.73.166:5061)           [pbx_config]
                   1000. Set(CALLERID(num)=2313067119)           [pbx_config]
                   1001. Dial(SIP/911@63.208.161.100)            [pbx_config]
 '9911' =>         1. GotoIf($[ "${CALLERIDNUM:0:3}" = "200" ]?1000) [pbx_config]
                   2. Goto(testpbx-outbound|911|1)            [pbx_config]
                   1000. Set(CALLERID(num)=2313067119)           [pbx_config]
                   1001. Dial(SIP/911@63.208.161.100)            [pbx_config]
 'h' =>            1. DEADAGI(pending-calls.agi|end|0|${UNIQUEID}) [pbx_config]
                   2. DEADAGI(log-call.agi|outboundfinish|${EPOCH}|${HANGUPCAUSE}|${CDR(answer)}|${OUTAGENT}|${sipuseragent}) [pbx_config]
                   3. Set(TIMESTAMP=${EPOCH})                    [pbx_config]
                   4. Set(PHONE=${CALLERID(all)})                [pbx_config]
                   5. Set(AGENT=${sipuseragent})                 [pbx_config]
                   6. AGI(wrapupout.agi|wrapupout|${PHONE}|1|${TIMESTAMP}|${AGENT}) [pbx_config]
 '_000NXXNXXXXXX' => 3. Hangup()                                   [pbx_config]
 '_139NXXNXXXXXX' => 2. Set(CALLERID(num)=8775708748)              [pbx_config]
 '_71NXXNXXXXXX' => 1. Set(CALLERID(num)=3134817100)              [pbx_config]
                   2. Set(SIP_CODEC=ulaw)                        [pbx_config]
                   3. Dial(SIP/${EXTEN:1}@216.144.214.130:5060|600) [pbx_config]
 '_8250NXXXXXX' => 1. SIPDTMFMode(rfc2833)                       [pbx_config]
                   2. Dial(SIP/${EXTEN:1}@72.2.3.57:5061)        [pbx_config]
                   3. Dial(SIP/${EXTEN:1}@72.2.3.58:5061)        [pbx_config]
                   4. Dial(SIP/${EXTEN:1}@72.2.3.59:5061)        [pbx_config]
                   5. Dial(SIP/${EXTEN:1}@72.2.3.60:5061)        [pbx_config]
                   6. Dial(SIP/${EXTEN:1}@72.2.3.61:5061)        [pbx_config]
 '_8NXXNXXXXXX' => 1. SIPDTMFMode(rfc2833)                       [pbx_config]
                   2. Dial(SIP/1${EXTEN:1}@72.2.3.57:5061)       [pbx_config]
                   3. Dial(SIP/1${EXTEN:1}@72.2.3.58:5061)       [pbx_config]
                   4. Dial(SIP/1${EXTEN:1}@72.2.3.59:5061)       [pbx_config]
                   5. Dial(SIP/1${EXTEN:1}@72.2.3.60:5061)       [pbx_config]
                   6. Dial(SIP/1${EXTEN:1}@72.2.3.61:5061)       [pbx_config]
 '_9011.' =>       1. GotoIf($[ "${CALLERIDNUM:0:3}" = "200" ]?1000) [pbx_config]
                   2. Set(CALLERID(num)=3134817100)              [pbx_config]
                   3. Dial(SIP/${EXTEN:1}@216.144.214.140:5060)  [pbx_config]
                   1000. Set(CALLERID(num)=2313067119)           [pbx_config]
                   1001. Dial(SIP/${EXTEN:1}@216.144.214.140:5060) [pbx_config]
 '_XXXNXXNXXXXXX' => 1. Set(CALLERID(num)=3134817100)              [pbx_config]
                   2. AGI(set-agent-outbound.agi|${CHANNEL}|${AGENTEXTEN}|${EXTEN}|${CALLERID(all)}) [pbx_config]
                   3. AGI(log-call.agi|outboundstart|${EPOCH}|${EXTEN:3}|pch${EXTEN:0:3}) [pbx_config]
                   4. AGI(pending-calls.agi|out|${CHANNEL}|${UNIQUEID}|${EXTEN:3}|${EPOCH}|${EXTEN:3}|pch${EXTEN:0:3}) [pbx_config]
                   5. Set(MONFILENAME=/var/spool/asterisk/monitor/testpbx/${STRFTIME(${EPOCH}|GMT-5|%G%m%d)}/${STRFTIME(${EPOCH}|GMT-5|%H%M%S)}-${CALLERID(num)}-${EXTEN:3}) [pbx_config]
                   6. Monitor(wav|${MONFILENAME}|m)              [pbx_config]
                   7. Dial(SIP/1${EXTEN:3}@216.144.214.130:5060|300) [pbx_config]
                   8. Hangup()                                   [pbx_config]
 '_XXXXXXXXXX' =>  1. Set(CALLERID(num)=3134817100)              [pbx_config]
 Include =>        'testpbx-extensions'                       [pbx_config]
sipsrv03*CLI>
[ Context 'testpbx-extensions' created by 'pbx_config' ]
 '700' =>          1. Park()                                     [pbx_config]
 '706' =>          1. Dial(SIP/stu)                              [pbx_config]
 '_#6XXX' =>       1. Chanspy(SIP)                               [pbx_config]
 '_ASTERISK-3[1234]0XX1' => 1. AgentCallbackLogin(${EXTEN:2:4}||${CALLERID(num):0:3}@agent-callback) [pbx_config]
                   2. PauseQueueMember(|Agent/${EXTEN:2:4})      [pbx_config]
                   3. AGI(test.agi)                              [pbx_config]
                   4. UnpauseQueueMember(|Agent/${EXTEN:2:4})    [pbx_config]
                   5. Set(AGENT_NUM=${EXTEN:2:4})                [pbx_config]
                   6. Set(TIMESTAMP=${EPOCH})                    [pbx_config]
                   7. Set(PHONE=${CALLERID(num):0:3})            [pbx_config]
                   8. AGI(agent-log.agi|start|${AGENT_NUM}|1|${TIMESTAMP}|${PHONE}) [pbx_config]
                   9. Playback(digits/${EXTEN:2:1})              [pbx_config]
                   10. Playback(digits/${EXTEN:3:1})             [pbx_config]
                   11. Playback(digits/${EXTEN:4:1})             [pbx_config]
                   12. Playback(digits/${EXTEN:5:1})             [pbx_config]
                   13. Playback(auth-thankyou)                   [pbx_config]
                   14. Playback(beep)                            [pbx_config]
 '_ASTERISK-3[1234]0XX2' => 1. Answer()                                   [pbx_config]
                   2. AgentCallbackLogin(${EXTEN:2:4}||#@agent-logoff) [pbx_config]
                   3. Set(AGENT_NUM=${EXTEN:2:4})                [pbx_config]
                   4. Set(TIMESTAMP=${EPOCH})                    [pbx_config]
                   5. AGI(agent-log.agi|start|${AGENT_NUM}|0|${TIMESTAMP}) [pbx_config]
                   6. Playback(agent-loggedoff)                  [pbx_config]
                   7. Hangup()                                   [pbx_config]
                   8. Playback(auth-thankyou)                    [pbx_config]
                   9. Playback(beep)                             [pbx_config]
 '_ASTERISK-3[1234]0XX3' => 1. AgentCallbackLogin(${EXTEN:2:4}||@agent-callback) [pbx_config]
                   2. Set(AGENT_NUM=${EXTEN:2:4})                [pbx_config]
                   3. Set(TIMESTAMP=${EPOCH})                    [pbx_config]
                   4. AGI(agent-log.agi|start|${AGENT_NUM}|1|${TIMESTAMP}) [pbx_config]
                   5. Playback(digits/${EXTEN:2:1})              [pbx_config]
                   6. Playback(digits/${EXTEN:3:1})              [pbx_config]
                   7. Playback(digits/${EXTEN:4:1})              [pbx_config]
                   8. Playback(digits/${EXTEN:5:1})              [pbx_config]
                   9. Playback(auth-thankyou)                    [pbx_config]
                   10. Playback(beep)                            [pbx_config]
 '_*0[1234]0XXX' => 1. PauseQueueMember(|Agent/${EXTEN:2:4})      [pbx_config]
                   2. Set(AGENT_NUM=${EXTEN:2:4})                [pbx_config]
                   3. Set(PAUSE_CODE=${EXTEN:6:1})               [pbx_config]
                   4. Set(TIMESTAMP=${EPOCH})                    [pbx_config]
                   5. AGI(agent-log.agi|start|${AGENT_NUM}|${PAUSE_CODE}|${TIMESTAMP}) [pbx_config]
                   6. Playback(agent-loggedoff)                  [pbx_config]
                   7. Playback(digits/${EXTEN:2:1})              [pbx_config]
                   8. Playback(digits/${EXTEN:3:1})              [pbx_config]
                   9. Playback(digits/${EXTEN:4:1})              [pbx_config]
                   10. Playback(digits/${EXTEN:5:1})             [pbx_config]
                   11. Playback(vm-num-i-have)                   [pbx_config]
                   12. Playback(digits/${EXTEN:6:1})             [pbx_config]
                   13. Playback(auth-thankyou)                   [pbx_config]
                   14. Playback(beep)                            [pbx_config]
 '_*1[1234]0XXX' => 1. UnpauseQueueMember(|Agent/${EXTEN:2:4})    [pbx_config]
                   2. Set(AGENT_NUM=${EXTEN:2:4})                [pbx_config]
                   3. Set(PAUSE_CODE=${EXTEN:6:1})               [pbx_config]
                   4. Set(TIMESTAMP=${EPOCH})                    [pbx_config]
                   5. AGI(agent-log.agi|start|${AGENT_NUM}|${PAUSE_CODE}|${TIMESTAMP}) [pbx_config]
                   6. Playback(agent-loginok)                    [pbx_config]
                   7. Playback(digits/${EXTEN:2:1})              [pbx_config]
                   8. Playback(digits/${EXTEN:3:1})              [pbx_config]
                   9. Playback(digits/${EXTEN:4:1})              [pbx_config]
                   10. Playback(digits/${EXTEN:5:1})             [pbx_config]
                   11. Playback(auth-thankyou)                   [pbx_config]
                   12. Playback(beep)                            [pbx_config]
 '_300' =>         1. Dial(SIP/18662338368@216.144.214.140:5060|300) [pbx_config]
 '_7XX' =>         1. Goto(parkedcalls|${ARG1}|1)                [pbx_config]
 '_oXXX' =>        1. GotoIf($[ "${CALLERIDNUM:0:4}" = "${EXTEN:0:4}" ]?2000) [pbx_config]
                   2. NoOp(${CALLERIDNUM})                       [pbx_config]
                   3. NoOp(${EXTEN:0:4})                         [pbx_config]
                   4. Macro(sipoverflowexten|${EXTEN}|testpbx) [pbx_config]
                   2000. VoiceMailMain(129@testpbx)           [pbx_config]
 '_XXX' =>         1. GotoIf($[ "${CALLERIDNUM:0:3}" = "${EXTEN:0:3}" ]?1000) [pbx_config]
                   2. NoOp(${CALLERIDNUM})                       [pbx_config]
                   3. NoOp(${EXTEN:0:3})                         [pbx_config]
                   4. Macro(sipexten|${EXTEN}|testpbx)        [pbx_config]
                   1000. VoiceMailMain(${EXTEN}@testpbx)      [pbx_config]

[ Context 'testing-outbound' created by 'pbx_config' ]
 '_X1NXXNXXXXXX' => 1. Playback(/var/lib/asterisk/sounds-real/pls-wait-connect-call) [pbx_config]
                   2. Goto(testpbx-outbound|${EXTEN}|1)       [pbx_config]

[ Context 'agent-callback' created by 'pbx_config' ]
 '_XXX' =>         1. GotoIf($["${THEID}" = "9895637126"]?:3)    [pbx_config]
                   2. SIPAddHeader(Alert-Info: n=Simple-5)       [pbx_config]
                   3. Dial(SIP/${EXTEN}.testpbx)              [pbx_config]

[ Context 'agent-logoff' created by 'pbx_config' ]
 '0' =>            1. sendDTMF(#)                                [pbx_config]

[ Context 'admin-queue-out' created by 'pbx_config' ]
 '0' =>            1. Voicemail(u131@testpbx)                 [pbx_config]
 '131' =>          1. Dial(Agent/3000|25|r)                      [pbx_config]
                   2. Voicemail(u131@testpbx)                 [pbx_config]
 '132' =>          1. Dial(Agent/4001|25|r)                      [pbx_config]
                   2. Voicemail(u132@testpbx)                 [pbx_config]
 '140' =>          1. Dial(Agent/4002|25|r)                      [pbx_config]
                   2. Voicemail(u140@testpbx)                 [pbx_config]
 '260' =>          1. Dial(Agent/4000|25|r)                      [pbx_config]
                   2. Voicemail(u260@testpbx)                 [pbx_config]

[ Context 'asc-out' created by 'pbx_config' ]
 '0' =>            1. Voicemail(tu@testpbx)                   [pbx_config]

[ Context 'queue-out' created by 'pbx_config' ]
 '0' =>            1. GotoIf($["${CALLERID(dnid)}" = "2482867120"]?10) [pbx_config]
                   2. AGI(log-call.agi|voicemail)                [pbx_config]
                   3. AGI(pending-calls.agi|end|0|${UNIQUEID})   [pbx_config]
                   4. Voicemail(u129@testpbx)                 [pbx_config]
                   10. Queue(${QUEUE})                           [pbx_config]
 '5' =>            1. GotoIf($["${CALLERID(dnid)}" = "2313167144"]?3) [pbx_config]
                   2. GotoIf($["${CALLERID(dnid)}" = "8662194166"]?:8) [pbx_config]
                   3. GotoIf($[${QUEUE_PRIO} < 20000 ]?:8)       [pbx_config]
                   4. SIPAddHeader(Alert-Info: n=Simple-5)       [pbx_config]
                   5. Set(CALLERID(name)=VIP ${CNAM})            [pbx_config]
                   6. AGI(weight-call.agi|3)                     [pbx_config]
                   7. Set(QUEUE_PRIO=${MYWEIGHT})                [pbx_config]
                   8. Queue(${QUEUE})                            [pbx_config]
 '6' =>            1. GotoIf($["${CALLERID(dnid)}" = "8775708748"]?:4) [pbx_config]
                   2. Dial(SIP/8663577812@216.144.214.133:5060|300) [pbx_config]
                   3. Hangup()                                   [pbx_config]
                   4. Queue(${QUEUE})                            [pbx_config]
 'h' =>            1. DEADAGI(pending-calls.agi|end|0|${UNIQUEID}) [pbx_config]
                   2. DEADAGI(log-call.agi|2|${EPOCH}|${HANGUPCAUSE}|${CDR(answer)}|${CDR(dstchannel)}|${SIPUSERAGENT}|${CDR(accountcode)}) [pbx_config]
                   3. Set(TIMESTAMP=${EPOCH})                    [pbx_config]
                   4. Set(PHONE=${CDR(dstchannel)})              [pbx_config]
                   5. Set(AGENT=${AGENTEXTEN})                   [pbx_config]
                   6. DEADAGI(agent-log.agi|wrapupin|${PHONE}|1|${TIMESTAMP}|${PHONE}) [pbx_config]
sipsrv03*CLI>
[ Context 'callrouter' created by 'pbx_config' ]
 '7345277199' =>   1. Voicemailmain(@testpbx)                 [pbx_config]
 '8663058995' =>   1. Answer()                                   [pbx_config]
                   2. Set(SIP_CODEC=g729)                        [pbx_config]
                   3. SIPDTMFMode(rfc2833)                       [pbx_config]
                   4. Set(START-TIME=${EPOCH})                   [pbx_config]
                   5. AGI(find-queue.agi|${CALLERID(dnid)}|testpbx) [pbx_config]
                   6. SetCallerPres(allowed)                     [pbx_config]
                   7. AGI(weight-call.agi|${DID_PRIOR})          [pbx_config]
                   8. Set(QUEUE_PRIO=${MYWEIGHT})                [pbx_config]
                   9. Set(MONFILENAME=/var/spool/asterisk/monitor/recordings/${STRFTIME(${EPOCH}|GMT+8|%G%m%d)}/${STRFTIME(${EPOCH}|GMT+8|%m.%d.%G %H.%M.%S%p)}-${CNAM}.${CALLERID(dnid)}-${CALLERID(num)}) [pbx_config]
                   10. Monitor(gsm|${MONFILENAME}|m)             [pbx_config]
                   11. Set(OLD_NAME=${CALLERID(name)})           [pbx_config]
                   12. Set(CALLERID(name)=${CNAM})               [pbx_config]
                   13. Set(CALLERID(ani)=${ODID})                [pbx_config]
                   14. Set(QUEUE-TIME=${EPOCH})                  [pbx_config]
                   15. AGI(log-call.agi|start|${START-TIME}|${QUEUE-TIME}|${QUEUE}|${OLD_NAME}|${CDR(accountcode)}|${CHANNEL}) [pbx_config]
                   16. ResetCDR()                                [pbx_config]
                   17. Playback(${INTROMSG})                     [pbx_config]
                   18. Queue(${QUEUE}||||)                       [pbx_config]
 'h' =>            1. DEADAGI(pending-calls.agi|end|0|${UNIQUEID}) [pbx_config]
                   2. DEADAGI(log-call.agi|2|${EPOCH}|${HANGUPCAUSE}|${CDR(answer)}|${CDR(dstchannel)}|${SIPUSERAGENT}|${CDR(accountcode)}) [pbx_config]
                   3. GotoIf($[ "${MINBILLED}" = "1" ]?:6)       [pbx_config]
                   4. NoOp()                                     [pbx_config]
                   5. DEADAGI(billCall.agi|${CDR(billsec)}|${CALLERID(dnid)}) [pbx_config]
                   6. Set(TIMESTAMP=${EPOCH})                    [pbx_config]
                   7. Set(PHONE=${CDR(dstchannel)})              [pbx_config]
                   8. Set(AGENT=${AGENTEXTEN})                   [pbx_config]
                   9. DEADAGI(agent-log.agi|wrapupin|${PHONE}|1|${TIMESTAMP}|${PHONE}) [pbx_config]
 '_XXXXXXXXXX' =>  1. Answer()                                   [pbx_config]
                   2. Set(SIP_CODEC=g729)                        [pbx_config]
                   3. SIPDTMFMode(rfc2833)                       [pbx_config]
                   4. Set(START-TIME=${EPOCH})                   [pbx_config]
                   5. AGI(find-queue.agi|${CALLERID(dnid)}|testpbx) [pbx_config]
                   6. GotoIf($["${CALLERID(dnid)}" = "3136257194"]?:9) [pbx_config]
                   7. SetMusicOnHold(testpbx-kosher)          [pbx_config]
                   8. Goto(70)                                   [pbx_config]
                   9. GotoIf($["${CALLERID(dnid)}" = "9898857128"]?:12) [pbx_config]
                   10. SetMusicOnHold(testpbx-kosher)         [pbx_config]
                   11. Goto(70)                                  [pbx_config]
                   12. GotoIf($["${CALLERID(dnid)}" = "2482867120"]?:15) [pbx_config]
                   13. SetMusicOnHold(no-zero)                   [pbx_config]
                   14. Goto(70)                                  [pbx_config]
                   15. GotoIf($["${CALLERID(dnid)}" = "9895637126"]?:69) [pbx_config]
                   16. SIPAddHeader(Alert-Info: n=Simple-5)      [pbx_config]
                   17. Goto(70)                                  [pbx_config]
                   18. GotoIf($["${CALLERID(dnid)}" = "2482867140"]?:15) [pbx_config]
                   19. SetMusicOnHold(dag-intro)                 [pbx_config]
                   20. Goto(70)                                  [pbx_config]
                   69. SetMusicOnHold(${QUEUE}-default)          [pbx_config]
                   70. SetCallerPres(allowed)                    [pbx_config]
                   71. AGI(weight-call.agi|${DID_PRIOR})         [pbx_config]
                   72. Set(QUEUE_PRIO=${MYWEIGHT})               [pbx_config]
                   73. GotoIf($[ "${QUEUE}" = "" ]?200)          [pbx_config]
                   74. AGI(checkTimeRemaining.agi|${CALLERID(dnid)}) [pbx_config]
                   75. GotoIf($[ "${MINBILLED}" = "1" ]?:77)     [pbx_config]
                   76. GotoIf($[ "${MINREMAIN}" <= "0" ]?300)    [pbx_config]
                   77. Playback(/var/spool/asterisk/voicemail/testpbx/${INTRO}/unavail) [pbx_config]
                   78. Set(MONFILENAME=/var/spool/asterisk/monitor/recordings/${STRFTIME(${EPOCH}|GMT+8|%G%m%d)}/${STRFTIME(${EPOCH}|GMT+8|%m.%d.%G %H.%M.%S%p)}-.${CNAM}.${CALLERID(dnid)}-${CALLERID(num)}) [pbx_config]
                   79. Monitor(gsm|${MONFILENAME}|m)             [pbx_config]
                   80. Set(OLD_NAME=${CALLERID(name)})           [pbx_config]
                   81. Set(CALLERID(name)=${CNAM})               [pbx_config]
                   82. Set(CALLERID(ani)=${ODID})                [pbx_config]
                   83. Set(__THEID=${CALLERID(dnid)})            [pbx_config]
                   84. Set(QUEUE-TIME=${EPOCH})                  [pbx_config]
                   85. AGI(log-call.agi|start|${START-TIME}|${QUEUE-TIME}|${QUEUE}|${OLD_NAME}|${CDR(accountcode)}|${CHANNEL}) [pbx_config]
                   86. AGI(pending-calls.agi|start|1|${START-TIME}|${QUEUE}|abc123|${CALLERID(NAME)}|${CHANNEL}|${UNIQUEID}) [pbx_config]
                   87. ResetCDR()                                [pbx_config]
                   88. Playback(${INTROMSG})                     [pbx_config]
                   89. Set(foo=${UNIQUEID})                      [pbx_config]
                   90. Set(foo2=${QUEUE})                        [pbx_config]
                   91. Set(foo3=${CHANNEL})                      [pbx_config]
                   92. Queue(${QUEUE}|||||callpickup.agi)        [pbx_config]
                   200. Playback(no-support-enabled)             [pbx_config]
                   201. Hangup()                                 [pbx_config]
                   300. Playback(no-support-enabled)             [pbx_config]
                   301. Goto(queue-out|0|2)                      [pbx_config]

[ Context 'default' created by 'pbx_config' ]
 '299' =>          1. Ringing()                                  [pbx_config]
                   2. Wait(120)                                  [pbx_config]
 '_XXXXXXXXXX' =>  1. Set(VCONTEXT=${CUT(SIPDOMAIN|.|1)})        [pbx_config]
                   2. Goto(callrouter|${EXTEN}|1)                [pbx_config]

[ Context 'macro-sipoverflowexten' created by 'pbx_config' ]
 'a' =>            1. VoicemailMain(129@${ARG2})                 [pbx_config]
 's' =>            1. Dial(SIP/${ARG1}.${ARG2}|20|${ARG3})       [pbx_config]
                   2. Goto(s-${DIALSTATUS}|1)                    [pbx_config]
 's-BUSY' =>       1. Voicemail(b129@${ARG2})                    [pbx_config]
                   2. Goto(default|s|1)                          [pbx_config]
 's-NOANSWER' =>   1. Voicemail(u129@${ARG2})                    [pbx_config]
                   2. Goto(default|s|1)                          [pbx_config]
 '_s-.' =>         1. Goto(s-NOANSWER|1)                         [pbx_config]

[ Context 'macro-sipexten' created by 'pbx_config' ]
 'a' =>            1. VoicemailMain(${ARG1}@${ARG2})             [pbx_config]
 's' =>            1. Dial(SIP/${ARG1}.${ARG2}|20|${ARG3})       [pbx_config]
                   2. Goto(s-${DIALSTATUS}|1)                    [pbx_config]
 's-BUSY' =>       1. Voicemail(b${ARG1}@${ARG2})                [pbx_config]
                   2. Goto(default|s|1)                          [pbx_config]
 's-NOANSWER' =>   1. Voicemail(u${ARG1}@${ARG2})                [pbx_config]
                   2. Goto(default|s|1)                          [pbx_config]
 '_s-.' =>         1. Goto(s-NOANSWER|1)                         [pbx_config]

[ Context 'macro-stdexten' created by 'pbx_config' ]
 'a' =>            1. VoicemailMain(${ARG1})                     [pbx_config]
 's' =>            1. Dial(${ARG2}|20)                           [pbx_config]
                   2. Goto(s-${DIALSTATUS}|1)                    [pbx_config]
 's-BUSY' =>       1. Voicemail(b${ARG1})                        [pbx_config]
                   2. Goto(default|s|1)                          [pbx_config]
 's-NOANSWER' =>   1. Voicemail(u${ARG1})                        [pbx_config]
                   2. Goto(default|s|1)                          [pbx_config]
 '_s-.' =>         1. Goto(s-NOANSWER|1)                         [pbx_config]

 'SIP/270.testpbx' => 1. Dial(SIP/270.testpbx|30|)               [res_features]

[ Context 'parkedcalls' created by 'res_features' ]
 '700' =>          1. Park()                                     [res_features]

-= 59 extensions (268 priorities) in 15 contexts. =-
The 'show dialplan' command is deprecated and will be removed in a future release. Please use 'dialplan show' instead.
[Jul 20 11:37:37] NOTICE[22735]: utils.c:938 ast_carefulwrite: Timed out trying to write
By: Adam Azad (adam_pchl) 2009-07-20 10:52:44

Asterisk 1.4.25.1 and upgraded from a much older version (1.4.2 something) - Didn't have this issue until upgrading to 1.4.25.1
By: David Vossel (dvossel) 2009-07-20 17:35:30

I really don't think this issue has anything to do with MixMonitor at all.  If someone can provide an AGI script that causes this error I'll look into it further.
By: Adam Azad (adam_pchl) 2009-07-20 17:41:16

#!/usr/bin/php -q
<?php

$debug="1";

ob_implicit_flush(true);
set_time_limit(6);
$in = fopen("php://stdin","r");
$stdlog = fopen("/var/log/asterisk/agi.log", "w");

function read() {
  global $in, $debug, $stdlog;
  $input = str_replace("\n", "", fgets($in, 4096));
  if ($debug) fputs($stdlog, "read: $input\n");
  return $input;
}

       $database = "";
       $username = "";
       $password = "";

       mysql_connect("",$username,$password);
       mysql_select_db($database) or die( "Unable to select database");

       //log all this good stuff into mysql

       if($argv[1] == 'start') {

               $sql = 'INSERT INTO `pending_calls` (`status`, `timein`, `queue`, `code`, `cid`, `details`,`unique_id`) VALUES(';
               $sql .= '"' .$argv[2]. '",';
               $sql .= '"' .$argv[3]. '",';
               $sql .= '"' .$argv[4]. '",';
               $sql .= '"' .$argv[5]. '",';
               $sql .= '"' .$argv[6]. '",';
$sql .= '"' .$argv[7]. '",';
               $sql .= '"' .$argv[8]. '"';
               $sql .= ')';

echo "VERBOSE \"SQL: ".$sql." \" ";

       mysql_query($sql) or die(mysql_error()); }


       if($argv[1] == 'end') {

            $sql = "UPDATE pending_calls SET status = '0' WHERE unique_id = ".$argv[3]."";

       echo "VERBOSE \"SQL: ".$sql." \" ";

       mysql_query($sql) or die(mysql_error()); }


       if($argv[1] == 'out') {

               $sql = 'INSERT INTO `pending_calls` (`status`, `queue`, `code`, `cid`, `details`,`unique_id`,`pickuptime`) VALUES(';
               $sql .= '"4",';
               $sql .= '"Outbound",';
               $sql .= '"' .$argv[7]. '",';
               $sql .= '"' .$argv[4]. '",';
               $sql .= '"' .$argv[2]. '",';
               $sql .= '"' .$argv[3]. '",';
               $sql .= '"' .$argv[5]. '"';
               $sql .= ')';

       echo "VERBOSE \"SQL: ".$sql." \" ";

       mysql_query($sql) or die(mysql_error()); }


       mysql_close();


// toggle debugging output (more verbose)  $debug = true;


function write($line) {
  global $debug, $stdlog;
  if ($debug) fputs($stdlog, "write: $line\n");
  echo $line."\n";
}


function errlog($line) {
  global $err;
  echo "VERBOSE \"$line\"\n";
}


echo "VERBOSE \"Ive logged all this good stuff into mysql\" ";


?>
By: David Vossel (dvossel) 2009-07-24 13:19:18

thank you for the information.  I have become very busy and will not have time to look into this any further for awhile.  I'm un-assigning myself the issue to give someone else the chance to take a look at it.  If the issue is still around once I am free, I'll investigate it further.
By: David Vossel (dvossel) 2009-07-24 13:20:59

also, please upload code and debug files rather than placing them into the comment block.


By: Alan Graham (zerohalo) 2009-08-25 12:14:06

I find that this seems to be caused when AGI scripts clobber stdin. If you read() stdin and close() all handles at the end of execution, the problem disappears.
By: Leif Madsen (lmadsen) 2009-09-17 14:51:15

I am closing this issue for now because the ERROR messages I'm seeing was fixed in a version somewhere just prior to 1.4.26, or just after 1.4.26 was released.

If you still experience this error after testing the latest 1.4 release candidate (1.4.27-rc1 currently), then please open a new issue with the appropriate information in order to reproduce the issue.

Thanks!