Re: [hylafax-users] [Bug 47] RFE: MPSHandlingMethod, EOPHandlingMethod

[Dmitry Bely <dbely@mail.ru>]

Giulio Orsero <giulioo@pobox.com> writes:

> >+ ------- Additional Comments From dbely@mail.ru  2000-09-05 12:24 -------
> >+ 3 tries after "No response to EOP/MPS" during one call? That's impossible.
> Yes, as usual you're right :-)
> I always confuse RTN with EOP and MPS. Sorry.
> 
> However, since I placed the call, here's the log:
> 
> cvs 20000903, linux rh61, you've already told me to ignore the spurious
> XONXOFF. I get the same with another class1 modem which does not do
> weird XONXOFF.
> 
> I only know that the remote machine should be an old Olivetti-something.
> I get 100% MPS with that machine.

Very good -- then we have a chance to fix it :-) BTW, can you tell me its
exact model? I'll add it to the list of known NSFs.

> ===
> Sep 05 18:44:58.31: [28345]: SESSION BEGIN 00000008 39010501238
> Sep 05 18:44:58.31: [28345]: SEND FAX: JOB 21 DEST 0,010-501238 COMMID
> 00000008
> Sep 05 18:44:58.31: [28345]: MODEM set DTR OFF
> Sep 05 18:44:58.31: [28345]: DELAY 2600 ms
> Sep 05 18:45:00.91: [28345]: MODEM set DTR ON
> Sep 05 18:45:00.91: [28345]: MODEM set baud rate: 19200 baud, input flow
> XON/XOFF, output flow XON/XOFF
> Sep 05 18:45:00.91: [28345]: MODEM flush i/o
> Sep 05 18:45:00.91: [28345]: <-- [4:ATZ\r]
> Sep 05 18:45:01.08: [28345]: --> [2:OK]
> Sep 05 18:45:01.08: [28345]: <-- [26:ATE0V1Q0X3S0=0+FCLASS=0H0\r]
> Sep 05 18:45:01.39: [28345]: --> [25:ATE0V1Q0X3S0=0+FCLASS=0H0]
> Sep 05 18:45:01.39: [28345]: --> [2:OK]
> Sep 05 18:45:01.39: [28345]: <-- [21:ATS8=2S7=60&K4&D3&C1\r]
> Sep 05 18:45:01.50: [28345]: --> [2:OK]
> Sep 05 18:45:01.50: [28345]: <-- [12:AT+FCLASS=1\r]
> Sep 05 18:45:01.61: [28345]: --> [2:OK]
> Sep 05 18:45:01.61: [28345]: <-- [5:ATM0\r]
> Sep 05 18:45:01.71: [28345]: --> [2:OK]
> Sep 05 18:45:01.71: [28345]: STATE CHANGE: RUNNING -> SENDING
> Sep 05 18:45:01.71: [28345]: MODEM input buffering enabled
> Sep 05 18:45:01.71: [28345]: <-- [12:AT+FCLASS=1\r]
> Sep 05 18:45:01.93: [28345]: --> [2:OK]
> Sep 05 18:45:01.93: [28345]: MODEM set XON/XOFF/FLUSH: input ignored, output disabled
> Sep 05 18:45:01.93: [28345]: DIAL 0,010501238
> Sep 05 18:45:01.93: [28345]: <-- [17:ATDT0,010501238@\r]
> Sep 05 18:45:24.01: [28345]: --> [7:CONNECT]
> Sep 05 18:45:24.01: [28345]: MODEM input buffering disabled
> Sep 05 18:45:26.92: [28345]: --> HDLC<39:FF C0 04 00 00 8C 00 73 1D 00 E1 B0 BB
> 00 00 BB BB 00 00 BB BB BB BB BB 00 90 A0 40 18 62 10 B7 C6 0D 07 80 80
> 06 F4>
> Sep 05 18:45:26.92: [28345]: --> [2:OK]
> Sep 05 18:45:26.92: [28345]: REMOTE NSF "00 00 31 00 CE B8 00 87 0D DD
> 00 00 DD
> DD 00 00 DD DD DD DD DD 00 09 05 02 18 46 08 ED 63 B0 E0 01 01 60"
> Sep 05 18:45:26.92: [28345]: NSF remote fax equipment: unknown
> Sep 05 18:45:26.92: [28345]: NSF possible remote station ID: "ннннн"
> Sep 05 18:45:26.92: [28345]: <-- [9:AT+FRH=3\r]
> Sep 05 18:45:26.94: [28345]: --> [7:CONNECT]
> Sep 05 18:45:26.95: [28345]: --> HDLC<25:FF C0 02 1C CC 4C 8C 0C AC 0C
> 8C 0C 9C
> CC 04 04 04 04 04 04 04 04 04 DF F1>
> Sep 05 18:45:26.96: [28345]: --> [2:OK]
> Sep 05 18:45:26.96: [28345]: REMOTE CSI "39010501238"
> Sep 05 18:45:26.96: [28345]: <-- [9:AT+FRH=3\r]
> Sep 05 18:45:26.98: [28345]: --> [7:CONNECT]
> Sep 05 18:45:26.98: [28345]: --> HDLC<9:FF C8 01 00 73 1D 00 46 14>
> Sep 05 18:45:26.99: [28345]: --> [2:OK]
> Sep 05 18:45:26.99: [28345]: REMOTE best rate 9600 bit/s
> Sep 05 18:45:26.99: [28345]: REMOTE max page width 1728 pixels in 215 mm
> Sep 05 18:45:26.99: [28345]: REMOTE max unlimited page length
> Sep 05 18:45:26.99: [28345]: REMOTE best vres 7.7 line/mm
> Sep 05 18:45:26.99: [28345]: REMOTE best format 2-D MR
> Sep 05 18:45:26.99: [28345]: REMOTE best 20 ms, 10 ms/scanline
> Sep 05 18:45:26.99: [28345]: USE 9600 bit/s
> Sep 05 18:45:26.99: [28345]: USE 20 ms, 10 ms/scanline
> Sep 05 18:45:26.99: [28345]: SEND file "docq/doc21.ps;01"
> Sep 05 18:45:26.99: [28345]: USE page width 1728 pixels in 215 mm
> Sep 05 18:45:26.99: [28345]: USE unlimited page length
> Sep 05 18:45:26.99: [28345]: USE 7.7 line/mm
> Sep 05 18:45:26.99: [28345]: USE 1-D MR
> Sep 05 18:45:26.99: [28345]: SEND training at v.29 9600 bit/s
> Sep 05 18:45:26.99: [28345]: <-- [9:AT+FTH=3\r]
> Sep 05 18:45:27.04: [28345]: --> [7:CONNECT]
> Sep 05 18:45:27.04: [28345]: <-- HDLC<23:FF C0 C2 8C 8C 8C 8C 8C 04 0C
> 0C 0C 04
> 9C CC D4 04 04 04 04 04 04 04>
> Sep 05 18:45:27.04: [28345]: <-- data [23]
> Sep 05 18:45:27.04: [28345]: <-- data [2]
> Sep 05 18:45:27.06: [28345]: --> [1:^Q]
> Sep 05 18:45:27.07: [28345]: --> [7:CONNECT]
> Sep 05 18:45:27.07: [28345]: <-- HDLC<6:FF C8 C1 00 62 10>
> Sep 05 18:45:27.07: [28345]: <-- data [6]
> Sep 05 18:45:27.07: [28345]: <-- data [2]
> Sep 05 18:45:29.24: [28345]: --> [2:OK]
> Sep 05 18:45:29.24: [28345]: DELAY 75 ms
> Sep 05 18:45:29.32: [28345]: MODEM set XON/XOFF/FLUSH: input
> interpreted, output disabled
> Sep 05 18:45:29.32: [28345]: <-- [10:AT+FTM=96\r]
> Sep 05 18:45:29.65: [28345]: --> [7:CONNECT]
> Sep 05 18:45:29.65: [28345]: <-- data [1024]
> Sep 05 18:45:29.65: [28345]: <-- data [776]
> Sep 05 18:45:29.65: [28345]: <-- data [2]
> Sep 05 18:45:31.20: [28345]: --> [2:OK]
> Sep 05 18:45:31.20: [28345]: MODEM set XON/XOFF/DRAIN: input ignored,
> output disabled
> Sep 05 18:45:31.20: [28345]: <-- [9:AT+FRH=3\r]
> Sep 05 18:45:31.35: [28345]: --> [7:CONNECT]
> Sep 05 18:45:32.47: [28345]: --> HDLC<5:FF C8 21 57 BE>
> Sep 05 18:45:32.49: [28345]: --> [2:OK]
> Sep 05 18:45:32.49: [28345]: TRAINING succeeded
> Sep 05 18:45:32.49: [28345]: <-- [10:AT+FTM=96\r]
> Sep 05 18:45:32.89: [28345]: --> [1:^S]
> Sep 05 18:45:32.90: [28345]: --> [7:CONNECT]
> Sep 05 18:45:32.90: [28345]: SEND begin page
> Sep 05 18:45:32.90: [28345]: MODEM set XON/XOFF/FLUSH: input
> interpreted, output disabled
> Sep 05 18:45:32.90: [28345]: <-- data [1028]
> Sep 05 18:45:32.90: [28345]: <-- data [1024]
> Sep 05 18:45:32.90: [28345]: <-- data [1027]
> Sep 05 18:45:32.90: [28345]: <-- data [167]
> Sep 05 18:45:32.90: [28345]: SENT 3239 bytes of data
> Sep 05 18:45:32.90: [28345]: SEND 1D RTC
> Sep 05 18:45:32.90: [28345]: <-- data [29]
> Sep 05 18:45:32.90: [28345]: <-- data [2]
> Sep 05 18:45:32.90: [28345]: SEND end page
> Sep 05 18:45:35.91: [28345]: --> [2:OK]
> Sep 05 18:45:35.91: [28345]: MODEM set XON/XOFF/DRAIN: input ignored,
> output disabled
> Sep 05 18:45:35.91: [28345]: DELAY 95 ms
> Sep 05 18:45:36.01: [28345]: SEND send EOP (no more pages or documents)
> Sep 05 18:45:36.01: [28345]: <-- [9:AT+FTH=3\r]
> Sep 05 18:45:36.06: [28345]: --> [7:CONNECT]
> Sep 05 18:45:36.06: [28345]: <-- HDLC<3:FF C8 F4>
> Sep 05 18:45:36.06: [28345]: <-- data [3]
> Sep 05 18:45:36.06: [28345]: <-- data [2]
> Sep 05 18:45:37.38: [28345]: --> [1:^Q]
> Sep 05 18:45:37.38: [28345]: --> [2:OK]
> Sep 05 18:45:37.38: [28345]: <-- [9:AT+FRH=3\r]
> Sep 05 18:45:40.48: [28345]: --> [0:]
> Sep 05 18:45:40.48: [28345]: MODEM <Empty line>
> Sep 05 18:45:40.48: [28345]: MODEM TIMEOUT: waiting for v.21 carrier
> Sep 05 18:45:40.48: [28345]: <-- data [1]
> Sep 05 18:45:40.68: [28345]: MODEM TIMEOUT: reading line from modem
> Sep 05 18:45:40.68: [28345]: MODEM <Timeout>

