| Subject: | LF in verbose() breaks AGI communication |
I had a strange issue where AGI was behaving strangely. After some debugging, I found out that I had erroneously a line
feed (\n) add the end string used in a $AGI->verbose() call. Communication looked like this:
< GET FULL VARIABLE ${SIP_HEADER(X-doesnotmatter)}
Show quoted text
> 200 result=1 (some header value)
< VERBOSE "2012-05-11 10:50:16 [26202] (1336726216.8) some log message here
"
Show quoted text> 200 result=1
< ANSWER
Show quoted text> 510 Invalid or unknown command
< EXEC Playback "somesoundfile"
Show quoted text> 200 result=0
< GET FULL VARIABLE ${CHANNEL(peerip)}
Show quoted text> 200 result=0
> 200 result=1 (1.2.3.4)
Note the " in a new line after the VERBOSE. Asterisk obviously treats that as a new AGI command, leading to the "510
Invalid or unknown command" which Asterisk::AGI reads after sending ANSWER. So the results are now all shifted by one AGI
command.
The simple (and probably best) solution is to strip (or replace) LFs in strings sent to the AGI socket ($s =~ s/\n//g or
something). This also makes sure that no invalid command is sent.
Just reading all output from Asterisk after (or before) is not practical, as this is prone to race conditions and harder
to implement (non-blocking reads etc.).