Hi all,
I'm trying to setup asterisk and spandsp to recieve fax transmissions. I
got Asterisk to detect fax calls, it even tries to communicate, but the
other side doesn't seem to send the main data. Instead it ends the
communication with hangup. Have anybody got an idea?
Thanks a lot.
Jan Fousek
This is a relevant part of the log:
Jul 18 19:58:30 VERBOSE[20671] logger.c: -- Executing
Answer("SIP/420543254384-b5dd", "") in new stack
Jul 18 19:58:30 VERBOSE[20671] logger.c: -- Executing
AbsoluteTimeout("SIP/420543254384-b5dd", "35") in new stack
Jul 18 19:58:30 VERBOSE[20671] logger.c: -- Set Absolute Timeout to 35
Jul 18 19:58:30 VERBOSE[20671] logger.c: -- Executing
Set("SIP/420543254384-b5dd",
"FAXFILE=/var/spool/asterisk-fax/1153245510.15.tif") in new stack
Jul 18 19:58:30 VERBOSE[20671] logger.c: -- Executing
RxFAX("SIP/420543254384-b5dd",
"/var/spool/asterisk-fax/1153245510.15.tif|debug") in new stack
Jul 18 19:58:30 DEBUG[31032] chan_sip.c: Stopping retransmission on
'BW195830538180706-1588437227@193.138.78.20' of Response 23395782: Match
Found
Jul 18 19:58:32 DEBUG[31032] chan_sip.c: Auto destroying call
'75243e2746f654975f4d37b743f9bd7c@127.0.0.1'
Jul 18 19:58:33 DEBUG[31032] chan_sip.c: Auto destroying call
'08623a2019baf62e4ae8d7781e24d8b1@127.0.0.1'
Jul 18 19:58:33 DEBUG[20671] app_rxfax.c: FLOW Changed from phase 1 to 4
Jul 18 19:58:33 DEBUG[20671] app_rxfax.c: FLOW >>> DIS:Jul 18 19:58:33
DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:33 DEBUG[20671] app_rxfax.c: 00Jul 18
19:58:33 DEBUG[20671] app_rxfax.c: ceJul 18 19:58:33 DEBUG[20671] app_rxfax.c:
f4Jul 18 19:58:33 DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:33 DEBUG[20671]
app_rxfax.c: 80Jul 18 19:58:33 DEBUG[20671] app_rxfax.c: 81Jul 18 19:58:33
DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:33 DEBUG[20671] app_rxfax.c: 80Jul 18
19:58:33 DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:33 DEBUG[20671] app_rxfax.c:
18Jul 18 19:58:33 DEBUG[20671] app_rxfax.c:
Jul 18 19:58:35 DEBUG[20671] app_rxfax.c: FLOW HDLC underflow in state 9
Jul 18 19:58:35 DEBUG[20671] app_rxfax.c: FLOW Changed from phase 4 to 3
Jul 18 19:58:36 DEBUG[20671] app_rxfax.c: FLOW HDLC carrier up
Jul 18 19:58:36 DEBUG[20671] app_rxfax.c: FLOW HDLC framing OK
Jul 18 19:58:37 DEBUG[20671] app_rxfax.c: FLOW <<< ???:Jul 18 19:58:37
DEBUG[20671] app_rxfax.c: 1aJul 18 19:58:37 DEBUG[20671] app_rxfax.c:
Jul 18 19:58:37 DEBUG[20671] app_rxfax.c: FLOW ??? with final frame tag
Jul 18 19:58:37 DEBUG[20671] app_rxfax.c: FLOW In state 9
Jul 18 19:58:37 DEBUG[20671] app_rxfax.c: FLOW HDLC carrier down
Jul 18 19:58:38 DEBUG[20671] app_rxfax.c: FLOW T4 timeout in state 9
Jul 18 19:58:38 DEBUG[20671] app_rxfax.c: FLOW Changed from phase 3 to 4
Jul 18 19:58:38 DEBUG[20671] app_rxfax.c: FLOW >>> DIS:Jul 18 19:58:38
DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:38 DEBUG[20671] app_rxfax.c: 00Jul 18
19:58:38 DEBUG[20671] app_rxfax.c: ceJul 18 19:58:38 DEBUG[20671] app_rxfax.c:
f4Jul 18 19:58:38 DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:38 DEBUG[20671]
app_rxfax.c: 80Jul 18 19:58:38 DEBUG[20671] app_rxfax.c: 81Jul 18 19:58:38
DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:38 DEBUG[20671] app_rxfax.c: 80Jul 18
19:58:38 DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:38 DEBUG[20671] app_rxfax.c:
18Jul 18 19:58:38 DEBUG[20671] app_rxfax.c:
Jul 18 19:58:40 DEBUG[20671] app_rxfax.c: FLOW HDLC underflow in state 9
Jul 18 19:58:40 DEBUG[20671] app_rxfax.c: FLOW Changed from phase 4 to 3
Jul 18 19:58:43 DEBUG[20671] app_rxfax.c: FLOW T4 timeout in state 9
Jul 18 19:58:43 DEBUG[20671] app_rxfax.c: FLOW Changed from phase 3 to 4
Jul 18 19:58:43 DEBUG[20671] app_rxfax.c: FLOW >>> DIS:Jul 18 19:58:43
DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:43 DEBUG[20671] app_rxfax.c: 00Jul 18
19:58:43 DEBUG[20671] app_rxfax.c: ceJul 18 19:58:43 DEBUG[20671] app_rxfax.c:
f4Jul 18 19:58:43 DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:43 DEBUG[20671]
app_rxfax.c: 80Jul 18 19:58:43 DEBUG[20671] app_rxfax.c: 81Jul 18 19:58:43
DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:43 DEBUG[20671] app_rxfax.c: 80Jul 18
19:58:43 DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:43 DEBUG[20671] app_rxfax.c:
18Jul 18 19:58:43 DEBUG[20671] app_rxfax.c:
Jul 18 19:58:45 DEBUG[20671] app_rxfax.c: FLOW HDLC underflow in state 9
Jul 18 19:58:45 DEBUG[20671] app_rxfax.c: FLOW Changed from phase 4 to 3
Jul 18 19:58:48 DEBUG[20671] app_rxfax.c: FLOW T4 timeout in state 9
Jul 18 19:58:48 DEBUG[20671] app_rxfax.c: FLOW Changed from phase 3 to 4
Jul 18 19:58:48 DEBUG[20671] app_rxfax.c: FLOW >>> DIS:Jul 18 19:58:48
DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:48 DEBUG[20671] app_rxfax.c: 00Jul 18
19:58:48 DEBUG[20671] app_rxfax.c: ceJul 18 19:58:48 DEBUG[20671] app_rxfax.c:
f4Jul 18 19:58:48 DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:48 DEBUG[20671]
app_rxfax.c: 80Jul 18 19:58:48 DEBUG[20671] app_rxfax.c: 81Jul 18 19:58:48
DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:48 DEBUG[20671] app_rxfax.c: 80Jul 18
19:58:48 DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:48 DEBUG[20671] app_rxfax.c:
18Jul 18 19:58:48 DEBUG[20671] app_rxfax.c:
Jul 18 19:58:50 DEBUG[20671] app_rxfax.c: FLOW HDLC underflow in state 9
Jul 18 19:58:50 DEBUG[20671] app_rxfax.c: FLOW Changed from phase 4 to 3
Jul 18 19:58:51 DEBUG[20671] app_rxfax.c: FLOW HDLC carrier up
Jul 18 19:58:51 DEBUG[20671] app_rxfax.c: FLOW HDLC framing OK
Jul 18 19:58:52 DEBUG[20671] app_rxfax.c: FLOW <<< ???:Jul 18 19:58:52
DEBUG[20671] app_rxfax.c: 1aJul 18 19:58:52 DEBUG[20671] app_rxfax.c:
Jul 18 19:58:52 DEBUG[20671] app_rxfax.c: FLOW ??? with final frame tag
Jul 18 19:58:52 DEBUG[20671] app_rxfax.c: FLOW In state 9
Jul 18 19:58:52 DEBUG[20671] app_rxfax.c: FLOW HDLC carrier down
Jul 18 19:58:53 DEBUG[20671] app_rxfax.c: FLOW T4 timeout in state 9
Jul 18 19:58:53 DEBUG[20671] app_rxfax.c: FLOW Changed from phase 3 to 4
Jul 18 19:58:53 DEBUG[20671] app_rxfax.c: FLOW >>> DIS:Jul 18 19:58:53
DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:53 DEBUG[20671] app_rxfax.c: 00Jul 18
19:58:53 DEBUG[20671] app_rxfax.c: ceJul 18 19:58:53 DEBUG[20671] app_rxfax.c:
f4Jul 18 19:58:53 DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:53 DEBUG[20671]
app_rxfax.c: 80Jul 18 19:58:53 DEBUG[20671] app_rxfax.c: 81Jul 18 19:58:53
DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:53 DEBUG[20671] app_rxfax.c: 80Jul 18
19:58:53 DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:53 DEBUG[20671] app_rxfax.c:
18Jul 18 19:58:53 DEBUG[20671] app_rxfax.c:
Jul 18 19:58:55 DEBUG[20671] app_rxfax.c: FLOW HDLC underflow in state 9
Jul 18 19:58:55 DEBUG[20671] app_rxfax.c: FLOW Changed from phase 4 to 3
Jul 18 19:58:56 DEBUG[20671] app_rxfax.c: FLOW HDLC carrier up
Jul 18 19:58:56 DEBUG[20671] app_rxfax.c: FLOW HDLC framing OK
Jul 18 19:58:58 DEBUG[20671] app_rxfax.c: FLOW <<< ???:Jul 18 19:58:58
DEBUG[20671] app_rxfax.c: 1aJul 18 19:58:58 DEBUG[20671] app_rxfax.c:
Jul 18 19:58:58 DEBUG[20671] app_rxfax.c: FLOW ??? with final frame tag
Jul 18 19:58:58 DEBUG[20671] app_rxfax.c: FLOW In state 9
Jul 18 19:58:58 DEBUG[20671] app_rxfax.c: FLOW HDLC carrier down
Jul 18 19:58:58 DEBUG[20671] app_rxfax.c: FLOW T4 timeout in state 9
Jul 18 19:58:58 DEBUG[20671] app_rxfax.c: FLOW Changed from phase 3 to 4
Jul 18 19:58:58 DEBUG[20671] app_rxfax.c: FLOW >>> DIS:Jul 18 19:58:58
DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:58 DEBUG[20671] app_rxfax.c: 00Jul 18
19:58:58 DEBUG[20671] app_rxfax.c: ceJul 18 19:58:58 DEBUG[20671] app_rxfax.c:
f4Jul 18 19:58:58 DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:58 DEBUG[20671]
app_rxfax.c: 80Jul 18 19:58:58 DEBUG[20671] app_rxfax.c: 81Jul 18 19:58:58
DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:58 DEBUG[20671] app_rxfax.c: 80Jul 18
19:58:58 DEBUG[20671] app_rxfax.c: 80Jul 18 19:58:58 DEBUG[20671] app_rxfax.c:
18Jul 18 19:58:58 DEBUG[20671] app_rxfax.c:
Jul 18 19:59:01 DEBUG[20671] app_rxfax.c: FLOW HDLC underflow in state 9
Jul 18 19:59:01 DEBUG[20671] app_rxfax.c: FLOW Changed from phase 4 to 3
Jul 18 19:59:04 DEBUG[20671] app_rxfax.c: FLOW T4 timeout in state 9
Jul 18 19:59:04 DEBUG[20671] app_rxfax.c: FLOW Changed from phase 3 to 4
Jul 18 19:59:04 DEBUG[20671] app_rxfax.c: FLOW >>> DIS:Jul 18 19:59:04
DEBUG[20671] app_rxfax.c: 80Jul 18 19:59:04 DEBUG[20671] app_rxfax.c: 00Jul 18
19:59:04 DEBUG[20671] app_rxfax.c: ceJul 18 19:59:04 DEBUG[20671] app_rxfax.c:
f4Jul 18 19:59:04 DEBUG[20671] app_rxfax.c: 80Jul 18 19:59:04 DEBUG[20671]
app_rxfax.c: 80Jul 18 19:59:04 DEBUG[20671] app_rxfax.c: 81Jul 18 19:59:04
DEBUG[20671] app_rxfax.c: 80Jul 18 19:59:04 DEBUG[20671] app_rxfax.c: 80Jul 18
19:59:04 DEBUG[20671] app_rxfax.c: 80Jul 18 19:59:04 DEBUG[20671] app_rxfax.c:
18Jul 18 19:59:04 DEBUG[20671] app_rxfax.c:
Jul 18 19:59:05 DEBUG[20671] app_rxfax.c: Got hangup
Jul 18 19:59:05 DEBUG[20671] pbx.c: Extension s, priority 4 returned normally
even though call was hung up
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is 'unavailable'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is 'unavailable'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is 's'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is 'incomming'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is
'SIP/420543254384-b5dd'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is '(null)'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is 'RxFAX'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is
'/var/spool/asterisk-fax/1153245510.15.tif|debug'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is '2006-07-18
19:58:30'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is '2006-07-18
19:58:30'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is '2006-07-18
19:59:05'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is '35'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is '35'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is 'ANSWERED'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is 'DOCUMENTATION'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is '(null)'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is '1153245510.15'
Jul 18 19:59:05 DEBUG[20671] pbx.c: Function result is '(null)'