Date:	Wed, 24 Sep 2014 20:48:46 +0200
From:	Helge Deller <deller@....de>
To:	Peter Hurley <peter@...leysoftware.com>,
	linux-kernel@...r.kernel.org, linux-serial@...r.kernel.org,
	linux-parisc <linux-parisc@...r.kernel.org>
Subject: Re: serial console broken in v3.17-rc6 ?

Hi Peter,

On 09/23/2014 11:08 PM, Peter Hurley wrote:
> On 09/23/2014 04:11 PM, Helge Deller wrote:
>> During the release cycle of v3.17 I've seen sometimes a broken serial console output
>> on the parisc platform. Interestingly all kernel messages printed by the kernel via printk() show
>> up correctly, but output from userspace (e.g. by the init process during boot) show
>> up as random bytes.
>> Since the printk() output is correct the serial port itself and setup is probably correct.
>> Is parisc the only arch which has this problem, or are other architectures affected as well?
>> Maybe someone has an idea what could be wrong?
>> I did not try to bisect it yet.
>
> Thanks for the bug report.
>
> 1. What serial driver is this?

Serial port/driver integrated in NS87560 chip:
SuperIO: Found NS87560 Legacy I/O device at 0000:00:0e.1 (IRQ 68)
SuperIO: Serial port 1 at 0x3f8
SuperIO: Serial port 2 at 0x2f8
SuperIO: Parallel port at 0x378
SuperIO: Floppy controller at 0x3f0
SuperIO: ACPI at 0x7e0
SuperIO: USB regulator enabled
...
Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
serial8250: ttyS0 at I/O 0x3f8 (irq = 3, base_baud = 115200) is a 16550A

The source code for this driver is in drivers/parisc/superio.c,
see e.g. function superio_serial_init().
Maybe something is missing in here which was done to the other serial drivers?

Interestingly the *same* kernel don't show this problem on another (older) parisc
machine, but this older machine uses another serial driver:
Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
2:0:4: ttyS0 at MMIO 0xf0105800 (irq = 18, base_baud = 454545) is a 16550A
5:0:2: ttyS1 at MMIO 0xf0202800 (irq = 25, base_baud = 454545) is a 16550A

This (working) machine is using the drivers/tty/serial/8250/8250_gsc.c driver.

> 2. Regression since when?

Kernel 3.17 (3.16 worked)

> 3. Full dmesg please

See below.

> 4. Output of setserial -a [serial device]

root@...00:~# setserial -a /dev/ttyS0
/dev/ttyS0, Line 0, UART: 16550A, Port: 0x03f8, IRQ: 3
         Baud_base: 115200, close_delay: 50, divisor: 0
         closing_wait: 3000
         Flags: spd_normal

> 5. Output of stty -a [serial device]

root@...00:~# stty -a -F /dev/ttyS0
speed 9600 baud; rows 24; columns 80; line = 0;
intr = ^C; quit = ^\; erase = ^?; kill = ^U; eof = ^D; eol = <undef>; eol2 = <undef>; swtch = <undef>; start = ^Q; stop = ^S; susp = ^Z; rprnt = ^R; werase = ^W;
lnext = ^V; flush = ^O; min = 1; time = 0;
-parenb -parodd -cmspar cs8 hupcl -cstopb cread clocal -crtscts
-ignbrk -brkint -ignpar -parmrk -inpck -istrip -inlcr -igncr -icrnl -ixon -ixoff -iuclc -ixany -imaxbel -iutf8
-opost -olcuc -ocrnl -onlcr -onocr -onlret -ofill -ofdel nl0 cr0 tab0 bs0 vt0 ff0
-isig -icanon -iexten -echo -echoe -echok -echonl -noflsh -xcase -tostop -echoprt -echoctl -echoke


Here is the dmesg from git head from today.
The output copy&pasted from serial console, see strange characters at the end:

