Jul 30 22:51:31 DEBUG[25457] chan_sip.c: Allocating new SIP dialog for f569952c6f19ec44MzEyZjkxMjg1ZTA0OGUwOWJiNGFlZmVmMjM2Mjc5OTQ. - INVITE (With RTP) Jul 30 22:51:31 DEBUG[25457] chan_sip.c: Setting NAT on RTP to 0 Jul 30 22:51:32 DEBUG[25457] chan_sip.c: Stopping retransmission on 'f569952c6f19ec44MzEyZjkxMjg1ZTA0OGUwOWJiNGFlZmVmMjM2Mjc5OTQ.' of Response 1: Match Found Jul 30 22:51:32 DEBUG[25457] chan_sip.c: Setting NAT on RTP to 0 Jul 30 22:51:32 DEBUG[25457] chan_sip.c: Checking SIP call limits for device 251 Jul 30 22:51:32 DEBUG[25457] chan_sip.c: build_route: Contact hop: Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Macro' Jul 30 22:51:32 DEBUG[11226] pbx.c: Expression result is '1' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'GotoIf' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Macro' Jul 30 22:51:32 DEBUG[11226] pbx.c: Expression result is '0' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'GotoIf' Jul 30 22:51:32 DEBUG[11226] pbx.c: Not taking any branch Jul 30 22:51:32 DEBUG[11226] pbx.c: Expression result is '0' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'GotoIf' Jul 30 22:51:32 DEBUG[11226] pbx.c: Not taking any branch Jul 30 22:51:32 DEBUG[11226] pbx.c: Function result is '251' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Set' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'NoOp' Jul 30 22:51:32 DEBUG[11226] pbx.c: Function result is '251' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Set' Jul 30 22:51:32 DEBUG[11226] pbx.c: Function result is 'Laptop' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Set' Jul 30 22:51:32 DEBUG[11226] pbx.c: Expression result is '0' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'GotoIf' Jul 30 22:51:32 DEBUG[11226] pbx.c: Not taking any branch Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Set' Jul 30 22:51:32 DEBUG[11226] pbx.c: Function result is '"Laptop" <251>' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'NoOp' Jul 30 22:51:32 DEBUG[11226] pbx.c: Function result is '251' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Macro' Jul 30 22:51:32 DEBUG[11226] pbx.c: Function result is '0' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'GotoIf' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'AGI' Jul 30 22:51:32 DEBUG[11227] app_queue.c: Device 'SIP/251' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 30 22:51:32 VERBOSE[11226] logger.c: recordingcheck|20060730-225132|1154292692.34: Outbound recording not enabled Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'NoOp' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Macro' Jul 30 22:51:32 DEBUG[11226] pbx.c: Expression result is '1' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'GotoIf' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'NoOp' Jul 30 22:51:32 DEBUG[11226] pbx.c: Function result is '' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Set' Jul 30 22:51:32 DEBUG[11226] db.c: Unable to find key '251/emergency_cid' in family 'DEVICE' Jul 30 22:51:32 DEBUG[11226] func_db.c: DB: DEVICE/251/emergency_cid not found in database. Jul 30 22:51:32 DEBUG[11226] pbx.c: Function result is '' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Set' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Set' Jul 30 22:51:32 DEBUG[11226] pbx.c: Expression result is '1' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'GotoIf' Jul 30 22:51:32 DEBUG[11226] pbx.c: Expression result is '0' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'GotoIf' Jul 30 22:51:32 DEBUG[11226] pbx.c: Not taking any branch Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Set' Jul 30 22:51:32 DEBUG[11226] pbx.c: Expression result is '1' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'GotoIf' Jul 30 22:51:32 DEBUG[11226] pbx.c: Function result is '"" <788870>' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'NoOp' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Set' Jul 30 22:51:32 DEBUG[11226] pbx.c: Function result is '1' Jul 30 22:51:32 WARNING[11226] ast_expr2.fl: ast_yyerror(): syntax error: syntax error, unexpected $end, expecting TOK_MINUS or TOK_COMPL or TOK_LP or TOKEN; Input: 1 > ^ Jul 30 22:51:32 WARNING[11226] ast_expr2.fl: If you have questions, please refer to doc/README.variables in the asterisk source. Jul 30 22:51:32 DEBUG[11226] pbx.c: Expression result is '0' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'GotoIf' Jul 30 22:51:32 DEBUG[11226] pbx.c: Not taking any branch Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Set' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Set' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'AGI' Jul 30 22:51:32 VERBOSE[11226] logger.c: fixlocalprefix: Could not parse /etc/asterisk/localprefixes.conf Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Set' Jul 30 22:51:32 DEBUG[11226] pbx.c: Function result is 'IAX2/788870' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Set' Jul 30 22:51:32 DEBUG[11226] pbx.c: Expression result is '0' Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'GotoIf' Jul 30 22:51:32 DEBUG[11226] pbx.c: Not taking any branch Jul 30 22:51:32 DEBUG[11226] pbx.c: Launching 'Dial' Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-dialout-trunk-s-14. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable MACRO_DEPTH. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-dialout-trunk-s-13. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable custom. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-dialout-trunk-s-12. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable OUTNUM. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-dialout-trunk-s-11. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-dialout-trunk-s-10. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable DIAL_TRUNK. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-dialout-trunk-s-9. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable DIAL_NUMBER. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-dialout-trunk-s-8. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-dialout-trunk-s-7. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable GROUP. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-dialout-trunk-s-6. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable MACRO_PRIORITY. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable MACRO_CONTEXT. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable MACRO_EXTEN. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable ARG1. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-outbound-callerid-s-15. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-outbound-callerid-s-13. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-outbound-callerid-s-12. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-outbound-callerid-s-11. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-outbound-callerid-s-7. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable TRUNKOUTCID. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-outbound-callerid-s-6. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable EMERGENCYCID. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-outbound-callerid-s-5. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable USEROUTCID. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-outbound-callerid-s-4. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable DB_RESULT. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-outbound-callerid-s-3. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-outbound-callerid-s-1. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-dialout-trunk-s-5. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable ARG2. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-record-enable-s-5. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-record-enable-s-4. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-record-enable-s-1. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-dialout-trunk-s-4. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-user-callerid-s-9. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-user-callerid-s-8. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-user-callerid-s-7. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable AMPUSERCIDNAME. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-user-callerid-s-6. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable AMPUSER. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-user-callerid-s-5. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-user-callerid-s-4. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable REALCALLERIDNUM. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-user-callerid-s-3. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-user-callerid-s-2. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-user-callerid-s-1. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-dialout-trunk-s-3. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-macro-dialout-trunk-s-1. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable ARG4. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable ARG3. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable STACK-from-internal-718003664667-1. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable SIPCALLID. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable SIPUSERAGENT. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable SIPDOMAIN. Jul 30 22:51:32 DEBUG[11226] channel.c: Not copying variable SIPURI. Jul 30 22:51:32 DEBUG[11230] app_queue.c: Device 'IAX2/788870' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Jul 30 22:51:33 WARNING[25460] chan_iax2.c: Call rejected by 192.246.69.186: No such context/extension Jul 30 22:51:33 DEBUG[25460] chan_iax2.c: Immediately destroying 2, having received reject Jul 30 22:51:33 DEBUG[11226] channel.c: Hanging up channel 'IAX2/788870-2' Jul 30 22:51:33 DEBUG[11226] chan_iax2.c: We're hanging up IAX2/788870-2 now... Jul 30 22:51:33 DEBUG[11226] chan_iax2.c: Really destroying IAX2/788870-2 now... Jul 30 22:51:33 DEBUG[11226] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL. Jul 30 22:51:33 DEBUG[11226] pbx.c: Launching 'Goto' Jul 30 22:51:33 DEBUG[11226] pbx.c: Launching 'NoOp' Jul 30 22:51:33 DEBUG[11226] pbx.c: Launching 'Macro' Jul 30 22:51:33 DEBUG[11226] pbx.c: Launching 'Playback' Jul 30 22:51:33 DEBUG[11226] chan_sip.c: sip_answer(SIP/251-90ec) Jul 30 22:51:33 DEBUG[11226] channel.c: Set channel SIP/251-90ec to write format gsm Jul 30 22:51:33 DEBUG[11226] rtp.c: Ooh, format changed from unknown to ulaw Jul 30 22:51:33 DEBUG[11226] channel.c: Scheduling timer at 160 sample intervals Jul 30 22:51:33 DEBUG[11231] app_queue.c: Device 'IAX2/788870' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jul 30 22:51:33 DEBUG[11232] app_queue.c: Device 'SIP/251' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 30 22:51:33 DEBUG[11226] rtp.c: Got RTCP report of 156 bytes Jul 30 22:51:34 DEBUG[25457] chan_sip.c: Stopping retransmission on 'f569952c6f19ec44MzEyZjkxMjg1ZTA0OGUwOWJiNGFlZmVmMjM2Mjc5OTQ.' of Response 2: Match Found Jul 30 22:51:34 DEBUG[11226] channel.c: Scheduling timer at 0 sample intervals Jul 30 22:51:34 DEBUG[11226] channel.c: Scheduling timer at 0 sample intervals Jul 30 22:51:34 DEBUG[11226] channel.c: Set channel SIP/251-90ec to write format ulaw Jul 30 22:51:34 DEBUG[11226] pbx.c: Launching 'Playback' Jul 30 22:51:34 DEBUG[11226] channel.c: Set channel SIP/251-90ec to write format gsm Jul 30 22:51:34 DEBUG[11226] channel.c: Scheduling timer at 160 sample intervals Jul 30 22:51:37 DEBUG[11226] channel.c: Scheduling timer at 0 sample intervals Jul 30 22:51:37 DEBUG[11226] channel.c: Scheduling timer at 0 sample intervals Jul 30 22:51:37 DEBUG[11226] channel.c: Set channel SIP/251-90ec to write format ulaw Jul 30 22:51:37 DEBUG[11226] pbx.c: Launching 'Macro' Jul 30 22:51:37 DEBUG[11226] pbx.c: Launching 'ResetCDR' Jul 30 22:51:37 DEBUG[11226] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record. Jul 30 22:51:37 DEBUG[11226] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2006-07-30 22:51:32','788870','788870','718003664667','from-internal', 'SIP/251-90ec','IAX2/788870-2','ResetCDR','w',5,4,'ANSWERED',3,'','1154292692.34') Jul 30 22:51:37 DEBUG[11226] pbx.c: Launching 'NoCDR' Jul 30 22:51:37 WARNING[11226] cdr.c: CDR on channel 'SIP/251-90ec' not posted Jul 30 22:51:37 WARNING[11226] cdr.c: CDR on channel 'SIP/251-90ec' lacks end Jul 30 22:51:37 DEBUG[11226] pbx.c: Launching 'Wait' Jul 30 22:51:37 DEBUG[11226] rtp.c: Got RTCP report of 176 bytes Jul 30 22:51:38 DEBUG[25460] chan_iax2.c: Allocate call number Jul 30 22:51:38 DEBUG[25460] chan_iax2.c: Registration created on call 4 Jul 30 22:51:40 DEBUG[11226] rtp.c: Got RTCP report of 176 bytes Jul 30 22:51:42 DEBUG[11226] rtp.c: Got RTCP report of 160 bytes Jul 30 22:51:42 DEBUG[11226] pbx.c: Launching 'Hangup' Jul 30 22:51:42 DEBUG[11226] app_macro.c: Spawn extension (macro-hangupcall,s,4) exited non-zero on 'SIP/251-90ec' in macro 'hangupcall' Jul 30 22:51:42 DEBUG[11226] app_macro.c: Spawn extension (macro-hangupcall,s,4) exited non-zero on 'SIP/251-90ec' in macro 'outisbusy' Jul 30 22:51:42 DEBUG[11226] pbx.c: Spawn extension (macro-hangupcall,s,4) exited non-zero on 'SIP/251-90ec' Jul 30 22:51:42 DEBUG[11226] channel.c: Hanging up channel 'SIP/251-90ec' Jul 30 22:51:42 DEBUG[11226] chan_sip.c: Hangup call SIP/251-90ec, SIP callid f569952c6f19ec44MzEyZjkxMjg1ZTA0OGUwOWJiNGFlZmVmMjM2Mjc5OTQ.) Jul 30 22:51:42 DEBUG[11226] chan_sip.c: update_call_counter(251) - decrement call limit counter Jul 30 22:51:42 DEBUG[11233] app_queue.c: Device 'SIP/251' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jul 30 22:51:42 DEBUG[25457] chan_sip.c: Stopping retransmission on 'f569952c6f19ec44MzEyZjkxMjg1ZTA0OGUwOWJiNGFlZmVmMjM2Mjc5OTQ.' of Request 102: Match Found Jul 30 22:51:44 DEBUG[25460] chan_iax2.c: Peer lastms 347, historicms 347, maxms 2000 [root@asterisk1 ~]#