May 23 23:02:09 DEBUG[28426] chan_sip.c: Stopping retransmission on '0c5659bf1502067067a98c423d0df4a8@192.168.0.10' of Request 102: Match Found
May 23 23:02:09 VERBOSE[28426] logger.c: -- Got SIP response 481 "Call Leg/Transaction Does Not Exist" back from 192.168.0.2
May 23 23:02:12 DEBUG[28426] chan_sip.c: Auto destroying call '863dd5924bd74edc9aa2333bb3ff5a59@192.168.0.2'
May 23 23:02:12 DEBUG[28426] chan_sip.c: Auto destroying call '47cb258cb66f4eb99205cb68f045a3c6@192.168.0.2'
May 23 23:02:14 DEBUG[28426] chan_sip.c: Setting NAT on RTP to 0
May 23 23:02:14 DEBUG[28426] chan_sip.c: Stopping retransmission on 'cfa6b9638eaf4320b5043590fc0534bb@192.168.0.2' of Response 1: Match Found
May 23 23:02:14 DEBUG[28426] chan_sip.c: Setting NAT on RTP to 0
May 23 23:02:14 DEBUG[28426] chan_sip.c: Checking SIP call limits for device 201
May 23 23:02:14 DEBUG[28426] chan_sip.c: build_route: Contact hop:
May 23 23:02:14 VERBOSE[30291] logger.c: -- Executing Answer("SIP/201-05e2", "") in new stack
May 23 23:02:14 VERBOSE[30291] logger.c: -- Executing Read("SIP/201-05e2", "ext_num|vm-extension") in new stack
May 23 23:02:14 DEBUG[30291] channel.c: Scheduling timer at 160 sample intervals
May 23 23:02:14 VERBOSE[30291] logger.c: -- Playing 'vm-extension' (language 'en')
May 23 23:02:14 DEBUG[28426] chan_sip.c: Stopping retransmission on 'cfa6b9638eaf4320b5043590fc0534bb@192.168.0.2' of Response 2: Match Found
May 23 23:02:15 DEBUG[30291] channel.c: Scheduling timer at 97 sample intervals
May 23 23:02:15 DEBUG[30291] channel.c: Scheduling timer at 0 sample intervals
May 23 23:02:15 DEBUG[30291] channel.c: Scheduling timer at 0 sample intervals
May 23 23:02:18 VERBOSE[30291] logger.c: -- User entered '401'
May 23 23:02:18 VERBOSE[30291] logger.c: -- Executing Wait("SIP/201-05e2", "1") in new stack
May 23 23:02:19 VERBOSE[30291] logger.c: -- Executing Read("SIP/201-05e2", "ext_pwd|vm-password") in new stack
May 23 23:02:19 DEBUG[30291] channel.c: Scheduling timer at 160 sample intervals
May 23 23:02:19 VERBOSE[30291] logger.c: -- Playing 'vm-password' (language 'en')
May 23 23:02:20 DEBUG[30291] channel.c: Scheduling timer at 63 sample intervals
May 23 23:02:20 DEBUG[30291] channel.c: Scheduling timer at 0 sample intervals
May 23 23:02:20 DEBUG[30291] channel.c: Scheduling timer at 0 sample intervals
May 23 23:02:22 VERBOSE[30291] logger.c: -- User entered nothing.
May 23 23:02:22 VERBOSE[30291] logger.c: -- Executing Wait("SIP/201-05e2", "1") in new stack
May 23 23:02:23 VERBOSE[30291] logger.c: -- Executing AGI("SIP/201-05e2", "chk_vm_pwd.agi|/etc/asterisk/voicemail.conf|401|") in new stack
May 23 23:02:23 VERBOSE[30291] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/chk_vm_pwd.agi
May 23 23:02:23 VERBOSE[30291] logger.c: -- AGI Script chk_vm_pwd.agi completed, returning 0
May 23 23:02:23 DEBUG[30291] pbx.c: Expression result is '0'
May 23 23:02:23 VERBOSE[30291] logger.c: -- Executing GotoIf("SIP/201-05e2", "0?20:30") in new stack
May 23 23:02:23 VERBOSE[30291] logger.c: -- Goto (from-internal,*122,30)
May 23 23:02:23 VERBOSE[30291] logger.c: -- Executing Playback("SIP/201-05e2", "invalid") in new stack
May 23 23:02:23 DEBUG[30291] channel.c: Scheduling timer at 160 sample intervals
May 23 23:02:23 VERBOSE[30291] logger.c: -- Playing 'invalid' (language 'en')
May 23 23:02:26 DEBUG[30291] channel.c: Scheduling timer at 0 sample intervals
May 23 23:02:26 VERBOSE[30291] logger.c: == Spawn extension (from-internal, *122, 30) exited non-zero on 'SIP/201-05e2'
May 23 23:02:26 VERBOSE[30291] logger.c: -- Executing Macro("SIP/201-05e2", "hangupcall") in new stack
May 23 23:02:26 VERBOSE[30291] logger.c: -- Executing ResetCDR("SIP/201-05e2", "w") in new stack
May 23 23:02:26 DEBUG[30291] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
May 23 23:02:26 DEBUG[30291] 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-05-23 23:02:14','\"Office Phone 1\" <201>','201','*122','from-internal', 'SIP/201-05e2','','ResetCDR','w',12,12,'ANSWERED',3,'','1148414534.46')
May 23 23:02:26 VERBOSE[30291] logger.c: -- Executing NoCDR("SIP/201-05e2", "") in new stack
May 23 23:02:26 WARNING[30291] cdr.c: CDR on channel 'SIP/201-05e2' not posted
May 23 23:02:26 WARNING[30291] cdr.c: CDR on channel 'SIP/201-05e2' lacks end
May 23 23:02:26 VERBOSE[30291] logger.c: -- Executing Wait("SIP/201-05e2", "5") in new stack
May 23 23:02:26 VERBOSE[30291] logger.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on 'SIP/201-05e2' in macro 'hangupcall'
May 23 23:02:26 VERBOSE[30291] logger.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on 'SIP/201-05e2'
May 23 23:02:26 DEBUG[30291] chan_sip.c: update_call_counter(201) - decrement call limit counter
May 23 23:02:26 VERBOSE[28426] logger.c: -- Unregistered SIP '201'
May 23 23:02:26 VERBOSE[28426] logger.c: -- Registered SIP '201' at 192.168.0.2 port 8385 expires 120
May 23 23:02:26 VERBOSE[28426] logger.c: -- Registered SIP '201' at 192.168.0.2 port 8385 expires 120