Linux version 3.17.0-rc6-32bit+ (deller@...0) (gcc version 4.7.2 20121105 (Red Hat 4.7.2-2.aa.20121114svn) (GCC) ) #230 SMP Wed Sep 24 20:23:00 CEST 2014
unwind_init: start = 0x10742550, end = 0x10786df0, entries = 17546
FP[0] enabled: Rev 1 Model 19
The 32-bit Kernel has started...
Default page size is 4KB.
bootconsole [ttyB0] enabled
Initialized PDC Console for debugging.
Determining PDC firmware type: System Map.
model 00005dc0 00000481 00000000 00000002 777c3e84 100000f0 00000008 000000b2 000000b2
vers  00000301
CPUID vers 19 rev 11 (0x0000026b)
capabilities 0x7
model 9000/785/C3700
Total Memory: 2048 MB
LCD display at f05d0008,f05d0000 registered
PERCPU: Embedded 11 pages/cpu @1197b000 s23200 r8192 d13664 u45056
SMP: bootstrap CPU ID is 0
Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 520192
Kernel command line: HOME=/ root=/dev/sdb5 ip=bootp panic_timeout=60 panic=-1 console=ttyS0 TERM=vt102 palo_kernel=0/vmlinux
log_buf_len individual max cpu contribution: 4096 bytes
log_buf_len total cpu_extra contributions: 126976 bytes
log_buf_len min size: 65536 bytes
log_buf_len: 262144 bytes
early log buf free: 63248(96%)
PID hash table entries: 4096 (order: 2, 16384 bytes)
Dentry cache hash table entries: 262144 (order: 8, 1048576 bytes)
Inode-cache hash table entries: 131072 (order: 7, 524288 bytes)
Sorting __ex_table...
Memory: 2067904K/2097152K available (4840K kernel code, 679K rwdata, 1237K rodata, 332K init, 337K bss, 29248K reserved)
virtual kernel memory layout:
    vmalloc : 0x00008000 - 0x0f000000   ( 239 MB)
    memory  : 0x10000000 - 0x90000000   (2048 MB)
      .init : 0x10100000 - 0x10153000   ( 332 kB)
      .data : 0x1060d000 - 0x107ec1d0   (1916 kB)
      .text : 0x10153000 - 0x1060d000   (4840 kB)
Hierarchical RCU implementation.
         Additional per-CPU info printed with stalls.
