Jul 27 22:00:15 DEBUG[2673] chan_sip.c: Allocating new SIP dialog for 8822155f422b2a5eZWU0MjM0NDA5MzMyYWUxMTM0ZjhlNzllZjczM2VhZWU. - INVITE (With RTP)
Jul 27 22:00:15 DEBUG[2673] chan_sip.c: Setting NAT on RTP to 0
Jul 27 22:00:15 DEBUG[2673] chan_sip.c: Stopping retransmission on '8822155f422b2a5eZWU0MjM0NDA5MzMyYWUxMTM0ZjhlNzllZjczM2VhZWU.' of Response 1: Match Found
Jul 27 22:00:15 DEBUG[2673] chan_sip.c: Setting NAT on RTP to 0
Jul 27 22:00:15 DEBUG[2673] chan_sip.c: Checking SIP call limits for device 250
Jul 27 22:00:15 DEBUG[2673] chan_sip.c: build_route: Contact hop: <sip:250@5.55.205.216:63158>
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Macro'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Expression result is '1'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'GotoIf'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Macro'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Expression result is '0'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'GotoIf'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Not taking any branch
Jul 27 22:00:15 DEBUG[6699] pbx.c: Expression result is '0'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'GotoIf'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Not taking any branch
Jul 27 22:00:15 DEBUG[6699] pbx.c: Function result is '250'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Set'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'NoOp'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Function result is '250'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Set'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Function result is 'David'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Set'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Expression result is '0'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'GotoIf'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Not taking any branch
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Set'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Function result is '"David" <250>'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'NoOp'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Function result is '250'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Macro'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Function result is '0'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'GotoIf'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'AGI'
Jul 27 22:00:15 DEBUG[6700] app_queue.c: Device 'SIP/250' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Jul 27 22:00:15 VERBOSE[6699] logger.c:   recordingcheck|20060727-220015|1154030415.43: Outbound recording enabled.
Jul 27 22:00:15 VERBOSE[6699] logger.c:   recordingcheck|20060727-220015|1154030415.43: CALLFILENAME=OUT250-20060727-220015-1154030415.43
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Monitor'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Macro'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Expression result is '1'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'GotoIf'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'NoOp'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Function result is ''
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Set'
Jul 27 22:00:15 DEBUG[6699] db.c: Unable to find key '250/emergency_cid' in family 'DEVICE'
Jul 27 22:00:15 DEBUG[6699] func_db.c: DB: DEVICE/250/emergency_cid not found in database.
Jul 27 22:00:15 DEBUG[6699] pbx.c: Function result is ''
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Set'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Set'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Expression result is '1'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'GotoIf'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Expression result is '1'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'GotoIf'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Expression result is '1'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'GotoIf'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Function result is '"David" <250>'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'NoOp'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Set'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Function result is '1'
Jul 27 22:00:15 WARNING[6699] 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 27 22:00:15 WARNING[6699] ast_expr2.fl: If you have questions, please refer to doc/README.variables in the asterisk source.
Jul 27 22:00:15 DEBUG[6699] pbx.c: Expression result is '0'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'GotoIf'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Not taking any branch
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Set'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Set'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'AGI'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Set'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Function result is 'SIP/fwd'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Set'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Expression result is '0'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'GotoIf'
Jul 27 22:00:15 DEBUG[6699] pbx.c: Not taking any branch
Jul 27 22:00:15 DEBUG[6699] pbx.c: Launching 'Dial'
Jul 27 22:00:15 DEBUG[6699] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
Jul 27 22:00:15 DEBUG[6699] chan_sip.c: Setting NAT on RTP to 0
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-dialout-trunk-s-14.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable MACRO_DEPTH.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-dialout-trunk-s-13.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable custom.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-dialout-trunk-s-12.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable OUTNUM.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-dialout-trunk-s-11.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-dialout-trunk-s-10.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable DIAL_TRUNK.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-dialout-trunk-s-9.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable DIAL_NUMBER.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-dialout-trunk-s-8.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-dialout-trunk-s-7.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable GROUP.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-dialout-trunk-s-6.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable MACRO_PRIORITY.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable MACRO_CONTEXT.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable MACRO_EXTEN.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable ARG1.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-outbound-callerid-s-15.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-outbound-callerid-s-13.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-outbound-callerid-s-11.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-outbound-callerid-s-7.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable TRUNKOUTCID.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-outbound-callerid-s-6.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable EMERGENCYCID.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-outbound-callerid-s-5.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable USEROUTCID.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-outbound-callerid-s-4.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable DB_RESULT.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-outbound-callerid-s-3.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-outbound-callerid-s-1.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-dialout-trunk-s-5.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable ARG2.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable AUTO_MONITOR.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-record-enable-s-999.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable CALLFILENAME.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-record-enable-s-4.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-record-enable-s-1.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-dialout-trunk-s-4.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-user-callerid-s-9.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-user-callerid-s-8.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-user-callerid-s-7.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable AMPUSERCIDNAME.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-user-callerid-s-6.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable AMPUSER.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-user-callerid-s-5.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-user-callerid-s-4.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable REALCALLERIDNUM.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-user-callerid-s-3.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-user-callerid-s-2.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-user-callerid-s-1.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-dialout-trunk-s-3.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-macro-dialout-trunk-s-1.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable ARG4.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable ARG3.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable STACK-from-internal-818003664667-1.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable SIPCALLID.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable SIPUSERAGENT.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable SIPDOMAIN.
Jul 27 22:00:15 DEBUG[6699] channel.c: Not copying variable SIPURI.
Jul 27 22:00:15 DEBUG[6699] chan_sip.c: Outgoing Call for 818003664667
Jul 27 22:00:15 DEBUG[2673] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1bd0138127d842574db2bf301641becb@192.168.1.16' Request 102: Found
Jul 27 22:00:16 DEBUG[2673] chan_sip.c: Acked pending invite 102
Jul 27 22:00:16 DEBUG[2673] chan_sip.c: Stopping retransmission on '1bd0138127d842574db2bf301641becb@192.168.1.16' of Request 102: Match Found
Jul 27 22:00:16 DEBUG[6699] channel.c: Hanging up channel 'SIP/fwd-aa11'
Jul 27 22:00:16 DEBUG[6699] chan_sip.c: Hangup call SIP/fwd-aa11, SIP callid 1bd0138127d842574db2bf301641becb@192.168.1.16)
Jul 27 22:00:16 DEBUG[6699] chan_sip.c: update_call_counter(818003664667) - decrement call limit counter
Jul 27 22:00:16 DEBUG[6699] app_dial.c: Exiting with DIALSTATUS=CONGESTION.
Jul 27 22:00:16 DEBUG[6699] pbx.c: Launching 'Goto'
Jul 27 22:00:16 DEBUG[6699] pbx.c: Launching 'NoOp'
Jul 27 22:00:16 DEBUG[6699] pbx.c: Launching 'Macro'
Jul 27 22:00:16 DEBUG[6699] pbx.c: Launching 'Playback'
Jul 27 22:00:16 DEBUG[6699] chan_sip.c: sip_answer(SIP/250-7f75)
Jul 27 22:00:16 DEBUG[6699] channel.c: Set channel SIP/250-7f75 to write format gsm
Jul 27 22:00:16 DEBUG[6699] rtp.c: Ooh, format changed from unknown to ulaw
Jul 27 22:00:16 DEBUG[6699] channel.c: Scheduling timer at 160 sample intervals
Jul 27 22:00:16 DEBUG[6703] app_queue.c: Device 'SIP/fwd' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
Jul 27 22:00:16 DEBUG[6704] app_queue.c: Device 'SIP/250' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Jul 27 22:00:16 DEBUG[6699] rtp.c: Got RTCP report of 132 bytes
Jul 27 22:00:16 DEBUG[2673] chan_sip.c: Stopping retransmission on '8822155f422b2a5eZWU0MjM0NDA5MzMyYWUxMTM0ZjhlNzllZjczM2VhZWU.' of Response 2: Match Found
Jul 27 22:00:17 DEBUG[6699] channel.c: Scheduling timer at 0 sample intervals
Jul 27 22:00:17 DEBUG[6699] channel.c: Scheduling timer at 0 sample intervals
Jul 27 22:00:17 DEBUG[6699] channel.c: Set channel SIP/250-7f75 to write format ulaw
Jul 27 22:00:17 DEBUG[6699] pbx.c: Launching 'Playback'
Jul 27 22:00:17 DEBUG[6699] channel.c: Set channel SIP/250-7f75 to write format gsm
Jul 27 22:00:17 DEBUG[6699] channel.c: Scheduling timer at 160 sample intervals
Jul 27 22:00:19 DEBUG[6699] rtp.c: Got RTCP report of 176 bytes
Jul 27 22:00:19 DEBUG[6699] channel.c: Scheduling timer at 0 sample intervals
Jul 27 22:00:19 DEBUG[6699] channel.c: Scheduling timer at 0 sample intervals
Jul 27 22:00:19 DEBUG[6699] channel.c: Set channel SIP/250-7f75 to write format ulaw
Jul 27 22:00:19 DEBUG[6699] pbx.c: Launching 'Macro'
Jul 27 22:00:19 DEBUG[6699] pbx.c: Launching 'ResetCDR'
Jul 27 22:00:19 DEBUG[6699] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Jul 27 22:00:19 DEBUG[6699] 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-27 22:00:15','\"David\" <250>','250','818003664667','from-internal', 'SIP/250-7f75','SIP/fwd-aa11','ResetCDR','w',4,3,'ANSWERED',3,'','1154030415.43')
Jul 27 22:00:19 DEBUG[6699] pbx.c: Launching 'NoCDR'
Jul 27 22:00:19 WARNING[6699] cdr.c: CDR on channel 'SIP/250-7f75' not posted
Jul 27 22:00:19 WARNING[6699] cdr.c: CDR on channel 'SIP/250-7f75' lacks end
Jul 27 22:00:19 DEBUG[6699] pbx.c: Launching 'Wait'
Jul 27 22:00:21 DEBUG[6699] rtp.c: Got RTCP report of 160 bytes
Jul 27 22:00:21 DEBUG[6699] app_macro.c: Spawn extension (macro-hangupcall,s,3) exited non-zero on 'SIP/250-7f75' in macro 'hangupcall'
Jul 27 22:00:21 DEBUG[6699] app_macro.c: Spawn extension (macro-hangupcall,s,3) exited non-zero on 'SIP/250-7f75' in macro 'outisbusy'
Jul 27 22:00:21 DEBUG[6699] pbx.c: Spawn extension (macro-hangupcall,s,3) exited non-zero on 'SIP/250-7f75'
Jul 27 22:00:21 DEBUG[6699] channel.c: Hanging up channel 'SIP/250-7f75'
Jul 27 22:00:21 DEBUG[6699] chan_sip.c: Hangup call SIP/250-7f75, SIP callid 8822155f422b2a5eZWU0MjM0NDA5MzMyYWUxMTM0ZjhlNzllZjczM2VhZWU.)
Jul 27 22:00:21 DEBUG[6699] chan_sip.c: update_call_counter(250) - decrement call limit counter
Jul 27 22:00:21 DEBUG[6705] app_queue.c: Device 'SIP/250' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.