Hmm, your modem does not return OK after interrupt... Could you try to set
Class1RecvAbortOK: 0
and collect the log again?

But frankly speaking I don't think it will help. May I place a couple of
test calls to that number? Maybe I will check some experimental code ...

> Sep 05 18:45:40.68: [28345]: SEND send EOP (no more pages or documents)
> Sep 05 18:45:40.68: [28345]: <-- [9:AT+FTH=3\r]
> Sep 05 18:45:40.73: [28345]: --> [7:CONNECT]
> Sep 05 18:45:40.73: [28345]: <-- HDLC<3:FF C8 F4>
> Sep 05 18:45:40.73: [28345]: <-- data [3]
> Sep 05 18:45:40.73: [28345]: <-- data [2]
> Sep 05 18:45:42.05: [28345]: --> [1:^Q]
> Sep 05 18:45:42.05: [28345]: --> [2:OK]
> Sep 05 18:45:42.05: [28345]: <-- [9:AT+FRH=3\r]
> Sep 05 18:45:45.15: [28345]: --> [0:]
> Sep 05 18:45:45.15: [28345]: MODEM <Empty line>
> Sep 05 18:45:45.15: [28345]: MODEM TIMEOUT: waiting for v.21 carrier
> Sep 05 18:45:45.15: [28345]: <-- data [1]
> Sep 05 18:45:45.35: [28345]: MODEM TIMEOUT: reading line from modem
> Sep 05 18:45:45.35: [28345]: MODEM <Timeout>
> Sep 05 18:45:45.35: [28345]: SEND send EOP (no more pages or documents)
> Sep 05 18:45:45.35: [28345]: <-- [9:AT+FTH=3\r]
> Sep 05 18:45:45.40: [28345]: --> [7:CONNECT]
> Sep 05 18:45:45.40: [28345]: <-- HDLC<3:FF C8 F4>
> Sep 05 18:45:45.40: [28345]: <-- data [3]
> Sep 05 18:45:45.40: [28345]: <-- data [2]
> Sep 05 18:45:46.72: [28345]: --> [1:^Q]
> Sep 05 18:45:46.72: [28345]: --> [2:OK]
> Sep 05 18:45:46.72: [28345]: <-- [9:AT+FRH=3\r]
> Sep 05 18:45:49.82: [28345]: --> [0:]
> Sep 05 18:45:49.82: [28345]: MODEM <Empty line>
> Sep 05 18:45:49.82: [28345]: MODEM TIMEOUT: waiting for v.21 carrier
> Sep 05 18:45:49.82: [28345]: <-- data [1]
> Sep 05 18:45:50.02: [28345]: MODEM TIMEOUT: reading line from modem
> Sep 05 18:45:50.02: [28345]: MODEM <Timeout>
> Sep 05 18:45:50.02: [28345]: No response to MPS or EOP repeated 3 tries
> Sep 05 18:45:50.02: [28345]: <-- [9:AT+FTH=3\r]
> Sep 05 18:45:50.07: [28345]: --> [7:CONNECT]
> Sep 05 18:45:50.07: [28345]: <-- HDLC<3:FF C8 DF>
> Sep 05 18:45:50.07: [28345]: <-- data [3]
> Sep 05 18:45:50.07: [28345]: <-- data [2]
> Sep 05 18:45:51.39: [28345]: --> [1:^Q]
> Sep 05 18:45:51.39: [28345]: --> [2:OK]
> Sep 05 18:45:51.39: [28345]: MODEM input buffering enabled
> Sep 05 18:45:51.39: [28345]: <-- [14:AT+FCLASS=0H0\r]
> Sep 05 18:45:51.82: [28345]: --> [10:NO CARRIER]
> Sep 05 18:45:51.82: [28345]: MODEM No carrier
> Sep 05 18:45:51.82: [28345]: MODEM set DTR OFF
> Sep 05 18:45:51.82: [28345]: STATE CHANGE: SENDING -> MODEMWAIT (timeout
> 5)
> Sep 05 18:45:51.82: [28345]: SESSION END
> ===

Hope to hear from you soon,
Dmitry




____________________ HylaFAX(tm) Users Mailing List _______________________
 To unsub: mail -s unsubscribe hylafax-users-request@hylafax.org < /dev/null