Nov 21 12:35:59 NOTICE[12760] chan_iax2.c: Restricting registration for peer '270' to 60 seconds (requested 300)
Nov 21 12:36:10 VERBOSE[12749] logger.c: == V4BRI-3#02: Incoming call '0249505609' -> '30203050'
Nov 21 12:36:10 VERBOSE[12749] logger.c: -- V4BRI-3#02: Updated channel name: CAPI/V4BRI-3/30203050-3a
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Executing Set("CAPI/V4BRI-3/30203050-3a", "FROM_DID=30203050") in new stack
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Executing Set("CAPI/V4BRI-3/30203050-3a", "FAX_RX=270") in new stack
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Executing Set("CAPI/V4BRI-3/30203050-3a", "FAX_RX_EMAIL=mark@mbit.com.au") in new stack
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Executing Answer("CAPI/V4BRI-3/30203050-3a", "") in new stack
Nov 21 12:36:10 VERBOSE[14211] logger.c: == V4BRI-3#02: Answering for 30203050
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Executing PlayTones("CAPI/V4BRI-3/30203050-3a", "ring") in new stack
Nov 21 12:36:10 DEBUG[14211] channel.c: Scheduling timer at 160 sample intervals
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Executing NVFaxDetect("CAPI/V4BRI-3/30203050-3a", "4") in new stack
Nov 21 12:36:10 DEBUG[14211] app_nv_faxdetect.c: Preparing detect of fax (waitdur=4ms, sildur=1000ms, mindur=100ms, maxdur=-1ms)
Nov 21 12:36:10 VERBOSE[12749] logger.c: == V4BRI-3#02: Setting up echo canceller (PLCI=0x403, function=1, options=4, tail=0)
Nov 21 12:36:10 VERBOSE[12749] logger.c: == V4BRI-3#02: Setting up DTMF detector (PLCI=0x403, flag=1)
Nov 21 12:36:10 VERBOSE[12749] logger.c: -- V4BRI-3#02: Echo canceller successfully set up (PLCI=0x403)
Nov 21 12:36:10 DEBUG[14211] channel.c: Generator got voice, switching to phase locked mode
Nov 21 12:36:10 DEBUG[14211] channel.c: Scheduling timer at 0 sample intervals
Nov 21 12:36:10 DEBUG[14211] app_nv_faxdetect.c: Start of voice token!
Nov 21 12:36:10 DEBUG[14211] app_nv_faxdetect.c: Fax detected on CAPI/V4BRI-3/30203050-3a
Nov 21 12:36:10 NOTICE[14211] app_nv_faxdetect.c: Redirecting CAPI/V4BRI-3/30203050-3a to fax extension
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Executing Goto("CAPI/V4BRI-3/30203050-3a", "ext-fax|in_fax|1") in new stack
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Goto (ext-fax,in_fax,1)
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Executing StopPlayTones("CAPI/V4BRI-3/30203050-3a", "") in new stack
Nov 21 12:36:10 DEBUG[14211] channel.c: Scheduling timer at 0 sample intervals
Nov 21 12:36:10 DEBUG[14211] pbx.c: Expression result is '0'
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Executing GotoIf("CAPI/V4BRI-3/30203050-3a", "0?3:analog_fax|1") in new stack
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Goto (ext-fax,analog_fax,1)
Nov 21 12:36:10 DEBUG[14211] pbx.c: Expression result is '0'
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Executing GotoIf("CAPI/V4BRI-3/30203050-3a", "0?4:2") in new stack
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Goto (ext-fax,analog_fax,2)
Nov 21 12:36:10 DEBUG[14211] pbx.c: Function result is 'IAX2/270'
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Executing Set("CAPI/V4BRI-3/30203050-3a", "DIAL=IAX2/270") in new stack
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Executing Dial("CAPI/V4BRI-3/30203050-3a", "IAX2/270|20|d") in new stack
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- Called 270
Nov 21 12:36:10 NOTICE[14211] channel.c: Dropping incompatible voice frame on CAPI/V4BRI-3/30203050-3a of format slin since our native format has changed to alaw
Nov 21 12:36:10 VERBOSE[12760] logger.c: -- Call accepted by 127.0.0.1 (format alaw)
Nov 21 12:36:10 VERBOSE[12760] logger.c: -- Format for call is alaw
Nov 21 12:36:10 VERBOSE[14211] logger.c: -- IAX2/270-1 is ringing
Nov 21 12:36:10 DEBUG[14211] channel.c: Driver for channel 'CAPI/V4BRI-3/30203050-3a' does not support indication 3, emulating it
Nov 21 12:36:10 DEBUG[14211] channel.c: Scheduling timer at 160 sample intervals
Nov 21 12:36:10 DEBUG[14211] channel.c: Generator got voice, switching to phase locked mode
Nov 21 12:36:10 DEBUG[14211] channel.c: Scheduling timer at 0 sample intervals
Nov 21 12:36:17 VERBOSE[12749] logger.c: -- Fax tone detected, but no fax extension for CAPI/V4BRI-3/30203050-3a
Nov 21 12:36:21 DEBUG[12749] chan_capi.c: Fax already handled
Nov 21 12:36:22 DEBUG[12754] chan_sip.c: Stopping retransmission on '6192573f30eea8cc39a5a2c23826e945@192.168.14.6' of Request 102: Match Found
Nov 21 12:36:24 DEBUG[12749] chan_capi.c: Fax already handled
Nov 21 12:36:26 DEBUG[12760] chan_iax2.c: Peer lastms 8, historicms 8, maxms 2000
Nov 21 12:36:28 DEBUG[12749] chan_capi.c: Fax already handled
Nov 21 12:36:29 DEBUG[12754] chan_sip.c: Stopping retransmission on '44a8bb551f56244165bc0a7c78793b26@192.168.0.1' of Request 102: Match Found
Nov 21 12:36:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '19b563a5656b64063fa227ed213fc8c0@192.168.0.1' of Request 102: Match Found
Nov 21 12:36:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '4e9dc8a64f0fa9c925f54a0e166fd31a@192.168.0.1' of Request 102: Match Found
Nov 21 12:36:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '62f8fef316fbe20e2d201ce34acf73ca@192.168.0.1' of Request 102: Match Found
Nov 21 12:36:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '3b3ad67912098d2f675f40cc3436c99a@192.168.0.1' of Request 102: Match Found
Nov 21 12:36:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '243699c40ea3e7671d90b1e300a132e0@192.168.0.1' of Request 102: Match Found
Nov 21 12:36:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '25f1c97d66feca915174cdaf086cdd29@192.168.0.1' of Request 102: Match Found
Nov 21 12:36:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '5fe8d32559d7a2e51e6e36434e674540@192.168.0.1' of Request 102: Match Found
Nov 21 12:36:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '083285df7ef907b3330df6f744e766a7@192.168.0.1' of Request 102: Match Found
Nov 21 12:36:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '24d152373715de180032f08b2538fdb5@192.168.0.1' of Request 102: Match Found
Nov 21 12:36:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '249246a369605faf3179b7887f04a393@192.168.0.1' of Request 102: Match Found
Nov 21 12:36:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '0fef3a5f5943327e32e0d3500a419ed1@192.168.0.1' of Request 102: Match Found
Nov 21 12:36:31 VERBOSE[14211] logger.c: -- Nobody picked up in 20000 ms
Nov 21 12:36:31 DEBUG[14211] channel.c: Scheduling timer at 0 sample intervals
Nov 21 12:36:31 DEBUG[14211] chan_iax2.c: We're hanging up IAX2/270-1 now...
Nov 21 12:36:31 VERBOSE[14211] logger.c: -- Hungup 'IAX2/270-1'
Nov 21 12:36:31 DEBUG[14211] app_dial.c: Exiting with DIALSTATUS=NOANSWER.
Nov 21 12:36:31 VERBOSE[14211] logger.c: -- Executing Hangup("CAPI/V4BRI-3/30203050-3a", "") in new stack
Nov 21 12:36:31 VERBOSE[14211] logger.c: == Spawn extension (ext-fax, analog_fax, 4) exited non-zero on 'CAPI/V4BRI-3/30203050-3a'
Nov 21 12:36:31 DEBUG[14211] pbx.c: Function result is '0249505609'
Nov 21 12:36:31 DEBUG[14211] pbx.c: Function result is '0249505609'
Nov 21 12:36:31 DEBUG[14211] pbx.c: Function result is ''
Nov 21 12:36:31 WARNING[14211] func_uri.c: Syntax: URIENCODE(<data>) - missing argument!
Nov 21 12:36:31 DEBUG[14211] pbx.c: Function result is '(null)'
Nov 21 12:36:31 DEBUG[14211] pbx.c: Function result is '0249505609'
Nov 21 12:36:31 DEBUG[14211] pbx.c: Function result is '0249505609'
Nov 21 12:36:31 VERBOSE[14211] logger.c: -- Executing System("CAPI/V4BRI-3/30203050-3a", "/var/lib/asterisk/bin/fax-process.pl --to --from postmaster@qti.com.au --subject "Fax from 0249505609 " --attachment 0249505609.pdf --type application/pdf --file ") in new stack
Nov 21 12:36:31 VERBOSE[14211] logger.c: -- Executing Hangup("CAPI/V4BRI-3/30203050-3a", "") in new stack
Nov 21 12:36:31 VERBOSE[14211] logger.c: == Spawn extension (ext-fax, h, 2) exited non-zero on 'CAPI/V4BRI-3/30203050-3a'
Nov 21 12:36:31 DEBUG[14211] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Nov 21 12:36:31 DEBUG[14211] 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 ('2006-11-21 12:36:10','0249505609','0249505609','analog_fax','ext-fax', 'CAPI/V4BRI-3/30203050-3a','IAX2/270-1','Hangup','',21,21,'ANSWERED',3,'')
Nov 21 12:36:31 VERBOSE[14211] logger.c: == V4BRI-3#02: CAPI Hangingup for PLCI=0x403 in state 2
Nov 21 12:36:31 VERBOSE[12749] logger.c: > V4BRI-3#02: CAPI INFO 0x3490: Normal call clearing
Nov 21 12:36:54 NOTICE[12760] chan_iax2.c: Restricting registration for peer '270' to 60 seconds (requested 300)
Nov 21 12:37:22 DEBUG[12754] chan_sip.c: Stopping retransmission on '5844d4f155f4e1d950792f57505f4a22@192.168.14.6' of Request 102: Match Found
Nov 21 12:37:26 DEBUG[12760] chan_iax2.c: Peer lastms 9, historicms 9, maxms 2000
Nov 21 12:37:29 DEBUG[12754] chan_sip.c: Stopping retransmission on '79faae144fc2ae5a7c7ec6492a9ebc8f@192.168.0.1' of Request 102: Match Found
Nov 21 12:37:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '60bf16a55fb0335212ff2b6945ec0bf1@192.168.0.1' of Request 102: Match Found
Nov 21 12:37:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '1883407a019e27b97e2d072539e4dfb9@192.168.0.1' of Request 102: Match Found
Nov 21 12:37:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '078dfabe27f710f37aca34e539ad0956@192.168.0.1' of Request 102: Match Found
Nov 21 12:37:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '3225f6bb488b996b26adbff7324874d9@192.168.0.1' of Request 102: Match Found
Nov 21 12:37:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '27df76d611da3f6a7adbea7522869fe4@192.168.0.1' of Request 102: Match Found
Nov 21 12:37:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '4a7a3bf471d6b77065009ba149ed3297@192.168.0.1' of Request 102: Match Found
Nov 21 12:37:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '3fb292ed1b847e5924382b4f06edb6b2@192.168.0.1' of Request 102: Match Found
Nov 21 12:37:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '421cf54272f484092cc84f0c56f79718@192.168.0.1' of Request 102: Match Found
Nov 21 12:37:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '14134d7130d9c4fc3f5d92235d2f66c9@192.168.0.1' of Request 102: Match Found
Nov 21 12:37:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '63a844bf477d37f843dd74222a3dc6ec@192.168.0.1' of Request 102: Match Found
Nov 21 12:37:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '69c093ae13dabc271f60101a2abec5cb@192.168.0.1' of Request 102: Match Found
Nov 21 12:37:34 DEBUG[12762] manager.c: Manager received command 'Command'
Nov 21 12:37:34 DEBUG[12762] manager.c: Manager received command 'Command'
Nov 21 12:37:47 DEBUG[12754] chan_sip.c: Stopping retransmission on '22ea7a3049428bca5059b40937210f9b@192.168.0.1' of Request 102: Match Found
Nov 21 12:37:49 NOTICE[12760] chan_iax2.c: Restricting registration for peer '270' to 60 seconds (requested 300)
Nov 21 12:37:58 DEBUG[12754] chan_sip.c: Auto destroying call '3c26700a83d6-y40daz4vfemw@snom320-000413247C63'
Nov 21 12:38:23 DEBUG[12754] chan_sip.c: Stopping retransmission on '1eab6a670e9510971701f740210d05a3@192.168.14.6' of Request 102: Match Found
Nov 21 12:38:26 DEBUG[12760] chan_iax2.c: Peer lastms 9, historicms 9, maxms 2000
Nov 21 12:38:29 DEBUG[12754] chan_sip.c: Stopping retransmission on '2d216e945d38721914dd705c74797f92@192.168.0.1' of Request 102: Match Found
Nov 21 12:38:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '1918c849291948126b3fbe9575f1ce84@192.168.0.1' of Request 102: Match Found
Nov 21 12:38:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '32deb315458306290006d0144c64d969@192.168.0.1' of Request 102: Match Found
Nov 21 12:38:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '330428fd4e348ebb33df306d0b608990@192.168.0.1' of Request 102: Match Found
Nov 21 12:38:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '6014d0d310fc676a019690ee0db538cb@192.168.0.1' of Request 102: Match Found
Nov 21 12:38:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '33239a115c68b53d47cac5ab26215a22@192.168.0.1' of Request 102: Match Found
Nov 21 12:38:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '1481ddcb6361a1794654b2975a2188b2@192.168.0.1' of Request 102: Match Found
Nov 21 12:38:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '09929e6530e43cd03bde1ffa0e553b1c@192.168.0.1' of Request 102: Match Found
Nov 21 12:38:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '656173b5790040e8765fa1ca0799bed4@192.168.0.1' of Request 102: Match Found
Nov 21 12:38:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '6b6ba8a9334e26fd019fccad0d6ce924@192.168.0.1' of Request 102: Match Found
Nov 21 12:38:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '0b1c421849284e113e78e3e9798297ed@192.168.0.1' of Request 102: Match Found
Nov 21 12:38:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '3e79e76b6fba25110310dd531e3735f8@192.168.0.1' of Request 102: Match Found
Nov 21 12:38:44 NOTICE[12760] chan_iax2.c: Restricting registration for peer '270' to 60 seconds (requested 300)
Nov 21 12:39:23 DEBUG[12754] chan_sip.c: Stopping retransmission on '19e04567424156b255e226935f74c4f9@192.168.14.6' of Request 102: Match Found
Nov 21 12:39:26 DEBUG[12760] chan_iax2.c: Peer lastms 9, historicms 9, maxms 2000
Nov 21 12:39:29 DEBUG[12754] chan_sip.c: Stopping retransmission on '18a6795511a6ba3e08065c080fa01adc@192.168.0.1' of Request 102: Match Found
Nov 21 12:39:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '4f32275f02804e5c04201b09118d042e@192.168.0.1' of Request 102: Match Found
Nov 21 12:39:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '704afa093973481a77ec2c03716ec3f0@192.168.0.1' of Request 102: Match Found
Nov 21 12:39:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '780d6f9c67c794ad6ad87200090fa7f9@192.168.0.1' of Request 102: Match Found
Nov 21 12:39:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '0915d74846e98dc56263043816cc7f75@192.168.0.1' of Request 102: Match Found
Nov 21 12:39:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '79fa03b479302af55da272c96aee3ee1@192.168.0.1' of Request 102: Match Found
Nov 21 12:39:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '29a1d87e7175df524cd6c50e1b7b9f19@192.168.0.1' of Request 102: Match Found
Nov 21 12:39:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '3b84944c46eb88d35b83ef1651e7d443@192.168.0.1' of Request 102: Match Found
Nov 21 12:39:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '1f11c88157d7468d44730b4c5ff9b3ea@192.168.0.1' of Request 102: Match Found
Nov 21 12:39:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '3bbaa98163d294a158e53eab261d957b@192.168.0.1' of Request 102: Match Found
Nov 21 12:39:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '417f113a72e40cdd3e294de74bafe5a4@192.168.0.1' of Request 102: Match Found
Nov 21 12:39:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '2055337939234f6b53440c7b07ad34e0@192.168.0.1' of Request 102: Match Found
Nov 21 12:39:34 DEBUG[12762] manager.c: Manager received command 'Command'
Nov 21 12:39:34 DEBUG[12762] manager.c: Manager received command 'Command'
Nov 21 12:39:37 DEBUG[12754] chan_sip.c: Stopping retransmission on '3c26700a2710-zeu0k0abknbh@snom320-000413247A23' of Request 114: Match Found
Nov 21 12:39:37 DEBUG[12754] chan_sip.c: Stopping retransmission on '342af58a20ce1692112c973665519690@192.168.0.1' of Request 102: Match Found
Nov 21 12:39:39 NOTICE[12760] chan_iax2.c: Restricting registration for peer '270' to 60 seconds (requested 300)
Nov 21 12:39:42 DEBUG[12754] chan_sip.c: Auto destroying call '3c267009be6e-g59ybte950x6@snom320-000413247C66'
Nov 21 12:40:24 DEBUG[12754] chan_sip.c: Stopping retransmission on '5b5e9c881a60cc5f412aaada4d234146@192.168.14.6' of Request 102: Match Found
Nov 21 12:40:26 DEBUG[12760] chan_iax2.c: Peer lastms 9, historicms 9, maxms 2000
Nov 21 12:40:29 DEBUG[12754] chan_sip.c: Stopping retransmission on '049851f711c75a1a40315d26282ee863@192.168.0.1' of Request 102: Match Found
Nov 21 12:40:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '0ccb7de14a65bfc74a27d68d4277ff0d@192.168.0.1' of Request 102: Match Found
Nov 21 12:40:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '243513be162b3afb5b57e74a3ff23a6e@192.168.0.1' of Request 102: Match Found
Nov 21 12:40:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '4f772ed13f27391140d2a4eb5c7fce66@192.168.0.1' of Request 102: Match Found
Nov 21 12:40:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '46bdd75a4f6694a27de6c700565e897c@192.168.0.1' of Request 102: Match Found
Nov 21 12:40:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '080f868e51765849509402927d54b16c@192.168.0.1' of Request 102: Match Found
Nov 21 12:40:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '1bc41ea223fe01df740a74a476c1e8f1@192.168.0.1' of Request 102: Match Found
Nov 21 12:40:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '57bb44201b9942f527c6cf575ea6ed7e@192.168.0.1' of Request 102: Match Found
Nov 21 12:40:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '367cc383550354ca4b4e67df77006f8b@192.168.0.1' of Request 102: Match Found
Nov 21 12:40:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '2cad736c4e7c43cb270ff575033f4d79@192.168.0.1' of Request 102: Match Found
Nov 21 12:40:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '4a0d24c73468050b79aac4eb7559537d@192.168.0.1' of Request 102: Match Found
Nov 21 12:40:30 DEBUG[12754] chan_sip.c: Stopping retransmission on '34d8c59e7dffee676ad0d5193fbe8500@192.168.0.1' of Request 102: Match Found
Nov 21 12:40:34 NOTICE[12760] chan_iax2.c: Restricting registration for peer '270' to 60 seconds (requested 300)