Mar 15 19:04:01 VERBOSE[13698] logger.c: -- Attempting call on Local/17575653371@from-internal for s@broadcast:1 (Retry 1) Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Macro("Local/17575653371@from-internal-64b5,2", "dialout-enum|11|17575653371||") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?PASSWD:NOPASSWD") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Goto (macro-dialout-enum,s,3) Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Macro("Local/17575653371@from-internal-64b5,2", "user-callerid|SKIPTTL") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Function result is 'DoctorsOffice' Mar 15 19:04:01 DEBUG[13700] pbx.c: Function result is '7575648182' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "user-callerid: DoctorsOffice 7575648182") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Expression result is '1' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "1?report") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Goto (macro-user-callerid,s,11) Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "TTL: ARG1: SKIPTTL") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Expression result is '1' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "1?continue") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Goto (macro-user-callerid,s,21) Mar 15 19:04:01 DEBUG[13700] pbx.c: Function result is '"DoctorsOffice" <7575648182>' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "Using CallerID "DoctorsOffice" <7575648182>") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Function result is '7575648182' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Macro("Local/17575653371@from-internal-64b5,2", "record-enable|7575648182|OUT") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Function result is '0' Mar 15 19:04:01 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?2:4") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Goto (macro-record-enable,s,4) Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing DeadAGI("Local/17575653371@from-internal-64b5,2", "recordingcheck|20070315-190401|1173999841.21153") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck Mar 15 19:04:01 DEBUG[13700] db.c: Unable to find key '7575648182/recording' in family 'AMPUSER' Mar 15 19:04:01 VERBOSE[13700] logger.c: recordingcheck|20070315-190401|1173999841.21153: No AMPUSER db entry for 7575648182. Not recording Mar 15 19:04:01 VERBOSE[13700] logger.c: -- AGI Script recordingcheck completed, returning 0 Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "No recording needed") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Macro("Local/17575653371@from-internal-64b5,2", "outbound-callerid|11") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?start") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Not taking any branch Mar 15 19:04:01 DEBUG[13700] pbx.c: Function result is '7575648182' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "REALCALLERIDNUM=7575648182") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "REALCALLERIDNUM is 7575648182") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Expression result is '1' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "1?normcid") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Goto (macro-outbound-callerid,s,9) Mar 15 19:04:01 DEBUG[13700] db.c: Unable to find key '7575648182/outboundcid' in family 'AMPUSER' Mar 15 19:04:01 DEBUG[13700] func_db.c: DB: AMPUSER/7575648182/outboundcid not found in database. Mar 15 19:04:01 DEBUG[13700] pbx.c: Function result is '' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "USEROUTCID=") in new stack Mar 15 19:04:01 DEBUG[13700] db.c: Unable to find key '7575648182/emergency_cid' in family 'DEVICE' Mar 15 19:04:01 DEBUG[13700] func_db.c: DB: DEVICE/7575648182/emergency_cid not found in database. Mar 15 19:04:01 DEBUG[13700] pbx.c: Function result is '' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "EMERGENCYCID=") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "TRUNKOUTCID=<17575648182>") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Expression result is '1' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "1?trunkcid") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Goto (macro-outbound-callerid,s,16) Mar 15 19:04:01 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?usercid") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Not taking any branch Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "CALLERID(all)=<17575648182>") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Expression result is '1' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "1?report") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Goto (macro-outbound-callerid,s,22) Mar 15 19:04:01 DEBUG[13700] pbx.c: Function result is '"" <17575648182>' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "CallerID set to "" <17575648182>") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "GROUP()=OUT_11") in new stack Mar 15 19:04:01 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:01 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:01 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:01 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:01 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:01 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:01 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:01 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:01 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:01 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:01 WARNING[13700] channel.c: Avoided deadlock for '0x9afb9a0', 10 retries! Mar 15 19:04:01 DEBUG[13700] pbx.c: Function result is '1' Mar 15 19:04:01 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?nochans") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Not taking any branch Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "DIAL_NUMBER=17575653371") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "DIAL_TRUNK=11") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing DeadAGI("Local/17575653371@from-internal-64b5,2", "fixlocalprefix") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix Mar 15 19:04:01 VERBOSE[13700] logger.c: > fixlocalprefix: Using pattern 011|. Mar 15 19:04:01 VERBOSE[13700] logger.c: -- AGI Script fixlocalprefix completed, returning 0 Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "E164NETWORKS=e164.arpa-e164.info-e164.org") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?begin") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Not taking any branch Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "DIAL_NUMBER=+17575653371") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "E164NETWORKS is e164.arpa-e164.info-e164.org") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?failedtotally") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Not taking any branch Mar 15 19:04:01 DEBUG[13700] pbx.c: Function result is 'e164.arpa' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "ENUMNET=e164.arpa") in new stack Mar 15 19:04:01 DEBUG[13700] pbx.c: Function result is 'e164.info-e164.org' Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "E164NETWORKS=e164.info-e164.org") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "E164NETWORKS is now e164.info-e164.org") in new stack Mar 15 19:04:01 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "ENUMNET is e164.arpa") in new stack Mar 15 19:04:02 DEBUG[13700] enum.c: No such number found: 1.7.3.3.5.6.5.7.5.7.1.e164.arpa (Success) Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is '' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "ENUMCOUNT=") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "ENUMPTR=0") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "LOOKUPBUG=0") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?continue:failed") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-dialout-enum,s,47) Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "EnumLookup failed on network e164.arpa") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Goto("Local/17575653371@from-internal-64b5,2", "begin") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-dialout-enum,s,14) Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "E164NETWORKS is e164.info-e164.org") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?failedtotally") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Not taking any branch Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is 'e164.info' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "ENUMNET=e164.info") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is 'e164.org' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "E164NETWORKS=e164.org") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "E164NETWORKS is now e164.org") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "ENUMNET is e164.info") in new stack Mar 15 19:04:02 DEBUG[13700] enum.c: No such number found: 1.7.3.3.5.6.5.7.5.7.1.e164.info (Success) Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is '' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "ENUMCOUNT=") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "ENUMPTR=0") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "LOOKUPBUG=0") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?continue:failed") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-dialout-enum,s,47) Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "EnumLookup failed on network e164.info") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Goto("Local/17575653371@from-internal-64b5,2", "begin") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-dialout-enum,s,14) Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "E164NETWORKS is e164.org") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?failedtotally") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Not taking any branch Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is 'e164.org' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "ENUMNET=e164.org") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is '' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "E164NETWORKS=") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "E164NETWORKS is now ") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "ENUMNET is e164.org") in new stack Mar 15 19:04:02 DEBUG[13700] enum.c: No such number found: 1.7.3.3.5.6.5.7.5.7.1.e164.org (Success) Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is '' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "ENUMCOUNT=") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "ENUMPTR=0") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "LOOKUPBUG=0") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?continue:failed") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-dialout-enum,s,47) Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "EnumLookup failed on network e164.org") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Goto("Local/17575653371@from-internal-64b5,2", "begin") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-dialout-enum,s,14) Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "E164NETWORKS is ") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '1' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "1?failedtotally") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-dialout-enum,s,49) Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "EnumLookup failed -- no more networks to try") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Goto("Local/17575653371@from-internal-64b5,2", "end") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-dialout-enum,s,52) Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "Exiting macro-dialout-enum") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Macro("Local/17575653371@from-internal-64b5,2", "dialout-trunk|8|17575653371||") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "DIAL_TRUNK=8") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "_NODEST=") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "DIAL_NUMBER=17575653371") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "ROUTE_PASSWD=") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "DIAL_TRUNK_OPTIONS=tTrwW") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '1' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "1?noauth") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-dialout-trunk,s,8) Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "GROUP()=OUT_8") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Macro("Local/17575653371@from-internal-64b5,2", "user-callerid|SKIPTTL") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is '' Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is '17575648182' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "user-callerid: 17575648182") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '1' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "1?report") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-user-callerid,s,11) Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "TTL: ARG1: SKIPTTL") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '1' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "1?continue") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-user-callerid,s,21) Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is '"" <17575648182>' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "Using CallerID "" <17575648182>") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is '17575648182' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Macro("Local/17575653371@from-internal-64b5,2", "record-enable|17575648182|OUT") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is '0' Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?2:4") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-record-enable,s,4) Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing DeadAGI("Local/17575653371@from-internal-64b5,2", "recordingcheck|20070315-190402|1173999841.21153") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck Mar 15 19:04:02 DEBUG[13700] db.c: Unable to find key '17575648182/recording' in family 'AMPUSER' Mar 15 19:04:02 VERBOSE[13700] logger.c: recordingcheck|20070315-190402|1173999841.21153: No AMPUSER db entry for 17575648182. Not recording Mar 15 19:04:02 VERBOSE[13700] logger.c: -- AGI Script recordingcheck completed, returning 0 Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "No recording needed") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?skipoutcid") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Not taking any branch Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "DIAL_TRUNK_OPTIONS=") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Macro("Local/17575653371@from-internal-64b5,2", "outbound-callerid|8") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '1' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "1?start") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-outbound-callerid,s,3) Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "REALCALLERIDNUM is 7575648182") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '1' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "1?normcid") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-outbound-callerid,s,9) Mar 15 19:04:02 DEBUG[13700] db.c: Unable to find key '7575648182/outboundcid' in family 'AMPUSER' Mar 15 19:04:02 DEBUG[13700] func_db.c: DB: AMPUSER/7575648182/outboundcid not found in database. Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is '' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "USEROUTCID=") in new stack Mar 15 19:04:02 DEBUG[13700] db.c: Unable to find key '7575648182/emergency_cid' in family 'DEVICE' Mar 15 19:04:02 DEBUG[13700] func_db.c: DB: DEVICE/7575648182/emergency_cid not found in database. Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is '' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "EMERGENCYCID=") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "TRUNKOUTCID=<7575648182>") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '1' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "1?trunkcid") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-outbound-callerid,s,16) Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?usercid") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Not taking any branch Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "CALLERID(all)=<7575648182>") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '1' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "1?report") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Goto (macro-outbound-callerid,s,22) Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is '"" <7575648182>' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,2", "CallerID set to "" <7575648182>") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?nomax") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Not taking any branch Mar 15 19:04:02 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:02 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:02 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:02 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:02 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:02 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:02 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:02 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:02 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:02 DEBUG[13700] channel.c: Avoiding deadlock for 'SIP/103-09a811d0' Mar 15 19:04:02 WARNING[13700] channel.c: Avoided deadlock for '0x9afb9a0', 10 retries! Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is '1' Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?chanfull") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Not taking any branch Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing DeadAGI("Local/17575653371@from-internal-64b5,2", "fixlocalprefix") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix Mar 15 19:04:02 VERBOSE[13700] logger.c: > fixlocalprefix: Using pattern 1757+NXXXXXX Mar 15 19:04:02 VERBOSE[13700] logger.c: -- AGI Script fixlocalprefix completed, returning 0 Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "OUTNUM=17575653371") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Function result is 'IAX2/talklite' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,2", "custom=IAX2/talklite|g") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: == Setting global variable 'custom' to 'IAX2/talklite' Mar 15 19:04:02 DEBUG[13700] pbx.c: Expression result is '0' Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "0?customtrunk") in new stack Mar 15 19:04:02 DEBUG[13700] pbx.c: Not taking any branch Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Executing Dial("Local/17575653371@from-internal-64b5,2", "IAX2/talklite/17575653371|300|") in new stack Mar 15 19:04:02 VERBOSE[13700] logger.c: -- Called talklite/17575653371 Mar 15 19:04:03 VERBOSE[2531] logger.c: -- Call accepted by 208.101.3.2 (format gsm) Mar 15 19:04:03 VERBOSE[2531] logger.c: -- Format for call is gsm Mar 15 19:04:05 VERBOSE[13700] logger.c: -- IAX2/talklite-4 is making progress passing it to Local/17575653371@from-internal-64b5,2 Mar 15 19:04:05 DEBUG[2531] chan_iax2.c: Ooh, voice format changed to 2 Mar 15 19:04:05 DEBUG[2530] chan_sip.c: Stopping retransmission on '086d18f20870a43a0ca722101b94cb7b@192.168.0.14' of Request 102: Match Found Mar 15 19:04:12 DEBUG[2530] chan_sip.c: Stopping retransmission on '2a480b620bcf88914947ba56582f0839@192.168.0.14' of Request 102: Match Found Mar 15 19:04:16 DEBUG[2531] chan_iax2.c: Peer lastms 54, historicms 54, maxms 2000 Mar 15 19:04:16 DEBUG[2530] chan_sip.c: Scheduled a registration timeout for did.voip.les.net id #500864 Mar 15 19:04:16 DEBUG[2530] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1a17076e20fb9bdc7c89e50b5ca87eb6@127.0.0.1' Request 456: Found Mar 15 19:04:16 DEBUG[2530] chan_sip.c: Stopping retransmission on '1a17076e20fb9bdc7c89e50b5ca87eb6@127.0.0.1' of Request 456: Match Found Mar 15 19:04:16 DEBUG[2530] chan_sip.c: Registration successful Mar 15 19:04:16 DEBUG[2530] chan_sip.c: Cancelling timeout 500864 Mar 15 19:04:18 DEBUG[2530] chan_sip.c: Auto destroying call '6cf7a91e5fc2b97c1add27191a8cb531@127.0.0.1' Mar 15 19:04:18 DEBUG[2530] chan_sip.c: Stopping retransmission on '7d9dc2007f4d72713e05fc6e6671b881@192.168.0.14' of Request 102: Match Found Mar 15 19:04:23 DEBUG[2530] chan_sip.c: Auto destroying call '61271ca60920b8bf680bb2275ea8effe@127.0.0.1' Mar 15 19:04:24 DEBUG[2531] chan_iax2.c: Peer lastms 40, historicms 40, maxms 2000 Mar 15 19:04:26 DEBUG[2530] chan_sip.c: Auto destroying call '3c26700b4baf-sjxk8yvu8l2l@snom320-000413245283' Mar 15 19:04:38 VERBOSE[13700] logger.c: -- IAX2/talklite-4 answered Local/17575653371@from-internal-64b5,2 Mar 15 19:04:38 VERBOSE[13698] logger.c: > Channel Local/17575653371@from-internal-64b5,1 was answered. Mar 15 19:04:38 VERBOSE[13698] logger.c: -- Executing Answer("Local/17575653371@from-internal-64b5,1", "") in new stack Mar 15 19:04:38 VERBOSE[13698] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,1", "Channel: IAX2/talklite ") in new stack Mar 15 19:04:38 DEBUG[13698] pbx.c: Function result is 'IAX2' Mar 15 19:04:38 VERBOSE[13698] logger.c: -- Executing Set("Local/17575653371@from-internal-64b5,1", "ChannelType=IAX2") in new stack Mar 15 19:04:38 VERBOSE[13698] logger.c: -- Executing NoOp("Local/17575653371@from-internal-64b5,1", "ChannelType: IAX2") in new stack Mar 15 19:04:38 DEBUG[13698] pbx.c: Expression result is '0' Mar 15 19:04:38 VERBOSE[13698] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,1", "0?12:6") in new stack Mar 15 19:04:38 VERBOSE[13698] logger.c: -- Goto (broadcast,s,6) Mar 15 19:04:38 VERBOSE[13698] logger.c: -- Executing Wait("Local/17575653371@from-internal-64b5,1", "2") in new stack Mar 15 19:04:38 DEBUG[13700] channel.c: Planning to masquerade channel IAX2/talklite-4 into the structure of Local/17575653371@from-internal-64b5,1 Mar 15 19:04:38 DEBUG[13700] channel.c: Done planning to masquerade channel IAX2/talklite-4 into the structure of Local/17575653371@from-internal-64b5,1 Mar 15 19:04:38 DEBUG[13700] chan_local.c: Not posting to queue since already masked on 'Local/17575653371@from-internal-64b5,2' Mar 15 19:04:38 DEBUG[13698] channel.c: Got clone lock for masquerade on 'IAX2/talklite-4' at 0x9af7bd4 Mar 15 19:04:38 DEBUG[13698] channel.c: Putting channel IAX2/talklite-4 in 64/64 formats Mar 15 19:04:38 DEBUG[13698] channel.c: Released clone lock on 'Local/17575653371@from-internal-64b5,1' Mar 15 19:04:38 DEBUG[13698] channel.c: Done Masquerading IAX2/talklite-4 (6) Mar 15 19:04:38 DEBUG[13700] channel.c: Didn't get a frame from channel: Local/17575653371@from-internal-64b5,1 Mar 15 19:04:38 DEBUG[13700] channel.c: Bridge stops bridging channels Local/17575653371@from-internal-64b5,2 and Local/17575653371@from-internal-64b5,1 Mar 15 19:04:38 DEBUG[13700] app_dial.c: Exiting with DIALSTATUS=ANSWER. Mar 15 19:04:38 VERBOSE[13700] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'Local/17575653371@from-internal-64b5,2' in macro 'dialout-trunk' Mar 15 19:04:38 VERBOSE[13700] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'Local/17575653371@from-internal-64b5,2' Mar 15 19:04:38 VERBOSE[13700] logger.c: -- Executing Macro("Local/17575653371@from-internal-64b5,2", "hangupcall") in new stack Mar 15 19:04:38 VERBOSE[13700] logger.c: -- Executing ResetCDR("Local/17575653371@from-internal-64b5,2", "w") in new stack Mar 15 19:04:38 DEBUG[13700] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record. Mar 15 19:04:38 DEBUG[13700] 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) VALUES ('2007-03-15 19:04:01','7575648182','7575648182','17575653371','from-internal', 'Local/17575653371@from-internal-64b5,2','IAX2/talklite-4','ResetCDR','w',37,0,'ANSWERED',3,'') Mar 15 19:04:38 VERBOSE[13700] logger.c: -- Executing NoCDR("Local/17575653371@from-internal-64b5,2", "") in new stack Mar 15 19:04:38 NOTICE[13700] cdr.c: CDR on channel 'Local/17575653371@from-internal-64b5,2' not posted Mar 15 19:04:38 NOTICE[13700] cdr.c: CDR on channel 'Local/17575653371@from-internal-64b5,2' lacks end Mar 15 19:04:38 DEBUG[13700] pbx.c: Expression result is '1' Mar 15 19:04:38 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "1?skiprg") in new stack Mar 15 19:04:38 VERBOSE[13700] logger.c: -- Goto (macro-hangupcall,s,6) Mar 15 19:04:38 DEBUG[13700] pbx.c: Expression result is '1' Mar 15 19:04:38 VERBOSE[13700] logger.c: -- Executing GotoIf("Local/17575653371@from-internal-64b5,2", "1?theend") in new stack Mar 15 19:04:38 VERBOSE[13700] logger.c: -- Goto (macro-hangupcall,s,9) Mar 15 19:04:38 VERBOSE[13700] logger.c: -- Executing Wait("Local/17575653371@from-internal-64b5,2", "5") in new stack Mar 15 19:04:38 VERBOSE[13700] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'Local/17575653371@from-internal-64b5,2' in macro 'hangupcall' Mar 15 19:04:38 VERBOSE[13700] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'Local/17575653371@from-internal-64b5,2' Mar 15 19:04:40 DEBUG[13698] pbx.c: Function result is 'IAX2' Mar 15 19:04:40 VERBOSE[13698] logger.c: -- Executing MixMonitor("IAX2/talklite-4", "17575653371IAX2.wav|V(-2)") in new stack Mar 15 19:04:40 DEBUG[13698] channel.c: Spy MixMonitor added to channel IAX2/talklite-4 Mar 15 19:04:40 VERBOSE[13698] logger.c: -- Executing WaitForSilence("IAX2/talklite-4", "2000|1") in new stack Mar 15 19:04:40 VERBOSE[13698] logger.c: -- Waiting 1 time(s) for 2000 ms silence Mar 15 19:04:40 VERBOSE[13714] logger.c: == Begin MixMonitor Recording IAX2/talklite-4 Mar 15 19:04:40 DEBUG[13698] channel.c: Building translator from gsm to SLINEAR for spies on channel IAX2/talklite-4 Mar 15 19:04:44 DEBUG[13698] app_waitforsilence.c: WAITSTATUS was set to TIMEOUT Mar 15 19:04:44 DEBUG[13698] pbx.c: Expression result is '0'