NR_IRQS:96
Console: colour dummy device 128x48
Calibrating delay loop... 1495.85 BogoMIPS (lpj=7479296)
pid_max: default: 32768 minimum: 301
Mount-cache hash table entries: 4096 (order: 2, 16384 bytes)
Mountpoint-cache hash table entries: 4096 (order: 2, 16384 bytes)
Brought up 1 CPUs
devtmpfs: initialized
NET: Registered protocol family 16
EISA bus registered
Searching for devices...
Found devices:
1. Astro BC Runway Port at 0xfed00000 [10] { 12, 0x0, 0x582, 0x0000b }
2. Elroy PCI Bridge at 0xfed30000 [10/0] { 13, 0x0, 0x782, 0x0000a }
3. Elroy PCI Bridge at 0xfed32000 [10/1] { 13, 0x0, 0x782, 0x0000a }
4. Elroy PCI Bridge at 0xfed38000 [10/4] { 13, 0x0, 0x782, 0x0000a }
5. Elroy PCI Bridge at 0xfed3c000 [10/6] { 13, 0x0, 0x782, 0x0000a }
6. Allegro W2 at 0xfffa0000 [32] { 0, 0x0, 0x5dc, 0x00004 }
7. Memory at 0xfed10200 [49] { 1, 0x0, 0x09c, 0x00009 }
CPU(s): 1 out of 1 PA8700 (PCX-W2) at 750.000000 MHz online
Setting cache flush threshold to 640 (1 CPUs online)
SBA found Astro 2.1 at 0xfed00000
Elroy version TR4.0 (0x5) found at 0xfed30000
LBA 10:0: PCI host bridge to bus 0000:00
pci_bus 0000:00: root bus resource [io  0x0000-0x1fff]
pci_bus 0000:00: root bus resource [mem 0xf4000000-0xf47fffff]
pci_bus 0000:00: root bus resource [bus 00]
PCI: Enabled native mode for NS87415 (pif=0x8f)
Elroy version TR4.0 (0x5) found at 0xfed32000
LBA 10:1: PCI host bridge to bus 0000:01
pci_bus 0000:01: root bus resource [io  0x12000-0x13fff] (bus address [0x2000-0x3fff])
pci_bus 0000:01: root bus resource [mem 0xfa000000-0xfbffffff]
pci_bus 0000:01: root bus resource [mem 0xf4800000-0xf4ffffff]
pci_bus 0000:01: root bus resource [bus 01]
iosapic: hpa not registered for 0000:01:04.0
Elroy version TR4.0 (0x5) found at 0xfed38000
LBA 10:4: PCI host bridge to bus 0000:02
pci_bus 0000:02: root bus resource [io  0x28000-0x29fff] (bus address [0x8000-0x9fff])
pci_bus 0000:02: root bus resource [mem 0xf9000000-0xf9ffffff]
pci_bus 0000:02: root bus resource [mem 0xf6000000-0xf67fffff]
pci_bus 0000:02: root bus resource [bus 02]
iosapic: hpa not registered for 0000:02:03.0
Elroy version TR4.0 (0x5) found at 0xfed3c000
LBA 10:6: PCI host bridge to bus 0000:03
pci_bus 0000:03: root bus resource [io  0x3c000-0x3dfff] (bus address [0xc000-0xdfff])
pci_bus 0000:03: root bus resource [mem 0xf7000000-0xf77fffff]
pci_bus 0000:03: root bus resource [bus 03]
powersw: Soft power switch at 0xf0400804 enabled.
vgaarb: loaded
SCSI subsystem initialized
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
Switched to clocksource cr16
NET: Registered protocol family 2
TCP established hash table entries: 16384 (order: 4, 65536 bytes)
TCP bind hash table entries: 16384 (order: 7, 524288 bytes)
TCP: Hash tables configured (established 16384 bind 16384)
TCP: reno registered
UDP hash table entries: 1024 (order: 4, 81920 bytes)
UDP-Lite hash table entries: 1024 (order: 4, 81920 bytes)
NET: Registered protocol family 1
SuperIO: Found NS87560 Legacy I/O device at 0000:00:0e.1 (IRQ 68)
SuperIO: Serial port 1 at 0x3f8
SuperIO: Serial port 2 at 0x2f8
SuperIO: Parallel port at 0x378
SuperIO: Floppy controller at 0x3f0
SuperIO: ACPI at 0x7e0
SuperIO: USB regulator enabled
Enabling PDC chassis warnings support v0.05
futex hash table entries: 8192 (order: 7, 524288 bytes)
VFS: Disk quotas dquot_6.5.2
Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
msgmni has been set to 4038
io scheduler noop registered
io scheduler deadline registered
io scheduler cfq registered (default)
PDC Stable Storage facility v0.30
STI GSC/PCI core graphics driver Version 0.9b
sti 0000:01:04.0: enabling SERR and PARITY (0002 -> 0142)
STI PCI graphic ROM found at f4800000 (64 kB), fb at fa000000 (32 MB)
STI ROM supports 32 bit firmware functions.
STI selected 8x16 framebuffer font VGA8x16 for sticon
     id 2d08c0a7-9a02587, conforms to spec rev. 8.0a
     graphics card name: PCI_GRAFFITIX1280
