Dear Ian, > On 02.03.2016, at 11:45, Holger Kipp <holger.k...@alogis.com> wrote: > > > Am 01.03.2016 um 23:08 schrieb Ian Lepore > <i...@freebsd.org<mailto:i...@freebsd.org>>: > > On Tue, 2016-03-01 at 19:58 +0000, Holger Kipp wrote: > Hi all, > > I currently encounter a problem with sending faxes with new server > and FreeBSD 10.2-RELEASE p12 > using mgetty+sendfax and RS232-Modems via USB to RS232-Adapter (com, > uftdi). > > Problem is that _after_ sending the first page, the reply of modem is > not read correctly. > > In Error case, Faxlog says: > > 02/29 18:46:10 aU4 read 64, write 64 > 02/29 18:46:10 aU4 read 52, write 52 > 02/29 18:46:10 aU4 page complete, 40900 bytes sent > 02/29 18:46:10 aU4 sending DLE ',' > 02/29 18:46:10 aU4 got:[0a][0d][0a]OK[0d] > 02/29 18:46:18 aU4 got response: 'OK' > 02/29 18:46:18 aU4 fax_send_page("f2.g3") started... > 02/29 18:46:18 aU4 tio_set_flow_control( HARD ) > 02/29 18:46:18 aU4 fax_send: 'AT+FDT' > 02/29 18:46:18 aU4 fax_wait_for(CONNECT) > 02/29 18:46:18 aU4 got:[0a] > 02/29 18:48:18 aU4 Warning: got alarm signal! > > So I run into timeout because the modem does not reply as expected > after AT+FDT-command (maybe even after sending DLE ',‘ because the OK > response seems to take some more time than under FreeBSD 7.4). > > > if I issue "tip modem4" (which is /dev/cuaU4), I get the missing > replies including CONNECT from the modem (then leaving tip with "~.“) > > root@faxserver:/usr/local/etc/mgetty+sendfax # tip modem4 > connected > AT+FDT > CONNECT > > +FHS:43 > > OK > AT+FCLASS=0 > OK > ~ > [EOT] > root@faxserver:/usr/local/etc/mgetty+sendfax # > > > This works correctly with same modems and USB to RS232-Adapter > (uftdi) under FreeBSD 7.4. > > 02/29 12:18:26 aU4 receiver cap.: '+FIS:1,5,0,2,1,1,0,3' -> fine 144 > 2D/MR ECM** found ** > 02/29 12:18:26 aU4 sendfax: IGNORE DCD (carrier) status > 02/29 12:18:26 aU4 fax_send: 'AT+FDT' > 02/29 12:18:26 aU4 fax_wait_for(CONNECT) > 02/29 12:18:33 aU4 transmission par.: '+FCS:1,5,0,2,0,0,0,3'** found > ** > 02/29 12:18:33 aU4 sending f1.g3... > 02/29 12:19:04 aU4 page complete, 34495 bytes sent > 02/29 12:19:04 aU4 sending DLE ',' > 02/29 12:19:10 aU4 got response: 'OK' > 02/29 12:19:10 aU4 fax_send: 'AT+FDT' > 02/29 12:19:10 aU4 fax_wait_for(CONNECT)** found ** > 02/29 12:19:11 aU4 sending f2.g3... > 02/29 12:19:55 aU4 page complete, 60064 bytes sent > 02/29 12:19:55 aU4 sending DLE ',' > 02/29 12:20:01 aU4 got response: 'OK' > 02/29 12:20:01 aU4 fax_send: 'AT+FDT' > 02/29 12:20:01 aU4 fax_wait_for(CONNECT)** found ** > 02/29 12:20:01 aU4 sending f3.g3... > 02/29 12:20:52 aU4 page complete, 71335 bytes sent > 02/29 12:20:52 aU4 sending DLE ',' > 02/29 12:20:57 aU4 got response: 'OK' > 02/29 12:20:57 aU4 fax_send: 'AT+FDT' > 02/29 12:20:57 aU4 fax_wait_for(CONNECT)** found ** > 02/29 12:20:58 aU4 sending f4.g3... > 02/29 12:21:40 aU4 page complete, 58628 bytes sent > 02/29 12:21:40 aU4 sending DLE '.' > 02/29 12:21:49 aU4 connection hangup: '+FHS:00' > 02/29 12:21:49 aU4 got response: 'OK' > 02/29 12:21:49 aU4 fax_send: 'AT+FCLASS=0' > > This is with devolo 56k i ISDN-modems, but it looks more like a USB > interface communication issue to me. > > Modems and USB-to-RS232 are the same - connected to FreeBSD 7.4 > servers works (sends all pages), connected to 10.2 server does not > work (sends first page only). > > I can also provide dmesg.boot details on request but didn’t want to > pollute the list. > > Difference with stty -a /dev/cuaU4 seems to be clocal instead of > -clocal which I can’t set for cuaU4, only for .init and .lock. which > does not help. > 7.4 Kernel comes with uftdi and ucom compiled in. > 10.2 Kernel has the same issues with ucom and uftdi loaded as kernel > modules or compiled in. > > mgetty+sendfax is version 1.1.35_1 on FreeBSD 7.4 and version 1.1.37 > on FreeBSD 10.2-RELEASE p12. > > Any other ideas where to look further or what to investigate? > > Many thanks and best regards, > Holger > > Seeing "tio_set_flow_control( HARD )>" in your output, along with the > fact that you said the expected output finally appeared after you > connected with tip, makes me suspect that flow control is at the root > of this problem. > > The biggest ftdi driver difference before/after freebsd 8 is that the > driver used to automatically re-intialize the chip on every open to set > up some arbitrary combination of comms parameters (baud, flow control, > etc) -- I forget all the details now, I'd have to do some digging > through logs to find exactly what it used to set. Now the driver > leaves the chip alone at open time, and the contents of the > /dev/cuaU#.init and cuaU#.lock files should be completely in control of > the serial parameters. > > Is it possible that you set up the .init and/or .lock devices in some > rc script in freebsd 7 and forgot about it? If not, then maybe the > driver init changes are enough to explain the glitch. > > I wonder if this would fix it: > > stty -f /dev/cuaU4.init crtscts > > If so, then put that command into an rc script, or maybe into a devd > rule that runs whenever that usb-serial is attached. > > If not... then I guess we'll figure out what to try next. :) > > Dear Ian, > > below you will find stty settings in old and new system. > I had tried crtscts, but without success and not properly documented. > Have tried it once more (see below), now also documented ;-) > > FreeBSD 7.4: > faxserver# stty -f /dev/cuaU4 > speed 9600 baud; > lflags: -echo > oflags: -oxtabs > cflags: cs8 -parenb > faxserver# stty -f /dev/cuaU4.init > speed 9600 baud; > lflags: -echo > oflags: -oxtabs > cflags: cs8 -parenb > faxserver# stty -f /dev/cuaU4.lock > speed 0 baud; > lflags: -icanon -isig -iexten -echo > iflags: -icrnl -ixon -ixany -imaxbel -brkint > oflags: -opost -onlcr -oxtabs > cflags: -cread cs5 -parenb -hupcl > discard dsusp eof eol eol2 erase erase2 intr kill > ^@ ^@ ^@ ^@ ^@ ^@ ^@ ^@ ^@ > lnext min quit reprint start status stop susp werase > ^@ 0 ^@ ^@ ^@ ^@ ^@ ^@ ^@ > > > FreeBSD 10.2-RELEASE > faxserver# stty -f /dev/cuaU4 > speed 9600 baud; > lflags: echoe echoke echoctl > oflags: tab0 > cflags: cs8 -parenb clocal > faxserver# stty -f /dev/cuaU4.init > speed 9600 baud; > lflags: echoe echoke echoctl > oflags: tab0 > cflags: cs8 -parenb > faxserver# stty -f /dev/cuaU4.lock > speed 0 baud; > lflags: -icanon -isig -iexten -echo > iflags: -icrnl -ixon -ixany -imaxbel -brkint > oflags: -opost -onlcr tab0 > cflags: -cread cs5 -parenb -hupcl > discard dsusp eof eol eol2 erase erase2 intr kill > ^@ ^@ ^@ ^@ ^@ ^@ ^@ ^@ ^@ > lnext min quit reprint start status stop susp werase > ^@ 0 ^@ ^@ ^@ ^@ ^@ ^@ ^@ > > original settings (I have not changed anything for cuaU7): > faxserver# stty -f /dev/cuaU7 > speed 9600 baud; > lflags: echoe echoke echoctl > oflags: tab0 > cflags: cs8 -parenb clocal > faxserver# stty -f /dev/cuaU7.init > speed 9600 baud; > lflags: echoe echoke echoctl > oflags: tab0 > cflags: cs8 -parenb > faxserver# stty -f /dev/cuaU7.lock > speed 0 baud; > lflags: -icanon -isig -iexten -echo > iflags: -icrnl -ixon -ixany -imaxbel -brkint > oflags: -opost -onlcr tab0 > cflags: -cread cs5 -parenb -hupcl > discard dsusp eof eol eol2 erase erase2 intr kill > ^@ ^@ ^@ ^@ ^@ ^@ ^@ ^@ ^@ > lnext min quit reprint start status stop susp werase > ^@ 0 ^@ ^@ ^@ ^@ ^@ ^@ ^@ > > > I have set crtscts on 10.2 as requested: > faxserver# stty -f /dev/cuaU4.init crtscts > faxserver# stty -f /dev/cuaU4.init > speed 9600 baud; > lflags: echoe echoke echoctl > oflags: tab0 > cflags: cs8 -parenb crtscts > > then during transmission I get: > faxserver# stty -f /dev/cuaU4 > speed 38400 baud; > lflags: -icanon -isig -iexten -echo > iflags: -icrnl -ixon -ixany -imaxbel -brkint > oflags: -opost -onlcr tab0 > cflags: cs8 -parenb clocal crtscts > eol > ^@ > > so crtscts is obviously set. I don’t know why clocal is set instead of > –clocal, though (I _can_ change /dev/cuaU4 to -clocal whilst cuaU4 is in use, > but that also does not help (tested separately, see my remarks at the end)). > But behavior for faxing is exactly the same with crtscts set: > > 03/02 10:50:34 sendfax: interim release 1.1.37-Jun05 > 03/02 10:50:34 sending fax to <xxxxxxxx> > 03/02 10:50:34 checking f1.g3 > 03/02 10:50:34 checking f2.g3 > 03/02 10:50:34 checking f3.g3 > 03/02 10:50:34 checking f4.g3 > 03/02 10:50:34 checking f5.g3 > 03/02 10:50:34 aU4 tss: set speed to 38400 (113000) > 03/02 10:50:34 aU4 mdm_send: 'ATV1Q0' > 03/02 10:50:34 aU4 got:ATV1Q0[0d] > 03/02 10:50:34 aU4 mdm_command: string 'ATV1Q0' > 03/02 10:50:34 aU4 got:[0d][0a]OK[0d] > 03/02 10:50:34 aU4 mdm_command: string 'OK' -> OK > 03/02 10:50:34 aU4 mdm_send: 'ATI' > 03/02 10:50:34 aU4 got:[0a]ATI[0d] > 03/02 10:50:34 aU4 got:[0d][0a]282[0d] > 03/02 10:50:34 aU4 mdm_gis: string 1: '282' > 03/02 10:50:34 aU4 got:[0a][0d][0a]OK[0d] > 03/02 10:50:34 aU4 mdm_identify: string '282' > 03/02 10:50:34 aU4 ELSA MicroLink 28.8/56K series detected > 03/02 10:50:35 aU4 mdm_send: 'ATI3' > 03/02 10:50:35 aU4 got:[0a]ATI3[0d] > 03/02 10:50:35 aU4 got:[0d][0a]Version 1.87 / 31.07.2000[0d] > 03/02 10:50:35 aU4 mdm_gis: string 1: 'Version 1.87 / 31.07.2000' > 03/02 10:50:35 aU4 got:[0a][0d][0a]OK[0d] > 03/02 10:50:35 aU4 additional info: 'Version 1.87 / 31.07.2000' > 03/02 10:50:35 aU4 mdm_send: 'AT+FCLASS=2.0' > 03/02 10:50:35 aU4 got:[0a]AT+FCLASS=2.0[0d] > 03/02 10:50:35 aU4 mdm_command: string 'AT+FCLASS=2.0' > 03/02 10:50:35 aU4 got:[0d][0a]OK[0d] > 03/02 10:50:35 aU4 mdm_command: string 'OK' -> OK > 03/02 10:50:35 aU4 mdm_send: 'AT+FLI="+49"' > 03/02 10:50:35 aU4 got:[0a]AT+FLI="+49"[0d] > 03/02 10:50:35 aU4 mdm_command: string 'AT+FLI="+49"' > 03/02 10:50:35 aU4 got:[0d][0a]OK[0d] > 03/02 10:50:35 aU4 mdm_command: string 'OK' -> OK > 03/02 10:50:35 aU4 mdm_send: 'AT+FCC=1,5,0,2,0,0,0,0' > 03/02 10:50:35 aU4 got:[0a]AT+FCC=1,5,0,2,0,0,0,0[0d] > 03/02 10:50:35 aU4 mdm_command: string 'AT+FCC=1,5,0,2,0,0,0,0' > 03/02 10:50:35 aU4 got:[0d][0a]OK[0d] > 03/02 10:50:35 aU4 mdm_command: string 'OK' -> OK > 03/02 10:50:35 aU4 mdm_send: 'AT+FBO=0' > 03/02 10:50:35 aU4 got:[0a]AT+FBO=0[0d] > 03/02 10:50:35 aU4 mdm_command: string 'AT+FBO=0' > 03/02 10:50:35 aU4 got:[0d][0a]OK[0d] > 03/02 10:50:35 aU4 mdm_command: string 'OK' -> OK > 03/02 10:50:35 aU4 mdm_send: 'AT+FNR=1,1,1,0' > 03/02 10:50:35 aU4 got:[0a]AT+FNR=1,1,1,0[0d] > 03/02 10:50:35 aU4 mdm_command: string 'AT+FNR=1,1,1,0' > 03/02 10:50:35 aU4 got:[0d][0a]OK[0d] > 03/02 10:50:35 aU4 mdm_command: string 'OK' -> OK > 03/02 10:50:35 aU4 mdm_send: 'AT+FLO=2' > 03/02 10:50:35 aU4 got:[0a]AT+FLO=2[0d] > 03/02 10:50:35 aU4 mdm_command: string 'AT+FLO=2' > 03/02 10:50:35 aU4 got:[0d][0a]OK[0d] > 03/02 10:50:35 aU4 mdm_command: string 'OK' -> OK > 03/02 10:50:35 aU4 mdm_send: 'AT&H3' > 03/02 10:50:35 aU4 got:[0a]AT&H3[0d] > 03/02 10:50:35 aU4 mdm_command: string 'AT&H3' > 03/02 10:50:35 aU4 got:[0d][0a]ERROR[0d] > 03/02 10:50:35 aU4 mdm_command: string 'ERROR' -> ERROR > 03/02 10:50:35 aU4 cannot set 'modem_handshake'; ignored > 03/02 10:50:35 aU4 fax_send: 'ATD0<xxxxxxxx>' > 03/02 10:50:35 aU4 fax_wait_for(OK) > 03/02 10:50:35 aU4 got:[0a]ATD0<xxxxxxxx>[0d] > 03/02 10:50:35 aU4 fax_wait_for: string 'ATD0<xxxxxxxx>' > 03/02 10:50:35 aU4 got:[0d][0a]+FCO[0d] > 03/02 10:50:48 aU4 fax_wait_for: string '+FCO' > 03/02 10:50:48 aU4 got:[0a][0d][0a]+FIS:1,3,2,2,0,1,0,0[0d] > 03/02 10:50:49 aU4 fax_wait_for: string '+FIS:1,3,2,2,0,1,0,0' > 03/02 10:50:49 aU4 receiver cap.: '+FIS:1,3,2,2,0,1,0,0' -> fine ECM > 03/02 10:50:49 aU4 got:[0a][0d][0a]OK[0d] > 03/02 10:50:49 aU4 fax_wait_for: string 'OK'** found ** > 03/02 10:50:49 aU4 sendfax: IGNORE DCD (carrier) status > 03/02 10:50:49 aU4 fax_send_page("f1.g3") started... > 03/02 10:50:49 aU4 tio_set_flow_control( HARD ) > 03/02 10:50:49 aU4 fax_send: 'AT+FDT' > 03/02 10:50:49 aU4 fax_wait_for(CONNECT) > 03/02 10:50:49 aU4 got:[0a]AT+FDT[0d] > 03/02 10:50:49 aU4 fax_wait_for: string 'AT+FDT' > 03/02 10:50:49 aU4 got:[0d][0a]+FCS:1,3,0,2,0,0,0,0[0d] > 03/02 10:50:55 aU4 fax_wait_for: string '+FCS:1,3,0,2,0,0,0,0' > 03/02 10:50:55 aU4 transmission par.: '+FCS:1,3,0,2,0,0,0,0' > 03/02 10:50:55 aU4 got:[0a][0d][0a]CONNECT[0d] > 03/02 10:50:55 aU4 fax_wait_for: string 'CONNECT'** found ** > 03/02 10:50:55 aU4 tio_set_flow_control( HARD XON_OUT ) > 03/02 10:50:55 aU4 sending f1.g3... > 03/02 10:50:55 aU4 read 64, write 64 > 03/02 10:50:55 aU4 read 64, write 64 > 03/02 10:50:55 aU4 read 64, write 64 > [..] > 03/02 10:51:26 aU4 read 64, write 64 > 03/02 10:51:26 aU4 read 64, write 64 > 03/02 10:51:26 aU4 read 52, write 52 > 03/02 10:51:26 aU4 page complete, 40900 bytes sent > 03/02 10:51:26 aU4 sending DLE ',' > 03/02 10:51:26 aU4 got:[0a][0d][0a]OK[0d] > 03/02 10:51:33 aU4 got response: 'OK' > 03/02 10:51:33 aU4 fax_send_page("f2.g3") started... > 03/02 10:51:33 aU4 tio_set_flow_control( HARD ) > 03/02 10:51:33 aU4 fax_send: 'AT+FDT' > 03/02 10:51:33 aU4 fax_wait_for(CONNECT) > 03/02 10:51:33 aU4 got:[0a] > 03/02 10:53:34 aU4 Warning: got alarm signal! > 03/02 10:53:34 aU4 mdm_read_byte: read returned -1: Interrupted system call > 03/02 10:53:34 aU4 mdm_get_line: cannot read byte, return: Interrupted > system call > 03/02 10:53:34 aU4 AT+FDT -> some error (-6), abort fax send! > > I could change the AT&H3 to devolo-specific AT+IFC=2,2 (which is RTS,CTS) - > had already tested that just to make sure, but that is modem default setting > anyway so makes no difference. I reverted to default sendfax.config > afterwards (identical to the 7.4 settings). > > I noticed that for the first page I have HARD XON_OUT and for the second page > only HARD. This is however exactly the same behavior on 7.4. > stty -f /dev/cuaU4 reflects this (-ixon is set when trying to send the second > page, and even if -clocal was set before (during transmission of the first > page), this is then set back to clocal when the second page starts). > > On both 7.4 and 10.2 file /etc/rc.d/serial is unchanged, so no special > settings are applied. > No special settings for devd.conf either. And 10.2 (apart from added ports) > is just the plain RELEASE installation. > Originally this was a binary installation only (apart from added ports). I > have installed usr/src (10.2-RELEASE p12) and compiled with ucom, uftdi in > kernel (because it was compiled in in 7.4 FreeBSD version) to rule out any > possible side effects there. Nothing changed, but at least I’m now prepared > to recompile with any patches thrown at me ;-) > > Otherwise I’m a bit out of ideas right now. > > Many thanks and best regards, > Holger
Setting crtscts on its own did not help. I also tried an LogiLink AU0033 USB-Adapter which resulted in a comparable behaviour (sending first page only). So it is not related to uftdi. It turned out to be an issue with the modems as well (even though their default setting _is_ hardware handshake, there seems to be a problem with xon/xoff) - maybe together with changes to tty-handling between 7.4 and 10.2. setting crtscts -ixon -ixoff for .init and locking these settings (=> crtscts xon xoff for .lock) (done in rc.d/serial) however did help. Modems in question are Devolo 56k-I (ISDN). I have not checked other modems (eg ELSA ISDN TL V34) yet due to time constraints. Maybe this information is helpful if someone else is encountering a similar problem. Many thanks and best regards, Holger __________________________________________________________ Holger Kipp Diplom-Mathematiker Senior Consultant Tel. : +49 30 436 58 114 Fax. : +49 30 436 58 214 Mobil: +49 178 36 58 114 Email: holger.k...@alogis.com alogis AG Alt-Moabit 90b D-10559 Berlin http://www.alogis.com __________________________________________________________ alogis AG Sitz/Registergericht: Berlin/AG Charlottenburg, HRB 71484 Vorstand: Arne Friedrichs, Joern Samuelson Aufsichtsratsvorsitzender: Reinhard Mielke _______________________________________________ freebsd-stable@freebsd.org mailing list https://lists.freebsd.org/mailman/listinfo/freebsd-stable To unsubscribe, send any mail to "freebsd-stable-unsubscr...@freebsd.org"
