usb-serial stops working

[Markus Foerster <openbsd@1ster.de>]

Hi,

our setup is the following:
on several machines we got usb-to-serial converters and use them to 
connect modems and ISDN TAs. The "utty0" device is used by 
mgetty/pppd (for dialin), ppp (for dialout) and minicom (for 
diagnostics).

After a reboot, things usually work except for a long delay when 
mgetty tries to open the modem and that it needs the "forced init 
chat". But once the first "action" is performed on that port (e.g. 
starting and exiting minicom), mgetty is no longer able to initialize 
the modem, and minicom is no longer able to access it.

Example:

(still working somehow)
09/08 12:57:37 dem  mgetty: experimental test release 1.1.21-Jul24
09/08 12:57:37 dem  check for lockfiles
09/08 12:57:37 dem   checklock: stat failed, no file
09/08 12:57:37 dem  locking the line
09/08 12:57:37 dem   makelock(modem) called
09/08 12:57:37 dem   do_makelock: lock='/var/spool/lock/LCK..modem'
09/08 12:57:37 dem   lock made
09/08 12:57:37 dem  can't get group 'modem': No such file or directory
09/08 12:58:02 dem   tio_get_rs232_lines: status: DSR
09/08 12:58:02 dem  lowering DTR to reset Modem
09/08 12:58:03 dem   tss: set speed to 115200 (341000)
09/08 12:58:03 dem   tio_set_flow_control( HARD )
09/08 12:58:03 dem   waiting for line to clear (VTIME), read: [0a]
09/08 12:58:03 dem  send: AT[0d]
09/08 12:58:03 dem  waiting for ``OK''
09/08 12:58:03 dem   got:
09/08 12:58:23 dem  timeout in chat script, waiting for `OK'
09/08 12:58:23 dem  init chat timed out, trying force-init-chat
09/08 12:58:23 dem  send: \d[10][03]\d\d\d+++\d\d\d[0d]\dATQ0V1H0[0d]
09/08 12:58:27 dem  waiting for ``OK''
09/08 12:58:27 dem   got: ATQ0V1H0[0d][0d][0a]OK ** found **
09/08 12:58:27 dem   force-init succeeded, retrying init-chat
09/08 12:58:27 dem   waiting for line to clear (VTIME), read: [0d][0a]
09/08 12:58:27 dem  send: AT[0d]
09/08 12:58:27 dem  waiting for ``OK''
09/08 12:58:27 dem   got: AT[0d][0d][0a]OK ** found **
09/08 12:58:27 dem  send: ATS0=0L0M0Q0V1X3&C1&D2[0d]
09/08 12:58:27 dem  waiting for ``OK''
09/08 12:58:27 dem   got: 
[0d][0a]ATS0=0L0M0Q0V1X3&C1&D2[0d][0d][0a]OK ** found **
09/08 12:58:27 dem   waiting for line to clear (VTIME), read: [0d][0a]
09/08 12:58:28 dem   removing lock file
09/08 12:58:28 dem  waiting...

then running minicom. can talk with the modem. exiting minicom.
from now on mgetty fails:

09/08 13:01:02 dem  mgetty: experimental test release 1.1.21-Jul24
09/08 13:01:02 dem  check for lockfiles
09/08 13:01:02 dem   checklock: stat failed, no file
09/08 13:01:02 dem  locking the line
09/08 13:01:02 dem   makelock(modem) called
09/08 13:01:02 dem   do_makelock: lock='/var/spool/lock/LCK..modem'
09/08 13:01:02 dem   lock made
09/08 13:01:02 dem  can't get group 'modem': No such file or directory
09/08 13:01:28 dem   tio_get_rs232_lines: status: DSR
09/08 13:01:28 dem  lowering DTR to reset Modem
09/08 13:01:28 dem   tss: set speed to 115200 (341000)
09/08 13:01:28 dem   tio_set_flow_control( HARD )
09/08 13:01:28 dem   waiting for line to clear (VTIME), read: [0a]
09/08 13:01:28 dem  send: AT[0d]
09/08 13:01:28 dem  waiting for ``OK''
09/08 13:01:28 dem   got:
09/08 13:01:48 dem  timeout in chat script, waiting for `OK'
09/08 13:01:48 dem  init chat timed out, trying force-init-chat
09/08 13:01:48 dem  send: \d[10][03]\d\d\d+++\d\d\d[0d]\dATQ0V1H0[0d]
09/08 13:01:52 dem  waiting for ``OK''
09/08 13:01:52 dem   got:
09/08 13:02:12 dem  timeout in chat script, waiting for `OK'
09/08 13:02:12 dem  init chat failed, exiting...: Interrupted system 
call
09/08 13:02:12 ##### failed in mg_init_data, dev=modem, pid=5231

Accessing the modem with minicom also no longer works.

I though the problem could be related to switching baud rates, so I 
configured everything to 115200, but this did not help.

The situation with 3.4-beta (current snapshot) is even worse: OpenBSD 
hangs on booting if the USB-serial is plugged in. (see bug #3458)

A similar problem was reported (but without clear solution) in:

www.monkey.org/openbsd/archive/tech/0201/msg00224.html

Any help is greatly appreciated.

dmesg:

OpenBSD 3.3 (XXX) #5: Wed Aug 13 10:23:26 UTC 2003
    root@XXX:/data/src/OpenBSD/3.3/sys/arch/i386/compile/XXX
cpu0: Intel Pentium 4 ("GenuineIntel" 686-class) 1.80 GHz
cpu0: 
FPU,V86,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SYS,MTRR,PGE,MCA,CMOV,PAT,PSE
36,MMX,FXSR,SIMD
real mem  = 536395776 (523824K)
avail mem = 357826560 (349440K)
using 4278 buffers containing 161546240 bytes (157760K) of memory
mainbus0 (root)
bios0 at mainbus0: AT/286+(00) BIOS, date 06/02/03, BIOS32 rev. 0 @ 
0xffe90
pcibios0 at bios0: rev. 2.1 @ 0xf0000/0x10000
pcibios0: PCI IRQ Routing Table rev. 1.0 @ 0xfc500/96 (4 entries)
pcibios0: no compatible PCI ICU found: ICU vendor 0x1166 product 
0x0203
pcibios0: Warning, unable to fix up PCI interrupt routing
pcibios0: PCI bus #0 is the last bus
bios0: ROM list: 0xc0000/0x8000 0xc8000/0x4800 0xec000/0x4000!
pci0 at mainbus0 bus 0: configuration mode 1 (no bios)
pchb0 at pci0 dev 0 function 0 "ServerWorks CMIC_SL Host" rev 
0x32Found Serverworks HostBridge @0

pchb1 at pci0 dev 0 function 1 "ServerWorks CMIC_SL Host" rev 
0x00Found Serverworks HostBridge @1

pci1 at pchb1 bus 1
em0 at pci1 dev 3 function 0 "Intel PRO/1000MT (PWLA8492MT)" rev 
0x01: irq 10, address: 00:04:23:5f:7e:22
em1 at pci1 dev 3 function 1 "Intel PRO/1000MT (PWLA8492MT)" rev 
0x01: irq 7, address: 00:04:23:5f:7e:23
vga1 at pci0 dev 4 function 0 "ATI Rage XL" rev 0x27
wsdisplay0 at vga1: console (80x25, vt100 emulation)
wsdisplay0: screen 1-5 added (80x25, vt100 emulation)
pciide0 at pci0 dev 5 function 0 "CMD Technology PCI0680" rev 0x02
pciide0: bus-master DMA support present
pciide0: channel 0 wired to native-PCI mode
pciide0: using irq 15 for native-PCI interrupt
wd0 at pciide0 channel 0 drive 0: <ST340016A>
wd0: 16-sector PIO, LBA, 38162MB, 16383 cyl, 16 head, 63 sec, 
78156226 sectors
wd0(pciide0:0:0): using PIO mode 4, Ultra-DMA mode 5
pciide0: channel 1 wired to native-PCI mode
pchb2 at pci0 dev 15 function 0 vendor "ServerWorks", unknown product 
0x203 rev 0xa0Found Serverworks HostBridge @0

pciide1 at pci0 dev 15 function 1 "ServerWorks CSB6 IDE" rev 0xa0: DMA
atapiscsi0 at pciide1 channel 0 drive 0
scsibus0 at atapiscsi0: 2 targets
cd0 at scsibus0 targ 0 lun 0: <TEAC, CD-224E, K.9A> SCSI0 5/cdrom 
removable
cd0(pciide1:0:0): using PIO mode 4, DMA mode 2, Ultra-DMA mode 2
pciide1: no compatibility interrupt for use by channel 1
ohci0 at pci0 dev 15 function 2 vendor "ServerWorks", unknown product 
0x221 rev 0x05: irq 11, OHCI version 1.0, legacy support
usb0 at ohci0: USB revision 1.0
uhub0 at usb0
uhub0: vendor 0x0000 OHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub0: 4 ports with 4 removable, self powered
pcib0 at pci0 dev 15 function 3 vendor "ServerWorks", unknown product 
0x227 rev 0x00
pchb3 at pci0 dev 16 function 0 vendor "ServerWorks", unknown product 
0x110 rev 0x12Found Serverworks HostBridge @1

pchb4 at pci0 dev 16 function 2 vendor "ServerWorks", unknown product 
0x110 rev 0x12Found Serverworks HostBridge @2

pci2 at pchb4 bus 2
isa0 at pcib0
isadma0 at isa0
pckbc0 at isa0 port 0x60/5
pckbd0 at pckbc0 (kbd slot)
pckbc0: using irq 1 for kbd slot
wskbd0 at pckbd0: console keyboard, using wsdisplay0
pcppi0 at isa0 port 0x61
sysbeep0 at pcppi0
npx0 at isa0 port 0xf0/16: using exception 16
pccom0 at isa0 port 0x3f8/8 irq 4: ns16550a, 16 byte fifo
fdc0 at isa0 port 0x3f0/6 irq 6 drq 2
fd0 at fdc0 drive 0: 1.44MB 80 cyl, 2 head, 18 sec
biomask c840 netmask ccc0 ttymask ccc2
pctr: user-level cycle counter enabled
dkcsum: wd0 matched BIOS disk 80
root on wd0a
rootdev=0x0 rrootdev=0x300 rawdev=0x302
uplcom0 at uhub0 port 2
uplcom0: ATEN International Serial adapter, rev 1.10/0.01, addr 2
ucom0 at uplcom0