sticon: Initializing STI text console.
Console: switching to colour STI console 160x64
Console: switching to colour frame buffer device 160x64
fb0: stifb 1280x1024-8 frame buffer device, PCI_GRAFFITIX1280, id: 2d08c0a7, mmio: 0xfa100000
Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
serial8250: ttyS0 at I/O 0x3f8 (irq = 3, base_baud = 115200) is a 16550A
console [ttyS0] enabled
console [ttyS0] enabled
bootconsole [ttyB0] disabled
bootconsole [ttyB0] disabled
serial8250: ttyS1 at I/O 0x2f8 (irq = 4, base_baud = 115200) is a 16550A
Linux agpgart interface v0.103
brd: module loaded
loop: module loaded
Uniform Multi-Platform E-IDE driver
ns87415 0000:00:0e.0: IDE controller (0x100b:0x0002 rev 0x03)
ns87415 0000:00:0e.0: 100% native mode on irq 7
     ide0: BM-DMA at 0x0a00-0x0a07
     ide1: BM-DMA at 0x0a08-0x0a0f
hda: CD-532E-B, ATAPI CD/DVD-ROM drive
ide0 at 0xf00-0xf07,0xe02 on irq 7
ide1 at 0xd00-0xd07,0xb02 on irq 7
ide-gd driver 1.18
ide-cd driver 5.00
ide-cd: hda: ATAPI 32X CD-ROM drive, 128kB Cache
cdrom: Uniform CD-ROM driver Revision: 3.20
sym0: <896> rev 0x7 at pci 0000:00:0f.0 irq 69
sym0: PA-RISC Firmware, ID 7, Fast-40, SE, parity checking
sym0: SCSI BUS has been reset.
sym0: SCSI BUS mode change from SE to SE.
sym0: SCSI BUS has been reset.
scsi host0: sym-2.2.3
sym1: <896> rev 0x7 at pci 0000:00:0f.1 irq 69
sym1: PA-RISC Firmware, ID 7, Fast-40, LVD, parity checking
sym1: SCSI BUS has been reset.
scsi host1: sym-2.2.3
scsi 1:0:5:0: Direct-Access     SEAGATE  ST39102LC        HP01 PQ: 0 ANSI: 2
scsi target1:0:5: tagged command queuing enabled, command queue depth 16.
scsi target1:0:5: Beginning Domain Validation
scsi target1:0:5: FAST-40 WIDE SCSI 80.0 MB/s ST (25 ns, offset 15)
scsi target1:0:5: Domain Validation skipping write tests
scsi target1:0:5: Ending Domain Validation
scsi 1:0:6:0: Direct-Access     HP 36.4G ST336607LC       HPC3 PQ: 0 ANSI: 3
scsi target1:0:6: tagged command queuing enabled, command queue depth 16.
scsi target1:0:6: Beginning Domain Validation
scsi target1:0:6: FAST-40 WIDE SCSI 80.0 MB/s ST (25 ns, offset 31)
scsi target1:0:6: Domain Validation skipping write tests
scsi target1:0:6: Ending Domain Validation
st: Version 20101219, fixed bufsize 32768, s/g segs 256
sd 1:0:5:0: Attached scsi generic sg0 type 0
sd 1:0:6:0: Attached scsi generic sg1 type 0
Linux Tulip driver version 1.1.15 (Feb 27, 2007)
tulip0: no phy info, aborting mtable build
tulip0:  MII transceiver #1 config 1000 status 782d advertising 01e1
net eth0: Digital DS21142/43 Tulip rev 65 at Port 0x1000, 00:30:6e:48:aa:64, IRQ 66
LASI 82596 driver - Revision: 1.30
ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
ohci-pci: OHCI PCI platform driver
ohci-pci 0000:00:0e.2: OHCI PCI host controller
sd 1:0:6:0: [sdb] 71132960 512-byte logical blocks: (36.4 GB/33.9 GiB)
ohci-pci 0000:00:0e.2: new USB bus registered, assigned bus number 1
ohci-pci 0000:00:0e.2: irq 1, io mem 0xf4007000
sd 1:0:5:0: [sda] 17773524 512-byte logical blocks: (9.10 GB/8.47 GiB)
sd 1:0:6:0: [sdb] Write Protect is off
usb usb1: New USB device found, idVendor=1d6b, idProduct=0001
usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
usb usb1: Product: OHCI PCI host controller
usb usb1: Manufacturer: Linux 3.17.0-rc6-32bit+ ohci_hcd
usb usb1: SerialNumber: 0000:00:0e.2
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 3 ports detected
sd 1:0:5:0: [sda] Write Protect is off
uhci_hcd: USB Universal Host Controller Interface driver
HP SDC: No SDC found.
mousedev: PS/2 mouse device common for all mice
sd 1:0:5:0: [sda] Write cache: disabled, read cache: enabled, supports DPO and FUA
rtc-generic rtc-generic: rtc core: registered rtc-generic as rtc0
device-mapper: uevent: version 1.0.3
device-mapper: ioctl: 4.27.0-ioctl (2013-10-30) initialised: dm-devel@...hat.com
hidraw: raw HID events driver (C) Jiri Kosina
usbcore: registered new interface driver usbhid
usbhid: USB HID core driver
TCP: cubic registered
NET: Registered protocol family 17
rtc-generic rtc-generic: setting system clock to 2014-09-24 18:24:47 UTC (1411583087)
sd 1:0:6:0: [sdb] Write cache: disabled, read cache: enabled, supports DPO and FUA
Sending BOOTP requests .
usb 1-2: new low-speed USB device number 2 using ohci-pci
  OK
  sda: sda1 sda2 sda3 sda4
