 HylaFAX The world's
most advanced open source fax server
|
[Date Prev][Date Next][Thread Prev][Thread Next] [Date Index] [Thread Index]
[hylafax-users] T.38 / T.30 handshake problems
- To: hylafax-users@xxxxxxxxxxx
- Subject: [hylafax-users] T.38 / T.30 handshake problems
- From: "Atis Lezdins" <atis@xxxxxxxxxxx>
- Date: Fri, 1 Aug 2008 13:30:30 +0300
Hello,
I've been trying connecting Hylafax+ -> T38modem/OPAL -> Asterisk ->
VoIP provider -> PRI -> Asterisk -> IAXmodem -> Hylafax. Provider's
switch claims to support T.38, however i cannot send anything trough
it.
Connection is established, however if i send fax to regular phone, i
don't hear any sound. I've debugged this with provider, they sent me
their wireshark captures. I can see that there is some kind of NAT
involved, they are doing captures behind it, but that probably should
be ok. Of course dialing trough with u-law codec works fine.
There is some things that confuse me. In wireshark graph i can see
that there is sent "ced" , followed by v21 preamble and CSI num,
however i receive "ced" twice, and then Hylafax/T38modem replays with
"no signal".
So, is this handshake ok?
Any help or ideas would be appreciated.
Below are logs from Hylafax, and attachments are wireshark graphs.
(Real IP's and phone numbers are masked)
Regards,
Atis
Sender:
Jul 30 14:37:34.31: [ 4742]: SESSION BEGIN 000000006 14151111111
Jul 30 14:37:34.31: [ 4742]: HylaFAX (tm) Version 5.2.5
Jul 30 14:37:34.31: [ 4742]: SEND FAX: JOB 2 DEST 14151111111 COMMID
000000006 DEVICE '/dev/ttyT38-1' FROM 'a.lezdinsh
<a.lezdinsh@xxxxxxxxx>' USER root
Jul 30 14:37:34.31: [ 4742]: STATE CHANGE: RUNNING -> SENDING
Jul 30 14:37:34.31: [ 4742]: <-- [12:AT+FCLASS=1\r]
Jul 30 14:37:34.31: [ 4742]: --> [2:OK]
Jul 30 14:37:34.32: [ 4742]: DIAL 14151111111
Jul 30 14:37:34.32: [ 4742]: <-- [16:ATDT14151111111\r]
Jul 30 14:37:38.91: [ 4742]: --> [7:CONNECT]
Jul 30 14:37:41.47: [ 4742]: --> HDLC<25:FF C0 02 B6 A6 26 F6 B6 1A 82
92 04 04 04 04 04 04 04 04 04 04 04 04 2A 64>
Jul 30 14:37:41.47: [ 4742]: --> [2:OK]
Jul 30 14:37:41.47: [ 4742]: REMOTE CSI "IAXmodem"
Jul 30 14:37:41.47: [ 4742]: <-- [9:AT+FRH=3\r]
Jul 30 14:37:41.47: [ 4742]: --> [7:CONNECT]
Jul 30 14:37:41.47: [ 4742]: --> [10:NO CARRIER]
Jul 30 14:37:41.47: [ 4742]: MODEM No carrier
Jul 30 14:37:41.47: [ 4742]: <-- [10:AT+FRS=21\r]
Jul 30 14:37:41.69: [ 4742]: --> [2:OK]
Jul 30 14:37:41.69: [ 4742]: <-- [9:AT+FTH=3\r]
Jul 30 14:37:41.69: [ 4742]: --> [7:CONNECT]
Jul 30 14:37:41.69: [ 4742]: <-- HDLC<3:FF C8 D8>
Jul 30 14:37:41.69: [ 4742]: <-- data [3]
Jul 30 14:37:41.69: [ 4742]: <-- data [2]
Jul 30 14:37:42.79: [ 4742]: --> [2:OK]
Jul 30 14:37:42.79: [ 4742]: SEND send CRP (command repeat)
Jul 30 14:37:42.79: [ 4742]: <-- [9:AT+FRH=3\r]
Jul 30 14:37:45.88: [ 4742]: --> [7:CONNECT]
Jul 30 14:37:55.88: [ 4742]: MODEM TIMEOUT: receiving HDLC frame data
Jul 30 14:37:55.88: [ 4742]: <-- data [1]
Jul 30 14:37:55.88: [ 4742]: --> [2:OK]
Jul 30 14:37:55.88: [ 4742]: <-- [9:AT+FRS=7\r]
Jul 30 14:37:55.95: [ 4742]: --> [2:OK]
Jul 30 14:37:55.95: [ 4742]: <-- [9:AT+FRH=3\r]
Jul 30 14:38:01.11: [ 4742]: --> [7:CONNECT]
Jul 30 14:38:11.11: [ 4742]: MODEM TIMEOUT: receiving HDLC frame data
Jul 30 14:38:11.11: [ 4742]: <-- data [1]
Jul 30 14:38:11.11: [ 4742]: --> [2:OK]
Jul 30 14:38:11.11: [ 4742]: <-- [9:AT+FRS=7\r]
Jul 30 14:38:11.18: [ 4742]: --> [2:OK]
Jul 30 14:38:11.18: [ 4742]: <-- [9:AT+FRH=3\r]
Jul 30 14:38:16.35: [ 4742]: --> [7:CONNECT]
Jul 30 14:38:26.35: [ 4742]: MODEM TIMEOUT: receiving HDLC frame data
Jul 30 14:38:26.35: [ 4742]: <-- data [1]
Jul 30 14:38:26.35: [ 4742]: --> [5:ERROR]
Jul 30 14:38:26.35: [ 4742]: MODEM Command error
Jul 30 14:38:26.35: [ 4742]: No receiver protocol (T.30 T1 timeout) {E126}
Jul 30 14:38:26.35: [ 4742]: SEND FAILED: JOB 2 DEST 14151111111 ERR
No receiver protocol (T.30 T1 timeout) {E126}
Jul 30 14:38:26.35: [ 4742]: <-- [9:AT+FRS=7\r]
Jul 30 14:38:26.42: [ 4742]: --> [2:OK]
Jul 30 14:38:26.42: [ 4742]: <-- [9:AT+FTH=3\r]
Jul 30 14:38:26.42: [ 4742]: --> [7:CONNECT]
Jul 30 14:38:26.42: [ 4742]: <-- HDLC<3:FF C8 DF>
Jul 30 14:38:26.42: [ 4742]: <-- data [3]
Jul 30 14:38:26.42: [ 4742]: <-- data [2]
Jul 30 14:38:27.51: [ 4742]: --> [2:OK]
Jul 30 14:38:27.51: [ 4742]: MODEM input buffering enabled
Jul 30 14:38:28.51: [ 4742]: <-- [5:ATH0\r]
Jul 30 14:38:28.62: [ 4742]: --> [2:OK]
Jul 30 14:38:28.62: [ 4742]: MODEM set DTR OFF
Jul 30 14:38:28.62: [ 4742]: MODEM set baud rate: 0 baud (flow control
unchanged)
Jul 30 14:38:28.62: [ 4742]: STATE CHANGE: SENDING -> MODEMWAIT (timeout 5)
Jul 30 14:38:28.62: [ 4742]: SESSION END
Receiver:
Jul 31 10:45:54.88: [ 3884]: SESSION BEGIN 000019442 1212
Jul 31 10:45:54.88: [ 3884]: HylaFAX (tm) Version 5.2.2
Jul 31 10:45:54.88: [ 3884]: CallID: '' '1217526354.6738' '<NONE>' '21168'
Jul 31 10:45:54.88: [ 3884]: MODEM set XON/XOFF/FLUSH: input ignored,
output disabled
Jul 31 10:45:54.88: [ 3884]: <-- [4:ATA\r]
Jul 31 10:45:58.60: [ 3884]: --> [7:CONNECT]
Jul 31 10:45:58.60: [ 3884]: ANSWER: FAX CONNECTION DEVICE '/dev/ttyIAX1'
Jul 31 10:45:58.60: [ 3884]: STATE CHANGE: ANSWERING -> RECEIVING
Jul 31 10:45:58.60: [ 3884]: RECV FAX: begin
Jul 31 10:45:58.60: [ 3884]: <-- HDLC<32:FF C0 04 B5 00 AA 12 9E 36 86
62 82 1A 04 14 2E B6 94 04 6A A6 4E CE 96 F6 76 04 AC 74 4C 74 4C>
Jul 31 10:45:58.60: [ 3884]: <-- data [32]
Jul 31 10:45:58.60: [ 3884]: <-- data [2]
Jul 31 10:45:59.56: [ 3884]: --> [7:CONNECT]
Jul 31 10:45:59.56: [ 3884]: <-- HDLC<23:FF C0 02 B6 A6 26 F6 B6 1A 82
92 04 04 04 04 04 04 04 04 04 04 04 04>
Jul 31 10:45:59.56: [ 3884]: <-- data [23]
Jul 31 10:45:59.56: [ 3884]: <-- data [2]
Jul 31 10:46:00.30: [ 3884]: --> [7:CONNECT]
Jul 31 10:46:00.30: [ 3884]: <-- HDLC<13:FF C8 01 00 73 5F 23 01 FB C1 01 01 18>
Jul 31 10:46:00.30: [ 3884]: <-- data [13]
Jul 31 10:46:00.30: [ 3884]: <-- data [2]
Jul 31 10:46:00.88: [ 3884]: --> [2:OK]
Jul 31 10:46:00.88: [ 3884]: <-- [9:AT+FRH=3\r]
Jul 31 10:46:01.20: [ 3884]: --> [7:CONNECT]
Jul 31 10:46:04.48: [ 3884]: --> [10:NO CARRIER]
Jul 31 10:46:04.48: [ 3884]: MODEM No carrier
Jul 31 10:46:04.48: [ 3884]: <-- [10:AT+FRS=21\r]
Jul 31 10:46:04.68: [ 3884]: --> [2:OK]
Jul 31 10:46:04.68: [ 3884]: <-- [9:AT+FTH=3\r]
Jul 31 10:46:04.70: [ 3884]: --> [7:CONNECT]
Jul 31 10:46:04.70: [ 3884]: <-- HDLC<3:FF C8 58>
Jul 31 10:46:04.70: [ 3884]: <-- data [3]
Jul 31 10:46:04.70: [ 3884]: <-- data [2]
Jul 31 10:46:05.78: [ 3884]: --> [2:OK]
Jul 31 10:46:05.78: [ 3884]: RECV send CRP (command repeat)
Jul 31 10:46:05.78: [ 3884]: <-- [9:AT+FRH=3\r]
Jul 31 10:46:12.78: [ 3884]: --> [0:]
Jul 31 10:46:12.78: [ 3884]: MODEM <Empty line>
Jul 31 10:46:12.78: [ 3884]: MODEM TIMEOUT: waiting for v.21 carrier
Jul 31 10:46:12.78: [ 3884]: <-- data [1]
Jul 31 10:46:12.80: [ 3884]: --> [2:OK]
Jul 31 10:46:12.80: [ 3884]: <-- [9:AT+FRS=7\r]
Jul 31 10:46:12.82: [ 3884]: --> [2:OK]
Jul 31 10:46:12.82: [ 3884]: <-- [9:AT+FTH=3\r]
Jul 31 10:46:12.84: [ 3884]: --> [7:CONNECT]
Jul 31 10:46:12.84: [ 3884]: <-- HDLC<32:FF C0 04 B5 00 AA 12 9E 36 86
62 82 1A 04 14 2E B6 94 04 6A A6 4E CE 96 F6 76 04 AC 74 4C 74 4C>
Jul 31 10:46:12.84: [ 3884]: <-- data [32]
Jul 31 10:46:12.84: [ 3884]: <-- data [2]
Jul 31 10:46:14.62: [ 3884]: --> [7:CONNECT]
Jul 31 10:46:14.62: [ 3884]: <-- HDLC<23:FF C0 02 B6 A6 26 F6 B6 1A 82
92 04 04 04 04 04 04 04 04 04 04 04 04>
Jul 31 10:46:14.62: [ 3884]: <-- data [23]
Jul 31 10:46:14.62: [ 3884]: <-- data [2]
Jul 31 10:46:15.36: [ 3884]: --> [7:CONNECT]
Jul 31 10:46:15.36: [ 3884]: <-- HDLC<13:FF C8 01 00 73 5F 23 01 FB C1 01 01 18>
Jul 31 10:46:15.36: [ 3884]: <-- data [13]
Jul 31 10:46:15.36: [ 3884]: <-- data [2]
Jul 31 10:46:15.94: [ 3884]: --> [2:OK]
Jul 31 10:46:15.94: [ 3884]: <-- [9:AT+FRH=3\r]
Jul 31 10:46:17.90: [ 3884]: --> [7:CONNECT]
Jul 31 10:46:19.66: [ 3884]: --> [10:NO CARRIER]
Jul 31 10:46:19.66: [ 3884]: MODEM No carrier
Jul 31 10:46:19.66: [ 3884]: <-- [10:AT+FRS=21\r]
Jul 31 10:46:19.86: [ 3884]: --> [2:OK]
Jul 31 10:46:19.86: [ 3884]: <-- [9:AT+FTH=3\r]
Jul 31 10:46:19.88: [ 3884]: --> [7:CONNECT]
Jul 31 10:46:19.88: [ 3884]: <-- HDLC<3:FF C8 58>
Jul 31 10:46:19.88: [ 3884]: <-- data [3]
Jul 31 10:46:19.88: [ 3884]: <-- data [2]
Jul 31 10:46:20.96: [ 3884]: --> [2:OK]
Jul 31 10:46:20.96: [ 3884]: RECV send CRP (command repeat)
Jul 31 10:46:20.96: [ 3884]: <-- [9:AT+FRH=3\r]
Jul 31 10:46:27.96: [ 3884]: --> [0:]
Jul 31 10:46:27.96: [ 3884]: MODEM <Empty line>
Jul 31 10:46:27.96: [ 3884]: MODEM TIMEOUT: waiting for v.21 carrier
Jul 31 10:46:27.96: [ 3884]: <-- data [1]
Jul 31 10:46:27.98: [ 3884]: --> [2:OK]
Jul 31 10:46:27.98: [ 3884]: <-- [9:AT+FRS=7\r]
Jul 31 10:46:28.00: [ 3884]: --> [2:OK]
Jul 31 10:46:28.00: [ 3884]: <-- [9:AT+FTH=3\r]
Jul 31 10:46:28.02: [ 3884]: --> [7:CONNECT]
Jul 31 10:46:28.02: [ 3884]: <-- HDLC<32:FF C0 04 B5 00 AA 12 9E 36 86
62 82 1A 04 14 2E B6 94 04 6A A6 4E CE 96 F6 76 04 AC 74 4C 74 4C>
Jul 31 10:46:28.02: [ 3884]: <-- data [32]
Jul 31 10:46:28.02: [ 3884]: <-- data [2]
Jul 31 10:46:29.80: [ 3884]: --> [7:CONNECT]
Jul 31 10:46:29.80: [ 3884]: <-- HDLC<23:FF C0 02 B6 A6 26 F6 B6 1A 82
92 04 04 04 04 04 04 04 04 04 04 04 04>
Jul 31 10:46:29.80: [ 3884]: <-- data [23]
Jul 31 10:46:29.80: [ 3884]: <-- data [2]
Jul 31 10:46:30.54: [ 3884]: --> [7:CONNECT]
Jul 31 10:46:30.54: [ 3884]: <-- HDLC<13:FF C8 01 00 73 5F 23 01 FB C1 01 01 18>
Jul 31 10:46:30.54: [ 3884]: <-- data [13]
Jul 31 10:46:30.54: [ 3884]: <-- data [2]
Jul 31 10:46:31.12: [ 3884]: --> [2:OK]
Jul 31 10:46:31.12: [ 3884]: <-- [9:AT+FRH=3\r]
Jul 31 10:46:33.06: [ 3884]: --> [7:CONNECT]
Jul 31 10:46:34.84: [ 3884]: --> [10:NO CARRIER]
Jul 31 10:46:34.84: [ 3884]: MODEM No carrier
Jul 31 10:46:34.84: [ 3884]: <-- [10:AT+FRS=21\r]
Jul 31 10:46:35.04: [ 3884]: --> [2:OK]
Jul 31 10:46:35.04: [ 3884]: <-- [9:AT+FTH=3\r]
Jul 31 10:46:35.06: [ 3884]: --> [7:CONNECT]
Jul 31 10:46:35.06: [ 3884]: <-- HDLC<3:FF C8 58>
Jul 31 10:46:35.06: [ 3884]: <-- data [3]
Jul 31 10:46:35.06: [ 3884]: <-- data [2]
Jul 31 10:46:36.14: [ 3884]: --> [2:OK]
Jul 31 10:46:36.14: [ 3884]: RECV send CRP (command repeat)
Jul 31 10:46:36.14: [ 3884]: <-- [9:AT+FRH=3\r]
Jul 31 10:46:43.15: [ 3884]: --> [0:]
Jul 31 10:46:43.15: [ 3884]: MODEM <Empty line>
Jul 31 10:46:43.15: [ 3884]: MODEM TIMEOUT: waiting for v.21 carrier
Jul 31 10:46:43.15: [ 3884]: <-- data [1]
Jul 31 10:46:43.16: [ 3884]: --> [2:OK]
Jul 31 10:46:43.16: [ 3884]: RECV FAX: No sender protocol (T.30 T1
timeout) {E102}
Jul 31 10:46:43.16: [ 3884]: RECV FAX: end
Jul 31 10:46:43.16: [ 3884]: No sender protocol (T.30 T1 timeout) {E102}
Jul 31 10:46:43.16: [ 3884]: SESSION END
--
Atis Lezdins,
VoIP Project Manager / Developer,
atis@xxxxxxxxxxx
Skype: atis.lezdins
Cell Phone: +371 28806004
Cell Phone: +1 800 7300689
Work phone: +1 800 7502835
|Time | xxx.xxx.xxx.xxx | yyy.yy.yyy.yyy | |14,923 | INVITE SDP ( t38) |SIP From: sip:8001111111@xxxxxxxxxxxxxxx To:sip:14151111111@xxxxxxxxxxxxxx | |(5060) ------------------> (5060) | |15,128 | 100 Trying| |SIP Status | |(5060) <------------------ (5060) | |17,136 | 180 Ringing |SIP Status | |(5060) <------------------ (5060) | |17,380 | 200 OK SDP ( t38) |SIP Status | |(5060) <------------------ (5060) | |17,381 | ACK | |SIP Request | |(5060) ------------------> (5060) | |17,861 | ced | |t38:t30 Ind:ced | |(4655) <------------------ (10562) | |18,371 | ced | |t38:t30 Ind:ced | |(4655) <------------------ (10562) | |19,501 | v21-preamble |t38:t30 Ind:v21-preamble | |(4655) <------------------ (10562) | |22,061 | CSI Num: IAXmodem |t38:v21:HDLC:Called Subscriber Identification | |(4655) <------------------ (10562) | |22,282 | v21-preamble |t38:t30 Ind:v21-preamble | |(4655) ------------------> (10562) | |22,561 | DIS DSR:ITU-T V.27 ter and V.29 |t38:v21:HDLC:Digital Identification Signal | |(4655) <------------------ (10562) | |23,414 | no-signal | |t38:t30 Ind:no-signal | |(4655) ------------------> (10562) | |26,470 | v21-preamble |t38:t30 Ind:v21-preamble | |(4655) <------------------ (10562) | |34,609 | v21-preamble |t38:t30 Ind:v21-preamble | |(4655) <------------------ (10562) | |37,138 | CSI Num: IAXmodem |t38:v21:HDLC:Called Subscriber Identification | |(4655) <------------------ (10562) | |37,628 | DIS DSR:ITU-T V.27 ter and V.29 |t38:v21:HDLC:Digital Identification Signal | |(4655) <------------------ (10562) | |41,697 | v21-preamble |t38:t30 Ind:v21-preamble | |(4655) <------------------ (10562) | |49,836 | v21-preamble |t38:t30 Ind:v21-preamble | |(4655) <------------------ (10562) | |52,366 | CSI Num: IAXmodem |t38:v21:HDLC:Called Subscriber Identification | |(4655) <------------------ (10562) | |52,865 | DIS DSR:ITU-T V.27 ter and V.29 |t38:v21:HDLC:Digital Identification Signal | |(4655) <------------------ (10562) | |56,935 | v21-preamble |t38:t30 Ind:v21-preamble | |(4655) <------------------ (10562) | |66,403 | ced | |t38:t30 Ind:ced | |(4655) <------------------ (10562) | |67,006 | v21-preamble |t38:t30 Ind:v21-preamble | |(4655) ------------------> (10562) | |68,137 | no-signal | |t38:t30 Ind:no-signal | |(4655) ------------------> (10562) | |69,083 | v21-preamble |t38:t30 Ind:v21-preamble | |(4655) <------------------ (10562) | |69,105 | BYE | |SIP Request | |(5060) ------------------> (5060) | |69,473 | 200 OK | |SIP Status | |(5060) <------------------ (5060) |
|Time | 192.168.34.152 | 192.168.32.19 | 192.168.33.10 | |0,000 | INVITE SDP ( t38) | |SIP From: sip:8001111111-cpy-name-peer-juojuucsegnfc@xxxxxxxxxxxxxx To:sip:14151111111@xxxxxxxxxxxxx | |(5060) ------------------> (5060) | | |0,002 | 100 Trying| | |SIP Status | |(5060) <------------------ (5060) | | |1,977 | 180 Ringing | |SIP Status | |(5060) <------------------ (5060) | | |2,215 | 200 OK SDP ( t38) | |SIP Status | |(5060) <------------------ (5060) | | |2,441 | ACK | | |SIP Request | |(5060) ------------------> (5060) | | |2,714 | ced | | |t38:t30 Ind:ced | |(10562) <-------------------------------------- (14276) | |4,354 | v21-preamble | |t38:t30 Ind:v21-preamble | |(10562) <-------------------------------------- (14276) | |6,912 | CSI Num: IAXmodem | |t38:v21:HDLC:Called Subscriber Identification | |(10562) <-------------------------------------- (14276) | |7,409 | DIS DSR:ITU-T V.27 ter and V.29 |t38:v21:HDLC:Digital Identification Signal | |(10562) <-------------------------------------- (14276) | |8,464 | no-signal | | |t38:t30 Ind:no-signal | |(10562) --------------------------------------> (14276) | |11,324 | v21-preamble | |t38:t30 Ind:v21-preamble | |(10562) <-------------------------------------- (14276) | |21,994 | CSI Num: IAXmodem | |t38:v21:HDLC:Called Subscriber Identification | |(10562) <-------------------------------------- (14276) | |26,554 | v21-preamble | |t38:t30 Ind:v21-preamble | |(10562) <-------------------------------------- (14276) | |34,692 | v21-preamble | |t38:t30 Ind:v21-preamble | |(10562) <-------------------------------------- (14276) | |37,217 | CSI Num: IAXmodem | |t38:v21:HDLC:Called Subscriber Identification | |(10562) <-------------------------------------- (14276) | |37,722 | DIS DSR:ITU-T V.27 ter and V.29 |t38:v21:HDLC:Digital Identification Signal | |(10562) <-------------------------------------- (14276) | |41,791 | v21-preamble | |t38:t30 Ind:v21-preamble | |(10562) <-------------------------------------- (14276) | |52,061 | v21-preamble | |t38:t30 Ind:v21-preamble | |(10562) --------------------------------------> (14276) | |53,192 | no-signal | | |t38:t30 Ind:no-signal | |(10562) --------------------------------------> (14276) | |54,173 | BYE | | |SIP Request | |(5060) ------------------> (5060) | |
- Follow-Ups:
- [hylafax-users] T.38 / T.30 handshake problems
- From: Atis Lezdins
- Re: [hylafax-users] T.38 / T.30 handshake problems
- From: Lee Howard
- [hylafax-users] T.38 / T.30 handshake problems
- Prev by Date: Re: [hylafax-users] Modem Priority
- Next by Date: Re: [hylafax-users] Modem Priority
- Previous by thread: Re: [hylafax-users] Modem Priority
- Next by thread: [hylafax-users] T.38 / T.30 handshake problems
- Index(es):
Project hosted by iFAX Solutions