Dec 21 18:32:05 VERBOSE[205] logger.c:     -- Attempting call on Zap/g1/1002 for 1024@txfax:1 (Retry 1)
Dec 21 18:32:05 DEBUG[205] chan_zap.c: Using channel 1
Dec 21 18:32:05 VERBOSE[205] logger.c:     -- Requested transfer capability: 0x00 - SPEECH
Dec 21 18:32:05 DEBUG[205] devicestate.c: Changing state for Zap/1 - state 2 (In use)
Dec 21 18:32:05 DEBUG[205] devicestate.c: Changing state for Zap/1 - state 2 (In use)
Dec 21 18:32:05 DEBUG[205] app_queue.c: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Dec 21 18:32:05 DEBUG[205] app_queue.c: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Dec 21 18:32:05 VERBOSE[205] logger.c:     -- Accepting call from '' to '1002' on channel 0/1, span 2
Dec 21 18:32:05 DEBUG[205] chan_zap.c: No echo cancellation requested
Dec 21 18:32:05 DEBUG[205] devicestate.c: Changing state for Zap/32 - state 2 (In use)
Dec 21 18:32:05 DEBUG[205] pbx.c: Launching 'Answer'
Dec 21 18:32:05 VERBOSE[205] logger.c:     -- Executing Answer("Zap/32-1", "") in new stack
Dec 21 18:32:05 DEBUG[205] pbx.c: Launching 'Wait'
Dec 21 18:32:05 VERBOSE[205] logger.c:     -- Executing Wait("Zap/32-1", "") in new stack
Dec 21 18:32:05 DEBUG[205] pbx.c: Launching 'Set'
Dec 21 18:32:05 VERBOSE[205] logger.c:     -- Executing Set("Zap/32-1", "FAXFILE=/tmp/FAX-1198233125.1.tiff") in new stack
Dec 21 18:32:05 DEBUG[205] pbx.c: Function result is '1002'
Dec 21 18:32:05 DEBUG[205] pbx.c: Launching 'Set'
Dec 21 18:32:05 VERBOSE[205] logger.c:     -- Executing Set("Zap/32-1", "NEWFAXFILE=/var/spool/asterisk/fax/FAX-1002--1198233125----1198233125.1.tiff") in new stack
Dec 21 18:32:05 DEBUG[205] pbx.c: Launching 'RxFAX'
Dec 21 18:32:05 VERBOSE[205] logger.c:     -- Executing RxFAX("Zap/32-1", "/tmp/FAX-1198233125.1.tiff|debug") in new stack
Dec 21 18:32:05 DEBUG[205] app_queue.c: Device 'Zap/32' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Dec 21 18:32:05 DEBUG[205] devicestate.c: Changing state for Zap/32 - state 2 (In use)
Dec 21 18:32:05 DEBUG[205] channel.c: Set channel Zap/32-1 to read format slin
Dec 21 18:32:05 DEBUG[205] channel.c: Set channel Zap/32-1 to write format slin
Dec 21 18:32:05 DEBUG[205] app_queue.c: Device 'Zap/32' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Dec 21 18:32:05 DEBUG[205] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 1
Dec 21 18:32:05 DEBUG[205] chan_zap.c: No echo cancellation requested
Dec 21 18:32:05 VERBOSE[205] logger.c:        > Channel Zap/1-1 was answered.
Dec 21 18:32:05 DEBUG[205] pbx.c: Launching 'Answer'
Dec 21 18:32:05 VERBOSE[205] logger.c:     -- Executing Answer("Zap/1-1", "") in new stack
Dec 21 18:32:05 DEBUG[205] pbx.c: Launching 'Set'
Dec 21 18:32:05 VERBOSE[205] logger.c:     -- Executing Set("Zap/1-1", "CDR(userfield)=FAX-1") in new stack
Dec 21 18:32:05 DEBUG[205] pbx.c: Launching 'TxFAX'
Dec 21 18:32:05 VERBOSE[205] logger.c:     -- Executing TxFAX("Zap/1-1", "/var/spool/asterisk/outgoing_fax/page.1.1.tiff|caller|debug") in new stack
Dec 21 18:32:05 DEBUG[205] channel.c: Set channel Zap/1-1 to read format slin
Dec 21 18:32:05 DEBUG[205] channel.c: Set channel Zap/1-1 to write format slin
Dec 21 18:32:05 DEBUG[205] devicestate.c: Changing state for Zap/1 - state 2 (In use)
Dec 21 18:32:05 DEBUG[205] app_queue.c: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Dec 21 18:32:06 DEBUG[205] chan_iax2.c: Allocate call number
Dec 21 18:32:06 DEBUG[205] chan_iax2.c: Registration created on call 1
Dec 21 18:32:07 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 0
Dec 21 18:32:07 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 4
Dec 21 18:32:07 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 4
Dec 21 18:32:07 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 0
Dec 21 18:32:09 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 4
Dec 21 18:32:09 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 0
Dec 21 18:32:09 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:32:09 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 4
Dec 21 18:32:11 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 8
Dec 21 18:32:11 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 0
Dec 21 18:32:11 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:32:11 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 8
Dec 21 18:32:11 DEBUG[205] app_rxfax.c: FLOW FAX Switching from V.29 + V.21 to V.29 (-17.03dBm0)
Dec 21 18:32:12 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 4
Dec 21 18:32:12 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 0
Dec 21 18:32:12 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 0
Dec 21 18:32:12 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 4
Dec 21 18:32:14 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 8
Dec 21 18:32:14 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 0
Dec 21 18:32:14 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:32:14 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 8
Dec 21 18:32:14 DEBUG[205] app_rxfax.c: FLOW FAX Switching from V.29 + V.21 to V.29 (-18.30dBm0)
Dec 21 18:32:36 DEBUG[205] chan_iax2.c: Peer lastms 1, historicms 2, maxms 2000
Dec 21 18:32:54 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:32:54 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 4
Dec 21 18:32:56 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 4
Dec 21 18:32:56 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 0
Dec 21 18:32:56 DEBUG[205] chan_iax2.c: Allocate call number
Dec 21 18:32:56 DEBUG[205] chan_iax2.c: Registration created on call 4
Dec 21 18:32:59 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:32:59 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 4
Dec 21 18:33:00 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 4
Dec 21 18:33:00 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 0
Dec 21 18:33:04 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:33:04 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 4
Dec 21 18:33:05 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 4
Dec 21 18:33:05 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 0
Dec 21 18:33:08 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:33:08 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 4
Dec 21 18:33:09 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 4
Dec 21 18:33:09 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 0
Dec 21 18:33:13 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:33:13 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 4
Dec 21 18:33:14 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:33:14 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 1
Dec 21 18:33:15 DEBUG[205] app_txfax.c: ==============================================================================
Dec 21 18:33:15 DEBUG[205] app_txfax.c: Fax send not successful - result (25) No response after sending a page.
Dec 21 18:33:15 DEBUG[205] app_txfax.c: ==============================================================================
Dec 21 18:33:15 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 13
Dec 21 18:33:15 DEBUG[205] app_txfax.c: FLOW FAX FAX exchange complete
Dec 21 18:33:15 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 13
Dec 21 18:33:15 DEBUG[205] app_txfax.c: FLOW FAX FAX exchange complete
Dec 21 18:33:15 DEBUG[205] channel.c: Set channel Zap/1-1 to read format alaw
Dec 21 18:33:15 DEBUG[205] channel.c: Set channel Zap/1-1 to write format alaw
Dec 21 18:33:15 VERBOSE[205] logger.c:   == Auto fallthrough, channel 'Zap/1-1' status is 'UNKNOWN'
Dec 21 18:33:15 DEBUG[205] pbx.c: Launching 'Set'
Dec 21 18:33:15 VERBOSE[205] logger.c:     -- Executing Set("Zap/1-1", "QC_PROVISIONING_URL=http://admin:admin@192.168.1.57/provisioning/interface.php/") in new stack
Dec 21 18:33:15 DEBUG[205] pbx.c: Function result is '1198233125.0'
Dec 21 18:33:15 DEBUG[205] pbx.c: Launching 'Set'
Dec 21 18:33:15 VERBOSE[205] logger.c:     -- Executing Set("Zap/1-1", "UNIQUEID=1198233125.0") in new stack
Dec 21 18:33:15 DEBUG[205] channel.c: Hanging up channel 'Zap/1-1'
Dec 21 18:33:15 DEBUG[205] chan_zap.c: zt_hangup(Zap/1-1)
Dec 21 18:33:15 DEBUG[205] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/1-1
Dec 21 18:33:15 DEBUG[205] chan_zap.c: Hangup: channel: 1 index = 0, normal = 12, callwait = -1, thirdcall = -1
Dec 21 18:33:15 DEBUG[205] chan_zap.c: Not yet hungup...  Calling hangup once with icause, and clearing call
Dec 21 18:33:15 DEBUG[205] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1
Dec 21 18:33:15 DEBUG[205] chan_zap.c: Updated conferencing on 1, with 0 conference users
Dec 21 18:33:15 DEBUG[205] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/1-1
Dec 21 18:33:15 VERBOSE[205] logger.c:     -- Hungup 'Zap/1-1'
Dec 21 18:33:15 NOTICE[205] pbx_spool.c: Call completed to Zap/g1/1002
Dec 21 18:33:15 DEBUG[205] devicestate.c: Changing state for Zap/1 - state 0 (Unknown)
Dec 21 18:33:15 DEBUG[205] app_queue.c: Device 'Zap/1' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.
Dec 21 18:33:15 VERBOSE[205] logger.c:     -- Channel 0/1, span 2 got hangup request, cause 16
Dec 21 18:33:15 DEBUG[205] app_rxfax.c: Got hangup
Dec 21 18:33:15 DEBUG[205] channel.c: Set channel Zap/32-1 to read format alaw
Dec 21 18:33:15 DEBUG[205] channel.c: Set channel Zap/32-1 to write format alaw
Dec 21 18:33:15 DEBUG[205] app_rxfax.c: ==============================================================================
Dec 21 18:33:15 DEBUG[205] app_rxfax.c: Fax receive not successful - result (51) The call dropped prematurely.
Dec 21 18:33:15 DEBUG[205] app_rxfax.c: ==============================================================================
Dec 21 18:33:15 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 13
Dec 21 18:33:15 DEBUG[205] app_rxfax.c: FLOW FAX FAX exchange complete
Dec 21 18:33:15 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 13
Dec 21 18:33:15 DEBUG[205] app_rxfax.c: FLOW FAX FAX exchange complete
Dec 21 18:33:15 DEBUG[205] pbx.c: Extension 1002, priority 5 returned normally even though call was hung up
Dec 21 18:33:15 DEBUG[205] pbx.c: Launching 'NoOp'
Dec 21 18:33:15 VERBOSE[205] logger.c:     -- Executing NoOp("Zap/32-1", "FAXFILE") in new stack
Dec 21 18:33:15 DEBUG[205] pbx.c: Launching 'System'
Dec 21 18:33:15 VERBOSE[205] logger.c:     -- Executing System("Zap/32-1", "/bin/cp /tmp/FAX-1198233125.1.tiff /var/spool/asterisk/fax/FAX-1002--1198233125----1198233125.1.tiff") in new stack
Dec 21 18:33:15 DEBUG[205] pbx.c: Launching 'System'
Dec 21 18:33:15 VERBOSE[205] logger.c:     -- Executing System("Zap/32-1", "/bin/rm /tmp/FAX-1198233125.1.tiff") in new stack
Dec 21 18:33:15 DEBUG[205] channel.c: Hanging up channel 'Zap/32-1'
Dec 21 18:33:15 DEBUG[205] chan_zap.c: zt_hangup(Zap/32-1)
Dec 21 18:33:15 DEBUG[205] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/32-1
Dec 21 18:33:15 DEBUG[205] chan_zap.c: Hangup: channel: 32 index = 0, normal = 42, callwait = -1, thirdcall = -1
Dec 21 18:33:15 DEBUG[205] chan_zap.c: Not yet hungup...  Calling hangup once with icause, and clearing call
Dec 21 18:33:15 DEBUG[205] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/32-1
Dec 21 18:33:15 DEBUG[205] chan_zap.c: Updated conferencing on 32, with 0 conference users
Dec 21 18:33:15 DEBUG[205] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/32-1
Dec 21 18:33:15 VERBOSE[205] logger.c:     -- Hungup 'Zap/32-1'
Dec 21 18:33:15 DEBUG[205] devicestate.c: Changing state for Zap/32 - state 0 (Unknown)
Dec 21 18:33:15 DEBUG[205] app_queue.c: Device 'Zap/32' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.
Dec 21 18:33:35 VERBOSE[205] logger.c:     -- Attempting call on Zap/g1/1002 for 1024@txfax:1 (Retry 1)
Dec 21 18:33:35 DEBUG[205] chan_zap.c: Using channel 1
Dec 21 18:33:35 VERBOSE[205] logger.c:     -- Requested transfer capability: 0x00 - SPEECH
Dec 21 18:33:35 DEBUG[205] devicestate.c: Changing state for Zap/1 - state 2 (In use)
Dec 21 18:33:35 DEBUG[205] devicestate.c: Changing state for Zap/1 - state 2 (In use)
Dec 21 18:33:35 DEBUG[205] app_queue.c: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Dec 21 18:33:35 DEBUG[205] app_queue.c: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Dec 21 18:33:35 VERBOSE[205] logger.c:     -- Accepting call from '' to '1002' on channel 0/1, span 2
Dec 21 18:33:35 DEBUG[205] chan_zap.c: No echo cancellation requested
Dec 21 18:33:35 DEBUG[205] devicestate.c: Changing state for Zap/32 - state 2 (In use)
Dec 21 18:33:35 DEBUG[205] pbx.c: Launching 'Answer'
Dec 21 18:33:35 VERBOSE[205] logger.c:     -- Executing Answer("Zap/32-1", "") in new stack
Dec 21 18:33:35 DEBUG[205] pbx.c: Launching 'Wait'
Dec 21 18:33:35 VERBOSE[205] logger.c:     -- Executing Wait("Zap/32-1", "") in new stack
Dec 21 18:33:35 DEBUG[205] pbx.c: Launching 'Set'
Dec 21 18:33:35 VERBOSE[205] logger.c:     -- Executing Set("Zap/32-1", "FAXFILE=/tmp/FAX-1198233215.3.tiff") in new stack
Dec 21 18:33:35 DEBUG[205] pbx.c: Function result is '1002'
Dec 21 18:33:35 DEBUG[205] pbx.c: Launching 'Set'
Dec 21 18:33:35 VERBOSE[205] logger.c:     -- Executing Set("Zap/32-1", "NEWFAXFILE=/var/spool/asterisk/fax/FAX-1002--1198233215----1198233215.3.tiff") in new stack
Dec 21 18:33:35 DEBUG[205] pbx.c: Launching 'RxFAX'
Dec 21 18:33:35 VERBOSE[205] logger.c:     -- Executing RxFAX("Zap/32-1", "/tmp/FAX-1198233215.3.tiff|debug") in new stack
Dec 21 18:33:35 DEBUG[205] channel.c: Set channel Zap/32-1 to read format slin
Dec 21 18:33:35 DEBUG[205] channel.c: Set channel Zap/32-1 to write format slin
Dec 21 18:33:35 DEBUG[205] app_queue.c: Device 'Zap/32' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Dec 21 18:33:35 DEBUG[205] devicestate.c: Changing state for Zap/32 - state 2 (In use)
Dec 21 18:33:35 DEBUG[205] app_queue.c: Device 'Zap/32' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Dec 21 18:33:35 DEBUG[205] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 1
Dec 21 18:33:35 DEBUG[205] chan_zap.c: No echo cancellation requested
Dec 21 18:33:35 VERBOSE[205] logger.c:        > Channel Zap/1-1 was answered.
Dec 21 18:33:35 DEBUG[205] pbx.c: Launching 'Answer'
Dec 21 18:33:35 VERBOSE[205] logger.c:     -- Executing Answer("Zap/1-1", "") in new stack
Dec 21 18:33:35 DEBUG[205] pbx.c: Launching 'Set'
Dec 21 18:33:35 VERBOSE[205] logger.c:     -- Executing Set("Zap/1-1", "CDR(userfield)=FAX-1") in new stack
Dec 21 18:33:35 DEBUG[205] pbx.c: Launching 'TxFAX'
Dec 21 18:33:35 VERBOSE[205] logger.c:     -- Executing TxFAX("Zap/1-1", "/var/spool/asterisk/outgoing_fax/page.1.1.tiff|caller|debug") in new stack
Dec 21 18:33:35 DEBUG[205] channel.c: Set channel Zap/1-1 to read format slin
Dec 21 18:33:35 DEBUG[205] channel.c: Set channel Zap/1-1 to write format slin
Dec 21 18:33:35 DEBUG[205] devicestate.c: Changing state for Zap/1 - state 2 (In use)
Dec 21 18:33:35 DEBUG[205] app_queue.c: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Dec 21 18:33:36 DEBUG[205] chan_iax2.c: Peer lastms 3, historicms 2, maxms 2000
Dec 21 18:33:37 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 0
Dec 21 18:33:37 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 4
Dec 21 18:33:37 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 4
Dec 21 18:33:37 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 0
Dec 21 18:33:39 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 4
Dec 21 18:33:39 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 0
Dec 21 18:33:39 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:33:39 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 4
Dec 21 18:33:41 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 8
Dec 21 18:33:41 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 0
Dec 21 18:33:41 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:33:41 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 8
Dec 21 18:33:41 DEBUG[205] app_rxfax.c: FLOW FAX Switching from V.29 + V.21 to V.29 (-17.29dBm0)
Dec 21 18:33:43 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 4
Dec 21 18:33:43 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 0
Dec 21 18:33:43 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 0
Dec 21 18:33:43 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 4
Dec 21 18:33:44 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 4
Dec 21 18:33:44 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 0
Dec 21 18:33:44 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:33:44 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 4
Dec 21 18:33:46 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:33:46 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 7
Dec 21 18:33:46 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 0
Dec 21 18:33:46 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 4
Dec 21 18:33:47 DEBUG[205] chan_iax2.c: Allocate call number
Dec 21 18:33:47 DEBUG[205] chan_iax2.c: Registration created on call 2
Dec 21 18:33:47 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 0
Dec 21 18:33:47 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 1
Dec 21 18:33:48 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 4
Dec 21 18:33:48 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 0
Dec 21 18:33:48 DEBUG[205] app_rxfax.c: ==============================================================================
Dec 21 18:33:48 DEBUG[205] app_rxfax.c: Fax receive not successful - result (13) Unexpected message received.
Dec 21 18:33:48 DEBUG[205] app_rxfax.c: ==============================================================================
Dec 21 18:33:48 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 13
Dec 21 18:33:48 DEBUG[205] app_rxfax.c: FLOW FAX FAX exchange complete
Dec 21 18:33:48 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 13
Dec 21 18:33:48 DEBUG[205] app_rxfax.c: FLOW FAX FAX exchange complete
Dec 21 18:33:48 DEBUG[205] channel.c: Set channel Zap/32-1 to read format alaw
Dec 21 18:33:48 DEBUG[205] channel.c: Set channel Zap/32-1 to write format alaw
Dec 21 18:33:48 DEBUG[205] pbx.c: Launching 'System'
Dec 21 18:33:48 VERBOSE[205] logger.c:     -- Executing System("Zap/32-1", "/bin/cp /tmp/FAX-1198233215.3.tiff /var/spool/asterisk/fax/FAX-1002--1198233215----1198233215.3.tiff") in new stack
Dec 21 18:33:48 DEBUG[205] pbx.c: Launching 'Hangup'
Dec 21 18:33:48 VERBOSE[205] logger.c:     -- Executing Hangup("Zap/32-1", "") in new stack
Dec 21 18:33:48 DEBUG[205] pbx.c: Spawn extension (rxfax,1002,7) exited non-zero on 'Zap/32-1'
Dec 21 18:33:48 VERBOSE[205] logger.c:   == Spawn extension (rxfax, 1002, 7) exited non-zero on 'Zap/32-1'
Dec 21 18:33:48 DEBUG[205] pbx.c: Launching 'NoOp'
Dec 21 18:33:48 VERBOSE[205] logger.c:     -- Executing NoOp("Zap/32-1", "FAXFILE") in new stack
Dec 21 18:33:48 DEBUG[205] pbx.c: Launching 'System'
Dec 21 18:33:48 VERBOSE[205] logger.c:     -- Executing System("Zap/32-1", "/bin/cp /tmp/FAX-1198233215.3.tiff /var/spool/asterisk/fax/FAX-1002--1198233215----1198233215.3.tiff") in new stack
Dec 21 18:33:48 DEBUG[205] pbx.c: Launching 'System'
Dec 21 18:33:48 VERBOSE[205] logger.c:     -- Executing System("Zap/32-1", "/bin/rm /tmp/FAX-1198233215.3.tiff") in new stack
Dec 21 18:33:48 DEBUG[205] channel.c: Hanging up channel 'Zap/32-1'
Dec 21 18:33:48 DEBUG[205] chan_zap.c: zt_hangup(Zap/32-1)
Dec 21 18:33:48 DEBUG[205] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/32-1
Dec 21 18:33:48 DEBUG[205] chan_zap.c: Hangup: channel: 32 index = 0, normal = 42, callwait = -1, thirdcall = -1
Dec 21 18:33:48 DEBUG[205] chan_zap.c: Not yet hungup...  Calling hangup once with icause, and clearing call
Dec 21 18:33:48 DEBUG[205] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/32-1
Dec 21 18:33:48 DEBUG[205] chan_zap.c: Updated conferencing on 32, with 0 conference users
Dec 21 18:33:48 DEBUG[205] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/32-1
Dec 21 18:33:48 VERBOSE[205] logger.c:     -- Hungup 'Zap/32-1'
Dec 21 18:33:48 DEBUG[205] devicestate.c: Changing state for Zap/32 - state 0 (Unknown)
Dec 21 18:33:48 DEBUG[205] app_queue.c: Device 'Zap/32' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.
Dec 21 18:33:48 VERBOSE[205] logger.c:     -- Channel 0/1, span 1 got hangup request, cause 16
Dec 21 18:33:48 DEBUG[205] app_txfax.c: Got hangup
Dec 21 18:33:48 DEBUG[205] channel.c: Set channel Zap/1-1 to read format alaw
Dec 21 18:33:48 DEBUG[205] channel.c: Set channel Zap/1-1 to write format alaw
Dec 21 18:33:48 DEBUG[205] app_txfax.c: ==============================================================================
Dec 21 18:33:48 DEBUG[205] app_txfax.c: Fax send not successful - result (51) The call dropped prematurely.
Dec 21 18:33:48 DEBUG[205] app_txfax.c: ==============================================================================
Dec 21 18:33:48 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 13
Dec 21 18:33:48 DEBUG[205] app_txfax.c: FLOW FAX FAX exchange complete
Dec 21 18:33:48 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 13
Dec 21 18:33:48 DEBUG[205] app_txfax.c: FLOW FAX FAX exchange complete
Dec 21 18:33:48 DEBUG[205] pbx.c: Extension 1024, priority 3 returned normally even though call was hung up
Dec 21 18:33:48 DEBUG[205] pbx.c: Launching 'Set'
Dec 21 18:33:48 VERBOSE[205] logger.c:     -- Executing Set("Zap/1-1", "QC_PROVISIONING_URL=http://admin:admin@192.168.1.57/provisioning/interface.php/") in new stack
Dec 21 18:33:48 DEBUG[205] pbx.c: Function result is '1198233215.2'
Dec 21 18:33:48 DEBUG[205] pbx.c: Launching 'Set'
Dec 21 18:33:48 VERBOSE[205] logger.c:     -- Executing Set("Zap/1-1", "UNIQUEID=1198233215.2") in new stack
Dec 21 18:33:48 DEBUG[205] channel.c: Hanging up channel 'Zap/1-1'
Dec 21 18:33:48 DEBUG[205] chan_zap.c: zt_hangup(Zap/1-1)
Dec 21 18:33:48 DEBUG[205] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/1-1
Dec 21 18:33:48 DEBUG[205] chan_zap.c: Hangup: channel: 1 index = 0, normal = 12, callwait = -1, thirdcall = -1
Dec 21 18:33:48 DEBUG[205] chan_zap.c: Not yet hungup...  Calling hangup once with icause, and clearing call
Dec 21 18:33:48 DEBUG[205] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1
Dec 21 18:33:48 DEBUG[205] chan_zap.c: Updated conferencing on 1, with 0 conference users
Dec 21 18:33:48 DEBUG[205] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/1-1
Dec 21 18:33:48 VERBOSE[205] logger.c:     -- Hungup 'Zap/1-1'
Dec 21 18:33:48 NOTICE[205] pbx_spool.c: Call completed to Zap/g1/1002
Dec 21 18:33:48 DEBUG[205] devicestate.c: Changing state for Zap/1 - state 0 (Unknown)
Dec 21 18:33:48 DEBUG[205] app_queue.c: Device 'Zap/1' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.
Dec 21 18:34:05 VERBOSE[205] logger.c:     -- Attempting call on Zap/g1/1002 for 1024@txfax:1 (Retry 1)
Dec 21 18:34:05 DEBUG[205] chan_zap.c: Using channel 1
Dec 21 18:34:05 VERBOSE[205] logger.c:     -- Requested transfer capability: 0x00 - SPEECH
Dec 21 18:34:05 DEBUG[205] devicestate.c: Changing state for Zap/1 - state 2 (In use)
Dec 21 18:34:05 DEBUG[205] devicestate.c: Changing state for Zap/1 - state 2 (In use)
Dec 21 18:34:05 DEBUG[205] app_queue.c: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Dec 21 18:34:05 DEBUG[205] app_queue.c: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Dec 21 18:34:05 VERBOSE[205] logger.c:     -- Accepting call from '' to '1002' on channel 0/1, span 2
Dec 21 18:34:05 DEBUG[205] chan_zap.c: No echo cancellation requested
Dec 21 18:34:05 DEBUG[205] devicestate.c: Changing state for Zap/32 - state 2 (In use)
Dec 21 18:34:05 DEBUG[205] pbx.c: Launching 'Answer'
Dec 21 18:34:05 VERBOSE[205] logger.c:     -- Executing Answer("Zap/32-1", "") in new stack
Dec 21 18:34:05 DEBUG[205] pbx.c: Launching 'Wait'
Dec 21 18:34:05 VERBOSE[205] logger.c:     -- Executing Wait("Zap/32-1", "") in new stack
Dec 21 18:34:05 DEBUG[205] pbx.c: Launching 'Set'
Dec 21 18:34:05 VERBOSE[205] logger.c:     -- Executing Set("Zap/32-1", "FAXFILE=/tmp/FAX-1198233245.5.tiff") in new stack
Dec 21 18:34:05 DEBUG[205] pbx.c: Function result is '1002'
Dec 21 18:34:05 DEBUG[205] pbx.c: Launching 'Set'
Dec 21 18:34:05 VERBOSE[205] logger.c:     -- Executing Set("Zap/32-1", "NEWFAXFILE=/var/spool/asterisk/fax/FAX-1002--1198233245----1198233245.5.tiff") in new stack
Dec 21 18:34:05 DEBUG[205] pbx.c: Launching 'RxFAX'
Dec 21 18:34:05 VERBOSE[205] logger.c:     -- Executing RxFAX("Zap/32-1", "/tmp/FAX-1198233245.5.tiff|debug") in new stack
Dec 21 18:34:05 DEBUG[205] channel.c: Set channel Zap/32-1 to read format slin
Dec 21 18:34:05 DEBUG[205] channel.c: Set channel Zap/32-1 to write format slin
Dec 21 18:34:05 DEBUG[205] app_queue.c: Device 'Zap/32' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Dec 21 18:34:05 DEBUG[205] devicestate.c: Changing state for Zap/32 - state 2 (In use)
Dec 21 18:34:05 DEBUG[205] app_queue.c: Device 'Zap/32' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Dec 21 18:34:05 DEBUG[205] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 1
Dec 21 18:34:05 DEBUG[205] chan_zap.c: No echo cancellation requested
Dec 21 18:34:05 VERBOSE[205] logger.c:        > Channel Zap/1-1 was answered.
Dec 21 18:34:05 DEBUG[205] pbx.c: Launching 'Answer'
Dec 21 18:34:05 VERBOSE[205] logger.c:     -- Executing Answer("Zap/1-1", "") in new stack
Dec 21 18:34:05 DEBUG[205] pbx.c: Launching 'Set'
Dec 21 18:34:05 VERBOSE[205] logger.c:     -- Executing Set("Zap/1-1", "CDR(userfield)=FAX-1") in new stack
Dec 21 18:34:05 DEBUG[205] pbx.c: Launching 'TxFAX'
Dec 21 18:34:05 VERBOSE[205] logger.c:     -- Executing TxFAX("Zap/1-1", "/var/spool/asterisk/outgoing_fax/page.1.1.tiff|caller|debug") in new stack
Dec 21 18:34:05 DEBUG[205] channel.c: Set channel Zap/1-1 to read format slin
Dec 21 18:34:05 DEBUG[205] channel.c: Set channel Zap/1-1 to write format slin
Dec 21 18:34:05 DEBUG[205] devicestate.c: Changing state for Zap/1 - state 2 (In use)
Dec 21 18:34:05 DEBUG[205] app_queue.c: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Dec 21 18:34:07 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 0
Dec 21 18:34:07 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 4
Dec 21 18:34:08 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 4
Dec 21 18:34:08 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 0
Dec 21 18:34:09 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 4
Dec 21 18:34:09 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 0
Dec 21 18:34:09 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:34:09 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 4
Dec 21 18:34:11 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 8
Dec 21 18:34:11 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 0
Dec 21 18:34:11 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:34:11 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 8
Dec 21 18:34:11 DEBUG[205] app_rxfax.c: FLOW FAX Switching from V.29 + V.21 to V.29 (-17.03dBm0)
Dec 21 18:34:13 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 4
Dec 21 18:34:13 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 0
Dec 21 18:34:13 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 0
Dec 21 18:34:13 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 4
Dec 21 18:34:14 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 8
Dec 21 18:34:14 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 0
Dec 21 18:34:14 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:34:14 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 8
Dec 21 18:34:14 DEBUG[205] app_rxfax.c: FLOW FAX Switching from V.29 + V.21 to V.29 (-17.51dBm0)
Dec 21 18:34:36 DEBUG[205] chan_iax2.c: Peer lastms 1, historicms 1, maxms 2000
Dec 21 18:34:37 DEBUG[205] chan_iax2.c: Allocate call number
Dec 21 18:34:37 DEBUG[205] chan_iax2.c: Registration created on call 1
Dec 21 18:34:54 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:34:54 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 4
Dec 21 18:34:56 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 4
Dec 21 18:34:56 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 0
Dec 21 18:34:59 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:34:59 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 4
Dec 21 18:35:00 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 4
Dec 21 18:35:00 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 0
Dec 21 18:35:04 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:35:04 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 4
Dec 21 18:35:05 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 4
Dec 21 18:35:05 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 0
Dec 21 18:35:08 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:35:08 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 4
Dec 21 18:35:10 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 4
Dec 21 18:35:10 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 0
Dec 21 18:35:13 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:35:13 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 4
Dec 21 18:35:14 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 0
Dec 21 18:35:14 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 1
Dec 21 18:35:15 DEBUG[205] app_txfax.c: ==============================================================================
Dec 21 18:35:15 DEBUG[205] app_txfax.c: Fax send not successful - result (25) No response after sending a page.
Dec 21 18:35:15 DEBUG[205] app_txfax.c: ==============================================================================
Dec 21 18:35:15 DEBUG[205] app_txfax.c: FLOW FAX Set rx type 13
Dec 21 18:35:15 DEBUG[205] app_txfax.c: FLOW FAX FAX exchange complete
Dec 21 18:35:15 DEBUG[205] app_txfax.c: FLOW FAX Set tx type 13
Dec 21 18:35:15 DEBUG[205] app_txfax.c: FLOW FAX FAX exchange complete
Dec 21 18:35:15 DEBUG[205] channel.c: Set channel Zap/1-1 to read format alaw
Dec 21 18:35:15 DEBUG[205] channel.c: Set channel Zap/1-1 to write format alaw
Dec 21 18:35:15 VERBOSE[205] logger.c:   == Auto fallthrough, channel 'Zap/1-1' status is 'UNKNOWN'
Dec 21 18:35:15 DEBUG[205] pbx.c: Launching 'Set'
Dec 21 18:35:15 VERBOSE[205] logger.c:     -- Executing Set("Zap/1-1", "QC_PROVISIONING_URL=http://admin:admin@192.168.1.57/provisioning/interface.php/") in new stack
Dec 21 18:35:15 DEBUG[205] pbx.c: Function result is '1198233245.4'
Dec 21 18:35:15 DEBUG[205] pbx.c: Launching 'Set'
Dec 21 18:35:15 VERBOSE[205] logger.c:     -- Executing Set("Zap/1-1", "UNIQUEID=1198233245.4") in new stack
Dec 21 18:35:15 DEBUG[205] channel.c: Hanging up channel 'Zap/1-1'
Dec 21 18:35:15 DEBUG[205] chan_zap.c: zt_hangup(Zap/1-1)
Dec 21 18:35:15 DEBUG[205] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/1-1
Dec 21 18:35:15 DEBUG[205] chan_zap.c: Hangup: channel: 1 index = 0, normal = 12, callwait = -1, thirdcall = -1
Dec 21 18:35:15 DEBUG[205] chan_zap.c: Not yet hungup...  Calling hangup once with icause, and clearing call
Dec 21 18:35:15 DEBUG[205] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1
Dec 21 18:35:15 DEBUG[205] chan_zap.c: Updated conferencing on 1, with 0 conference users
Dec 21 18:35:15 DEBUG[205] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/1-1
Dec 21 18:35:15 VERBOSE[205] logger.c:     -- Hungup 'Zap/1-1'
Dec 21 18:35:15 NOTICE[205] pbx_spool.c: Call completed to Zap/g1/1002
Dec 21 18:35:15 DEBUG[205] devicestate.c: Changing state for Zap/1 - state 0 (Unknown)
Dec 21 18:35:15 DEBUG[205] app_queue.c: Device 'Zap/1' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.
Dec 21 18:35:15 VERBOSE[205] logger.c:     -- Channel 0/1, span 2 got hangup request, cause 16
Dec 21 18:35:15 DEBUG[205] app_rxfax.c: Got hangup
Dec 21 18:35:15 DEBUG[205] channel.c: Set channel Zap/32-1 to read format alaw
Dec 21 18:35:15 DEBUG[205] channel.c: Set channel Zap/32-1 to write format alaw
Dec 21 18:35:15 DEBUG[205] app_rxfax.c: ==============================================================================
Dec 21 18:35:15 DEBUG[205] app_rxfax.c: Fax receive not successful - result (51) The call dropped prematurely.
Dec 21 18:35:15 DEBUG[205] app_rxfax.c: ==============================================================================
Dec 21 18:35:15 DEBUG[205] app_rxfax.c: FLOW FAX Set rx type 13
Dec 21 18:35:15 DEBUG[205] app_rxfax.c: FLOW FAX FAX exchange complete
Dec 21 18:35:15 DEBUG[205] app_rxfax.c: FLOW FAX Set tx type 13
Dec 21 18:35:15 DEBUG[205] app_rxfax.c: FLOW FAX FAX exchange complete
Dec 21 18:35:15 DEBUG[205] pbx.c: Extension 1002, priority 5 returned normally even though call was hung up
Dec 21 18:35:15 DEBUG[205] pbx.c: Launching 'NoOp'
Dec 21 18:35:15 VERBOSE[205] logger.c:     -- Executing NoOp("Zap/32-1", "FAXFILE") in new stack
Dec 21 18:35:15 DEBUG[205] pbx.c: Launching 'System'
Dec 21 18:35:15 VERBOSE[205] logger.c:     -- Executing System("Zap/32-1", "/bin/cp /tmp/FAX-1198233245.5.tiff /var/spool/asterisk/fax/FAX-1002--1198233245----1198233245.5.tiff") in new stack
Dec 21 18:35:15 DEBUG[205] pbx.c: Launching 'System'
Dec 21 18:35:15 VERBOSE[205] logger.c:     -- Executing System("Zap/32-1", "/bin/rm /tmp/FAX-1198233245.5.tiff") in new stack
Dec 21 18:35:15 DEBUG[205] channel.c: Hanging up channel 'Zap/32-1'
Dec 21 18:35:15 DEBUG[205] chan_zap.c: zt_hangup(Zap/32-1)
Dec 21 18:35:15 DEBUG[205] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/32-1
Dec 21 18:35:15 DEBUG[205] chan_zap.c: Hangup: channel: 32 index = 0, normal = 42, callwait = -1, thirdcall = -1
Dec 21 18:35:15 DEBUG[205] chan_zap.c: Not yet hungup...  Calling hangup once with icause, and clearing call
Dec 21 18:35:15 DEBUG[205] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/32-1
Dec 21 18:35:15 DEBUG[205] chan_zap.c: Updated conferencing on 32, with 0 conference users
Dec 21 18:35:15 DEBUG[205] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/32-1
Dec 21 18:35:15 VERBOSE[205] logger.c:     -- Hungup 'Zap/32-1'
Dec 21 18:35:15 DEBUG[205] devicestate.c: Changing state for Zap/32 - state 0 (Unknown)
Dec 21 18:35:15 DEBUG[205] app_queue.c: Device 'Zap/32' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.
Dec 21 18:35:27 DEBUG[205] chan_iax2.c: Allocate call number
Dec 21 18:35:27 DEBUG[205] chan_iax2.c: Registration created on call 4