Asterisk 13.21 ReceiveFAX не принимает факс-файл
Добавлено: 18 мар 2020, 09:54
Всех приветствую.
Имеем Asterisk 13.21 +FreePBX 14
Установленные модули и их параметры:
Код диалплана для приема факса:
Схема работы: при входящем звонке, оператор на ip-телефоне во время разговора набирает *6, затем вызывается macro-infax. В процессе факс-файл должен принятся приложением ReceiveFAX и сохраниться в tif формате в папке /var/spool/asterisk/fax, после php скрипт fax-in.php преобразует его в pdf и через smtp сервер отправит на e-mail.
И все бы хорошо, последняя часть (конвертация и отправка на почту) 100% рабочая, проверенно отдельно от вызова.
А вот загвоздка при выполнении приложения ReceiveFAX. Обмен данными происходит, но по итогу факс не проходит, соответствено tif файл не создается и отправляться нечему. Плюс после выполнения приложения ReceiveFAX сразу происходит хэнгап.
Прошу помощи в решении проблемы, либо подсказках в каком направлении копать, чтобы решить ее.
FAX For Asterisk Settings:
ECM: Enabled
Status Events: Off
Minimum Bit Rate: 9600
Maximum Bit Rate: 14400
Modem Modulations Allowed: V17,V27,V29
T.38 Negotiation Timeout: 5000
FAX Technology Modules:
Spandsp (Spandsp FAX Driver) Settings
Имеем Asterisk 13.21 +FreePBX 14
Установленные модули и их параметры:
Код диалплана для приема факса:
Код: Выделить всё
[macro-infax]
exten => s,1,NoOP(------------------- FAX from ${CALLERID(number)} ------------------)
same => n,Answer()
same => n,Set(__FAXFOLDER=/var/spool/asterisk/fax)
same => n,Set(DT=${STRFTIME(${EPOCH},,%Y%m%d-%H%M%S)}-${CALLERID(number)})
same => n,Set(FAXOPT(headerinfo)=Received by ${CALLERID(number)} ${STRFTIME(${EPOCH},,%Y-%m-%d %H-%M)})
same => n,NoOp(FAXOPT(ecm) : ${FAXOPT(ecm)})
same => n,NoOp(FAXOPT(headerinfo) : ${FAXOPT(headerinfo)})
same => n,NoOp(FAXOPT(localstationid) : ${FAXOPT(localstationid)})
same => n,NoOp(FAXOPT(maxrate) : ${FAXOPT(maxrate)})
same => n,NoOp(FAXOPT(minrate) : ${FAXOPT(minrate)})
same => n,NoOp(**** RECEIVING FAX : ${DT} ****)
same => n,ReceiveFAX(${FAXFOLDER}/${CALLERID(number)}.tif,f)
same => n,System(/usr/bin/php -q ${AVAN_BIN}/custom/fax-in.php INFAX "roman@avantele.com" "${FAXFOLDER}/${CALLERID(number)}" "${CALLERID(number)}" "${DATE}" "${TIME}" "${FAXSTATUS}" "${FAXPAGES}" "${FAXOPT(localstationid)}")
same => n,HangUp()
И все бы хорошо, последняя часть (конвертация и отправка на почту) 100% рабочая, проверенно отдельно от вызова.
А вот загвоздка при выполнении приложения ReceiveFAX. Обмен данными происходит, но по итогу факс не проходит, соответствено tif файл не создается и отправляться нечему. Плюс после выполнения приложения ReceiveFAX сразу происходит хэнгап.
Прошу помощи в решении проблемы, либо подсказках в каком направлении копать, чтобы решить ее.
FAX For Asterisk Settings:
ECM: Enabled
Status Events: Off
Minimum Bit Rate: 9600
Maximum Bit Rate: 14400
Modem Modulations Allowed: V17,V27,V29
T.38 Negotiation Timeout: 5000
FAX Technology Modules:
Spandsp (Spandsp FAX Driver) Settings
PRIME_BBCODE_SPOILER_SHOW PRIME_BBCODE_SPOILER: часть лога звонка с отработкой macro-infax +включен fax debug
[2020-03-18 12:31:36] VERBOSE[30440][C-000087c1] bridge_channel.c: Channel PJSIP/4900-00028351 joined 'simple_bridge' basic-bridge <d330ca43-19ff-48dd-b9e9-8ebd58973366>
[2020-03-18 12:31:36] VERBOSE[30431][C-000087c1] bridge_channel.c: Channel PJSIP/RTK_E1_pjsip-00028350 joined 'simple_bridge' basic-bridge <d330ca43-19ff-48dd-b9e9-8ebd58973366>
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF begin '*' received on PJSIP/4900-00028351
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF begin passthrough '*' on PJSIP/4900-00028351
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF end '*' received on PJSIP/4900-00028351, duration 90 ms
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF end accepted with begin '*' on PJSIP/4900-00028351
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF end passthrough '*' on PJSIP/4900-00028351
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF begin '6' received on PJSIP/4900-00028351
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF begin passthrough '6' on PJSIP/4900-00028351
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF end '6' received on PJSIP/4900-00028351, duration 90 ms
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF end accepted with begin '6' on PJSIP/4900-00028351
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF end passthrough '6' on PJSIP/4900-00028351
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:1] NoOp("PJSIP/RTK_E1_pjsip-00028350", "------------------- FAX from 89622295574 ------------------") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:2] Answer("PJSIP/RTK_E1_pjsip-00028350", "") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:3] Set("PJSIP/RTK_E1_pjsip-00028350", "__FAXFOLDER=/var/spool/asterisk/fax") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:4] Set("PJSIP/RTK_E1_pjsip-00028350", "DT=20200318-123140-89622295574") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:5] Set("PJSIP/RTK_E1_pjsip-00028350", "FAXOPT(headerinfo)=Received by 89622295574 2020-03-18 12-31") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:6] NoOp("PJSIP/RTK_E1_pjsip-00028350", "FAXOPT(ecm) : yes") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:7] NoOp("PJSIP/RTK_E1_pjsip-00028350", "FAXOPT(headerinfo) : Received by 89622295574 2020-03-18 12-31") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:8] NoOp("PJSIP/RTK_E1_pjsip-00028350", "FAXOPT(localstationid) : ") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:9] NoOp("PJSIP/RTK_E1_pjsip-00028350", "FAXOPT(maxrate) : 14400") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:10] NoOp("PJSIP/RTK_E1_pjsip-00028350", "FAXOPT(minrate) : 9600") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:11] NoOp("PJSIP/RTK_E1_pjsip-00028350", "**** RECEIVING FAX : 20200318-123140-89622295574 ****") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:12] ReceiveFAX("PJSIP/RTK_E1_pjsip-00028350", "/var/spool/asterisk/fax/89622295574.tif,f") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' receiving FAX '/var/spool/asterisk/fax/89622295574.tif'
[2020-03-18 12:31:41] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' fax session '9', [ 000.220307 ], stack sent 10 frames (200 ms) of silence.
[2020-03-18 12:31:43] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' fax session '9', [ 002.093318 ], channel sent 104 frames (2080 ms) of silence.
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 HDLC signal status is Carrier up (-2) in state 1
[2020-03-18 12:31:43] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' fax session '9', [ 002.592961 ], channel sent 25 frames (500 ms) of energy.
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 HDLC signal status is Carrier down (-1) in state 1
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Send complete in phase T30_PHASE_A_CED, state 1
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Starting answer mode
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Changing from phase T30_PHASE_A_CED to T30_PHASE_B_TX
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW FAX Set rx type 0
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW FAX Set tx type 4
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Start T2
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Changing from state 1 to 17
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Sending ident 'unknown'
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Tx: CSI without final frame tag
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Tx: ff 03 40 6e 77 6f 6e 6b 6e 75 20 20 20 20 20 20 20 20 20 20 20 20 20
[2020-03-18 12:31:43] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' fax session '9', [ 002.820366 ], stack sent 130 frames (2600 ms) of energy.
[2020-03-18 12:31:43] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' fax session '9', [ 002.880307 ], stack sent 3 frames (60 ms) of silence.
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 DIS:
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... 0...= 3G mobile network: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ..0. ....= V.8 capabilities: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .0.. ....= Preferred octets: 256 octets
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...0= Ready to transmit a fax document (polling): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..1.= Can receive fax: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ..10 11..= Supported data signalling rates: V.27 ter, V.29, and V.17
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= 2-D coding: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..00= Recording width: 215mm +- 1%
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... 10..= Recording length: Unlimited
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .111 ....= Receiver's minimum scan line time: 0ms at 3.85 l/mm; T7.7 = T3.85
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= Extension indicator: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .1..= Error correction mode (ECM): ECM
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .1.. ....= T.6 coding: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= Extension indicator: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...0= "Field not valid" supported: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..0.= Multiple selective polling: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .0..= Polled sub-address: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... 0...= T.43 coding: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ...0 ....= Plane interleave: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .0.. ....= Reserved for the use of extended voice coding set: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= Extension indicator: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...1= R8x15.4lines/mm: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..0.= 300x300pels/25.4mm: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .0..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... 0...= Inch-based resolution preferred: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ...1 ....= Metric-based resolution preferred: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .0.. ....= Selective polling: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= Extension indicator: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...0= Sub-addressing: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..0.= Password: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .0..= Ready to transmit a data file (polling): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ...0 ....= Binary file transfer (BFT): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ..0. ....= Document transfer mode (DTM): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .0.. ....= Electronic data interchange (EDI): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= Extension indicator: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...0= Basic transfer mode (BTM): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .0..= Ready to transfer a character or mixed mode document (polling): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... 0...= Character mode: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ..0. ....= Mixed mode (Annex E/T.4): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= Extension indicator: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...0= Processable mode 26 (Rec. T.505): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..0.= Digital network capability: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .0..= Duplex capability: Half only
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... 0...= JPEG coding: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ...0 ....= Full colour mode: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .0.. ....= 12bits/pel component: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= Extension indicator: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...0= No subsampling (1:1:1): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..0.= Custom illuminant: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .0..= Custom gamut range: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... 1...= North American Letter (215.9mm x 279.4mm): Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ...1 ....= North American Legal (215.9mm x 355.6mm): Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ..0. ....= Single-progression sequential coding (Rec. T.85) basic: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .0.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 0... ....= Extension indicator: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Tx: DIS with final frame tag
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Tx: ff 13 80 00 ee f8 c4 80 91 80 80 80 18
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Changing from phase T30_PHASE_B_TX to T30_PHASE_B_RX
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW FAX Set rx type 4
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW FAX Set tx type 0
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Start T4
[2020-03-18 12:31:45] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' fax session '9', [ 004.960186 ], stack sent 104 frames (2080 ms) of energy.
[2020-03-18 12:31:47] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' fax session '9', [ 006.713127 ], channel sent 203 frames (4060 ms) of silence.
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 HDLC signal status is Carrier up (-2) in state 17
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 HDLC signal status is Framing OK (-6) in state 17
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Start T4A
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Changing from state 17 to 32
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Changing from phase T30_PHASE_B_RX to T30_PHASE_CALL_FINISHED
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW FAX Set rx type 9
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW FAX FAX exchange complete
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW FAX Set tx type 9
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW FAX FAX exchange complete
[2020-03-18 12:31:47] VERBOSE[30431][C-000087c1] app_macro.c: Spawn extension (macro-infax, s, 12) exited non-zero on 'PJSIP/RTK_E1_pjsip-00028350' in macro 'infax'
[2020-03-18 12:31:47] VERBOSE[30431][C-000087c1] bridge_channel.c: Channel PJSIP/RTK_E1_pjsip-00028350 left 'simple_bridge' basic-bridge <d330ca43-19ff-48dd-b9e9-8ebd58973366>
[2020-03-18 12:31:47] VERBOSE[30431][C-000087c1] app_macro.c: Spawn extension (macro-dial-one, s, 54) exited non-zero on 'PJSIP/RTK_E1_pjsip-00028350' in macro 'dial-one'
[2020-03-18 12:31:47] VERBOSE[30431][C-000087c1] app_macro.c: Spawn extension (macro-exten-vm, s, 27) exited non-zero on 'PJSIP/RTK_E1_pjsip-00028350' in macro 'exten-vm'
[2020-03-18 12:31:47] VERBOSE[30431][C-000087c1] pbx.c: Spawn extension (ext-local, 4900, 2) exited non-zero on 'PJSIP/RTK_E1_pjsip-00028350'
[2020-03-18 12:31:47] VERBOSE[30431][C-000087c1] pbx.c: Executing [h@ext-local:1] Macro("PJSIP/RTK_E1_pjsip-00028350", "hangupcall,") in new stack
[2020-03-18 12:31:36] VERBOSE[30431][C-000087c1] bridge_channel.c: Channel PJSIP/RTK_E1_pjsip-00028350 joined 'simple_bridge' basic-bridge <d330ca43-19ff-48dd-b9e9-8ebd58973366>
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF begin '*' received on PJSIP/4900-00028351
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF begin passthrough '*' on PJSIP/4900-00028351
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF end '*' received on PJSIP/4900-00028351, duration 90 ms
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF end accepted with begin '*' on PJSIP/4900-00028351
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF end passthrough '*' on PJSIP/4900-00028351
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF begin '6' received on PJSIP/4900-00028351
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF begin passthrough '6' on PJSIP/4900-00028351
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF end '6' received on PJSIP/4900-00028351, duration 90 ms
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF end accepted with begin '6' on PJSIP/4900-00028351
[2020-03-18 12:31:40] DTMF[30440][C-000087c1] channel.c: DTMF end passthrough '6' on PJSIP/4900-00028351
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:1] NoOp("PJSIP/RTK_E1_pjsip-00028350", "------------------- FAX from 89622295574 ------------------") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:2] Answer("PJSIP/RTK_E1_pjsip-00028350", "") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:3] Set("PJSIP/RTK_E1_pjsip-00028350", "__FAXFOLDER=/var/spool/asterisk/fax") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:4] Set("PJSIP/RTK_E1_pjsip-00028350", "DT=20200318-123140-89622295574") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:5] Set("PJSIP/RTK_E1_pjsip-00028350", "FAXOPT(headerinfo)=Received by 89622295574 2020-03-18 12-31") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:6] NoOp("PJSIP/RTK_E1_pjsip-00028350", "FAXOPT(ecm) : yes") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:7] NoOp("PJSIP/RTK_E1_pjsip-00028350", "FAXOPT(headerinfo) : Received by 89622295574 2020-03-18 12-31") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:8] NoOp("PJSIP/RTK_E1_pjsip-00028350", "FAXOPT(localstationid) : ") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:9] NoOp("PJSIP/RTK_E1_pjsip-00028350", "FAXOPT(maxrate) : 14400") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:10] NoOp("PJSIP/RTK_E1_pjsip-00028350", "FAXOPT(minrate) : 9600") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:11] NoOp("PJSIP/RTK_E1_pjsip-00028350", "**** RECEIVING FAX : 20200318-123140-89622295574 ****") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] pbx.c: Executing [s@macro-infax:12] ReceiveFAX("PJSIP/RTK_E1_pjsip-00028350", "/var/spool/asterisk/fax/89622295574.tif,f") in new stack
[2020-03-18 12:31:40] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' receiving FAX '/var/spool/asterisk/fax/89622295574.tif'
[2020-03-18 12:31:41] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' fax session '9', [ 000.220307 ], stack sent 10 frames (200 ms) of silence.
[2020-03-18 12:31:43] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' fax session '9', [ 002.093318 ], channel sent 104 frames (2080 ms) of silence.
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 HDLC signal status is Carrier up (-2) in state 1
[2020-03-18 12:31:43] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' fax session '9', [ 002.592961 ], channel sent 25 frames (500 ms) of energy.
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 HDLC signal status is Carrier down (-1) in state 1
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Send complete in phase T30_PHASE_A_CED, state 1
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Starting answer mode
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Changing from phase T30_PHASE_A_CED to T30_PHASE_B_TX
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW FAX Set rx type 0
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW FAX Set tx type 4
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Start T2
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Changing from state 1 to 17
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Sending ident 'unknown'
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Tx: CSI without final frame tag
[2020-03-18 12:31:43] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Tx: ff 03 40 6e 77 6f 6e 6b 6e 75 20 20 20 20 20 20 20 20 20 20 20 20 20
[2020-03-18 12:31:43] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' fax session '9', [ 002.820366 ], stack sent 130 frames (2600 ms) of energy.
[2020-03-18 12:31:43] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' fax session '9', [ 002.880307 ], stack sent 3 frames (60 ms) of silence.
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 DIS:
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... 0...= 3G mobile network: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ..0. ....= V.8 capabilities: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .0.. ....= Preferred octets: 256 octets
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...0= Ready to transmit a fax document (polling): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..1.= Can receive fax: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ..10 11..= Supported data signalling rates: V.27 ter, V.29, and V.17
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= 2-D coding: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..00= Recording width: 215mm +- 1%
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... 10..= Recording length: Unlimited
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .111 ....= Receiver's minimum scan line time: 0ms at 3.85 l/mm; T7.7 = T3.85
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= Extension indicator: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .1..= Error correction mode (ECM): ECM
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .1.. ....= T.6 coding: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= Extension indicator: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...0= "Field not valid" supported: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..0.= Multiple selective polling: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .0..= Polled sub-address: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... 0...= T.43 coding: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ...0 ....= Plane interleave: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .0.. ....= Reserved for the use of extended voice coding set: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= Extension indicator: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...1= R8x15.4lines/mm: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..0.= 300x300pels/25.4mm: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .0..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... 0...= Inch-based resolution preferred: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ...1 ....= Metric-based resolution preferred: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .0.. ....= Selective polling: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= Extension indicator: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...0= Sub-addressing: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..0.= Password: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .0..= Ready to transmit a data file (polling): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ...0 ....= Binary file transfer (BFT): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ..0. ....= Document transfer mode (DTM): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .0.. ....= Electronic data interchange (EDI): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= Extension indicator: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...0= Basic transfer mode (BTM): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .0..= Ready to transfer a character or mixed mode document (polling): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... 0...= Character mode: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ..0. ....= Mixed mode (Annex E/T.4): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= Extension indicator: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...0= Processable mode 26 (Rec. T.505): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..0.= Digital network capability: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .0..= Duplex capability: Half only
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... 0...= JPEG coding: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ...0 ....= Full colour mode: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .0.. ....= 12bits/pel component: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 1... ....= Extension indicator: Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ...0= No subsampling (1:1:1): Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... ..0.= Custom illuminant: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... .0..= Custom gamut range: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .... 1...= North American Letter (215.9mm x 279.4mm): Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ...1 ....= North American Legal (215.9mm x 355.6mm): Set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 ..0. ....= Single-progression sequential coding (Rec. T.85) basic: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 .0.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 0... ....= Extension indicator: Not set
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Tx: DIS with final frame tag
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Tx: ff 13 80 00 ee f8 c4 80 91 80 80 80 18
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Changing from phase T30_PHASE_B_TX to T30_PHASE_B_RX
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW FAX Set rx type 4
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW FAX Set tx type 0
[2020-03-18 12:31:45] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Start T4
[2020-03-18 12:31:45] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' fax session '9', [ 004.960186 ], stack sent 104 frames (2080 ms) of energy.
[2020-03-18 12:31:47] VERBOSE[30431][C-000087c1] res_fax.c: Channel 'PJSIP/RTK_E1_pjsip-00028350' fax session '9', [ 006.713127 ], channel sent 203 frames (4060 ms) of silence.
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 HDLC signal status is Carrier up (-2) in state 17
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 HDLC signal status is Framing OK (-6) in state 17
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Start T4A
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Changing from state 17 to 32
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW T.30 Changing from phase T30_PHASE_B_RX to T30_PHASE_CALL_FINISHED
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW FAX Set rx type 9
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW FAX FAX exchange complete
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW FAX Set tx type 9
[2020-03-18 12:31:47] FAX[30431][C-000087c1] res_fax.c: FLOW FAX FAX exchange complete
[2020-03-18 12:31:47] VERBOSE[30431][C-000087c1] app_macro.c: Spawn extension (macro-infax, s, 12) exited non-zero on 'PJSIP/RTK_E1_pjsip-00028350' in macro 'infax'
[2020-03-18 12:31:47] VERBOSE[30431][C-000087c1] bridge_channel.c: Channel PJSIP/RTK_E1_pjsip-00028350 left 'simple_bridge' basic-bridge <d330ca43-19ff-48dd-b9e9-8ebd58973366>
[2020-03-18 12:31:47] VERBOSE[30431][C-000087c1] app_macro.c: Spawn extension (macro-dial-one, s, 54) exited non-zero on 'PJSIP/RTK_E1_pjsip-00028350' in macro 'dial-one'
[2020-03-18 12:31:47] VERBOSE[30431][C-000087c1] app_macro.c: Spawn extension (macro-exten-vm, s, 27) exited non-zero on 'PJSIP/RTK_E1_pjsip-00028350' in macro 'exten-vm'
[2020-03-18 12:31:47] VERBOSE[30431][C-000087c1] pbx.c: Spawn extension (ext-local, 4900, 2) exited non-zero on 'PJSIP/RTK_E1_pjsip-00028350'
[2020-03-18 12:31:47] VERBOSE[30431][C-000087c1] pbx.c: Executing [h@ext-local:1] Macro("PJSIP/RTK_E1_pjsip-00028350", "hangupcall,") in new stack