sd 1:0:5:0: [sda] Attached SCSI disk
  sdb: sdb1 sdb2 sdb3 < sdb5 sdb6 >
sd 1:0:6:0: [sdb] Attached SCSI disk
EXT3-fs (sdb5): error: couldn't mount because of unsupported optional features (240)
EXT2-fs (sdb5): error: couldn't mount because of unsupported optional features (240)
usb 1-2: New USB device found, idVendor=047b, idProduct=0002
usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
usb 1-2: Product: USB Keyboard and Mouse
usb 1-2: Manufacturer: SILITEK
EXT4-fs (sdb5): mounted filesystem with ordered data mode. Opts: (null)
VFS: Mounted root (ext4 filesystem) readonly on device 8:21.
input: SILITEK USB Keyboard and Mouse as /devices/parisc/10/10:0/pci0000:00/0000:00:0e.2/usb1/1-2/1-2:1.0/0003:047B:0002.0001/input/input0
hid-generic 0003:047B:0002.0001: input,hidraw0: USB HID v1.00 Keyboard [SILITEK USB Keyboard and Mouse] on usb-0000:00:0e.2-2/input0
devtmpfs: mounted
Freeing unused kernel memory: 332K (10100000 - 10153000)
input: SILITEK USB Keyboard and Mouse as /devices/parisc/10/10:0/pci0000:00/0000:00:0e.2/usb1/1-2/1-2:1.1/0003:047B:0002.0002/input/input1
hid-generic 0003:047B:0002.0002: input,hidraw1: USB HID v1.00 Mouse [SILITEK USB Keyboard and Mouse] on usb-0000:00:0e.2-2/input1
rs
      og
  ]f"
s l
    net eth0: Setting full-duplex based on MII#1 link partner capability of 45e1
random: nonblocking pool is initialized
tpdsystemd-udevd[743]: starting version 215
.
  eg..
      vp..
          ..Adding 1350652k swap on /dev/sdb6.  Priority:-1 extents:1 across:1350652k
.
  EXT4-fs (sdb5): re-mounted. Opts: (null)
i.l
    n 5
       .
        EXT4-fs (sdb5): re-mounted. Opts: errors=remount-ro
a..
    y.l
       nsb
          .
           p..
              fnsd
                  p
ve

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Powered by blists - more mailing lists