[SeaBIOS] WD Elements hang SeaBIOS at boot with "call16 with invalid stack"

Wed Dec 23 20:56:58 CET 2015

I replaced the printf(...) with dprintf(1, ...)  (since a dprintf earlier
in the function was working fine).

This appears to have fixed the issue (though PCHS seems to be wrong, maybe
because sector count is negative when parsed as a signed int). Full log
attached.

Press ESC for boot menu.

On Wed, Dec 23, 2015 at 7:58 PM, Kevin O'Connor <kevin at koconnor.net> wrote:

> On Wed, Dec 23, 2015 at 07:39:56PM +0100, Tobias Diedrich wrote:
> > On Wed, Dec 23, 2015 at 7:10 PM, Kevin O'Connor <kevin at koconnor.net>
> wrote:
> >
> > > On Wed, Dec 23, 2015 at 07:02:37PM +0100, Tobias Diedrich wrote:
> > > > Wcall16 with invalid stack: eax=dfbf3e62 edx=0 func=0x000f9563
> > > esp=dfbf3e50
> > > >
> > > > .text._farcall16 0x9563 : { *(.text._farcall16) }
> > > >
> > >
> > > Can you include the full log?  It looks like the code tried to call a
> > > 16bit function while in a "thread", and I need to figure out which
> > > thread did that.
> >
> >
> > From the esp address it looks like it'sin the USB probe for the MSC
> device
> > (full log attached):
> > /dfc02000\ Start thread func=dfc135f1
> > |dfc02000| set_address 0xdfc0a200
> > |dfc02000| config_usb: 0xdfc0a0d0
> > |dfc02000| device rev=0210 cls=00 sub=00 proto=00 size=64
> > |dfc02000| Searching bootorder for: /pci at i0cf8/usb at 12,2/storage at 5
> /*@0/*@0,0
> > |dfc02000| Searching bootorder for: /pci at i0cf8/usb at 12,2/usb-*@5
> > |dfc02000| USB MSC vendor='WD' product='Elements 10B8' rev='1012' type=0
> > removable=0
> > Wcall16 with invalid stack: eax=dfc02e66 edx=0 func=0x000f91f0
> esp=dfc02e54
> > ret=0x000f0604
>
> What happens if you apply the patch below?  (If it looks like it is
> hanging, give it at least a minute before stopping it.)
>
> -Kevin
>
>
> --- a/src/hw/blockcmd.c
> +++ b/src/hw/blockcmd.c
> @@ -168,7 +168,7 @@ scsi_is_ready(struct disk_op_s *op)
>
>          if (sense.asc == 0x04 && sense.ascq == 0x01 && !in_progress) {
>              /* IN PROGRESS OF BECOMING READY */
> -            printf("Waiting for device to detect medium... ");
> +            //printf("Waiting for device to detect medium... ");
>              /* Allow 30 seconds more */
>              end = timer_calc(30000);
>              in_progress = 1;
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.seabios.org/pipermail/seabios/attachments/20151223/35a87cb2/attachment-0001.html>
-------------- next part --------------
SeaBIOS (version rel-1.9.0-43-g76327b9-dirty-20151223_204524-navi)
BUILD: gcc: (coreboot toolchain v1.33 November 25th, 2015) 5.2.0 binutils: (GNU Binutils) 2.25
Attempting to find coreboot table
Found coreboot table forwarder.
Now attempting to find coreboot memory map
SeaBIOS (version rel-1.9.0-43-g76327b9-dirty-20151223_204524-navi)
BUILD: gcc: (coreboot toolchain v1.33 November 25th, 2015) 5.2.0 binutils: (GNU Binutils) 2.25
Found coreboot cbmem console @ dffde000
Found mainboard PC Engines APU1
malloc preinit
Relocating init from 0x000e4800 to 0xdfc0b9e0 (size 46464)
malloc init
Found CBFS header at 0xffe00138
Add romfile: cbfs master header (size=32)
Add romfile: fallback/romstage (size=168724)
Add romfile: fallback/ramstage (size=126226)
Add romfile: fallback/payload (size=60769)
Add romfile: config (size=282)
Add romfile: revision (size=569)
Add romfile: cmos.default (size=256)
Add romfile: cmos_layout.bin (size=796)
Add romfile: fallback/dsdt.aml (size=9847)
Add romfile: spd.bin (size=256)
Add romfile: payload_config (size=1585)
Add romfile: payload_revision (size=265)
Add romfile: etc/ps2-keyboard-spinup (size=8)
Add romfile:  (size=1660504)
Add romfile: s3nv (size=32768)
Add romfile:  (size=31576)
Add romfile: bootblock (size=1088)
multiboot: eax=0, ebx=0
init ivt
init bda
init bios32
init PMM
init PNPBIOS table
init keyboard
init mouse
init pic
math cp init
PCI probe
Found 27 PCI devices (max PCI bus is 05)
Relocating coreboot bios tables
Copying SMBIOS entry point from 0xdfc5f000 to 0x000f6440
Copying ACPI RSDP from 0xdfc70000 to 0x000f6410
Copying MPTABLE from 0xdfc94000/dfc94010 to 0x000f6230
Copying PIR from 0xdfc95000 to 0x000f6200
Using pmtimer, ioport 0x808
init timer
Scan for VGA option rom
/dfc09000\ Start thread func=dfc0f9ed
|dfc09000| init usb
|dfc09000| EHCI init on dev 00:12.2 (regs=0xf7f04020)
/dfc08000\ Start thread func=dfc0f07e
init ps2port
/dfc07000\ Start thread func=dfc0e567
|dfc07000| WARNING - Timeout at i8042_flush:71!
\dfc07000/ End thread
|dfc09000| EHCI init on dev 00:13.2 (regs=0xf7f05020)
/dfc07000\ Start thread func=dfc0f07e
/dfc05000\ Start thread func=dfc135f1
init lpt
Found 1 lpt ports
init serial
Found 2 serial ports
init floppy drives
init hard drives
init ahci
ebda moved from 9f000 to 9e800
AHCI controller at 11.0, iobase f7f03000, irq 11
AHCI: cap 0xf332ff05, ports_impl 0x3f
/dfc04000\ Start thread func=dfc11e79
|dfc04000| AHCI/0: probing
|dfc04000| AHCI/0: link up
|dfc09000| EHCI init on dev 00:16.2 (regs=0xf7f06020)
/dfc03000\ Start thread func=dfc0f07e
/dfc02000\ Start thread func=dfc135f1
/dfc01000\ Start thread func=dfc135f1
/dfbff000\ Start thread func=dfc11e79
|dfbff000| AHCI/1: probing
|dfbff000| AHCI/1: link up
|dfc04000| AHCI/0: ... finished, status 0x51, ERROR 0x4
|dfc09000| OHCI init on dev 00:12.0 (regs=0xf7f00000)
/dfbfe000\ Start thread func=dfc0f784
/dfbfd000\ Start thread func=dfc135f1
/dfbfc000\ Start thread func=dfc135f1
/dfbfb000\ Start thread func=dfc135f1
/dfbfa000\ Start thread func=dfc11e79
|dfbfa000| AHCI/2: probing
|dfc04000| Searching bootorder for: /pci at i0cf8/*@11/drive at 0/disk at 0
|dfc09000| OHCI init on dev 00:13.0 (regs=0xf7f01000)
/dfbf9000\ Start thread func=dfc0f784
/dfbf8000\ Start thread func=dfc135f1
/dfbf7000\ Start thread func=dfc135f1
/dfbf6000\ Start thread func=dfc135f1
\dfbf6000/ End thread
\dfbfb000/ End thread
\dfc01000/ End thread
\dfc05000/ End thread
/dfc01000\ Start thread func=dfc11e79
|dfc01000| AHCI/3: probing
|dfbfa000| AHCI/2: link down
|dfbff000| AHCI/1: ... finished, status 0x51, ERROR 0x4
|dfc04000| AHCI/0: registering: "AHCI/0: SB mSATA SSD ATA-10 Hard-Disk (14318 MiBytes)"
|dfc04000| Registering bootable: AHCI/0: SB mSATA SSD ATA-10 Hard-Disk (14318 MiBytes) (type:2 prio:103 data:f6190)
\dfc04000/ End thread
|dfc09000| OHCI init on dev 00:16.0 (regs=0xf7f02000)
/dfc04000\ Start thread func=dfc0f784
/dfbfb000\ Start thread func=dfc135f1
/dfbf6000\ Start thread func=dfc135f1
\dfbf6000/ End thread
\dfbf7000/ End thread
\dfbfc000/ End thread
\dfc02000/ End thread
/dfc02000\ Start thread func=dfc135f1
/dfbfc000\ Start thread func=dfc11e79
|dfbfc000| AHCI/4: probing
|dfc01000| AHCI/3: link down
\dfbfa000/ End thread
|dfbff000| Searching bootorder for: /pci at i0cf8/*@11/drive at 1/disk at 0
\dfc09000/ End thread
/dfbfa000\ Start thread func=dfc135f1
/dfbf7000\ Start thread func=dfc135f1
/dfbf6000\ Start thread func=dfc135f1
\dfbf6000/ End thread
\dfbfb000/ End thread
\dfbf8000/ End thread
|dfbfd000| set_address 0xdfc067b0
/dfbfb000\ Start thread func=dfc135f1
\dfbfb000/ End thread
/dfbfb000\ Start thread func=dfc11e79
|dfbfb000| AHCI/5: probing
|dfbfc000| AHCI/4: link down
\dfc01000/ End thread
|dfbff000| AHCI/1: registering: "AHCI/1: Corsair CSSD-F40GB2-A ATA-8 Hard-Disk (38164 MiBytes)"
|dfbff000| Registering bootable: AHCI/1: Corsair CSSD-F40GB2-A ATA-8 Hard-Disk (38164 MiBytes) (type:2 prio:103 data:f6140)
\dfbff000/ End thread
/dfc01000\ Start thread func=dfc135f1
/dfbff000\ Start thread func=dfc135f1
init megasas
|dfbfb000| AHCI/5: link down
\dfbfc000/ End thread
/dfc05000\ Start thread func=dfc135f1
/dfbfc000\ Start thread func=dfc135f1
/dfbf8000\ Start thread func=dfc135f1
|dfc02000| set_address 0xdfc0a200
\dfbfb000/ End thread
/dfbfb000\ Start thread func=dfc135f1
/dfbf6000\ Start thread func=dfc135f1
/dfbf5000\ Start thread func=dfc135f1
|dfbfd000| config_usb: 0xdfc095d0
\dfc07000/ End thread
/dfc07000\ Start thread func=dfc135f1
/dfbf4000\ Start thread func=dfc135f1
\dfbf4000/ End thread
\dfbf6000/ End thread
\dfbfc000/ End thread
\dfc01000/ End thread
\dfbfa000/ End thread
/dfc01000\ Start thread func=dfc135f1
\dfc01000/ End thread
\dfbf5000/ End thread
\dfbf8000/ End thread
\dfbff000/ End thread
\dfbf7000/ End thread
|dfbfd000| device rev=0201 cls=00 sub=00 proto=00 size=64
/dfc01000\ Start thread func=dfc135f1
|dfc02000| config_usb: 0xdfc0a0d0
\dfbf9000/ End thread
\dfbfe000/ End thread
|dfc02000| device rev=0210 cls=00 sub=00 proto=00 size=64
|dfc02000| Searching bootorder for: /pci at i0cf8/usb at 12,2/storage at 5/*@0/*@0,0
|dfc02000| Searching bootorder for: /pci at i0cf8/usb at 12,2/usb-*@5
|dfbfd000| Searching bootorder for: /pci at i0cf8/usb at 16,2/storage at 1/*@0/*@0,0
|dfbfd000| Searching bootorder for: /pci at i0cf8/usb at 16,2/usb-*@1
\dfc01000/ End thread
\dfc07000/ End thread
\dfbfb000/ End thread
\dfc05000/ End thread
|dfc02000| USB MSC vendor='WD' product='Elements 10B8' rev='1012' type=0 removable=0
\dfc04000/ End thread
|dfbfd000| USB MSC vendor='Multiple' product='Card  Reader' rev='1.00' type=0 removable=1
|dfbfd000| Device reports MEDIUM NOT PRESENT
|dfbfd000| scsi_is_ready returned -1
|dfbfd000| Unable to configure USB MSC drive.
|dfbfd000| Unable to configure USB MSC device.
\dfbfd000/ End thread
|dfc02000| Waiting for device to detect medium... \dfc03000/ End thread
|dfc02000| USB MSC blksize=512 sectors=-388003840
|dfc02000| Registering bootable: USB MSC Drive WD Elements 10B8 1012 (type:2 prio:103 data:f6110)
\dfc02000/ End thread
\dfc08000/ End thread
All threads complete.
Scan for option roms

Press ESC for boot menu.

Checking for bootsplash
Searching bootorder for: HALT
Mapping hd drive 0x000f6190 to 0
drive 0x000f6190: PCHS=16383/16/63 translation=lba LCHS=1024/255/63 s=29323728
Mapping hd drive 0x000f6140 to 1
drive 0x000f6140: PCHS=16383/16/63 translation=lba LCHS=1024/255/63 s=78161328
Mapping hd drive 0x000f6110 to 2
drive 0x000f6110: PCHS=0/0/0 translation=lba LCHS=1024/255/63 s=-388003840
finalize PMM
malloc finalize
Space available for UMB: c0000-efd80, f5c60-f6110
Returned 241664 bytes of ZoneHigh
e820 map has 7 items:
  0: 0000000000000000 - 000000000009e800 = 1 RAM
  1: 000000000009e800 - 00000000000a0000 = 2 RESERVED
  2: 00000000000f0000 - 0000000000100000 = 2 RESERVED
  3: 0000000000100000 - 00000000dfc52000 = 1 RAM
  4: 00000000dfc52000 - 00000000e0000000 = 2 RESERVED
  5: 00000000f8000000 - 00000000fc000000 = 2 RESERVED
  6: 0000000100000000 - 000000011f000000 = 1 RAM
Jump to int19
enter handle_19:
  NULL
Booting from Hard Disk...
Booting from 0000:7c00
enter handle_12:
   a=00009a49  b=00001c00  c=00000000  d=00007080 ds=07c0 es=0880 ss=9000
  si=00000010 di=00000011 bp=00000000 sp=0000ffd6 cs=0880 ip=005b  f=0246
invalid handle_legacy_disk:701:
   a=00000000  b=00000020  c=00000000  d=00000300 ds=9ba0 es=0000 ss=9000
  si=00000168 di=00000001 bp=00000000 sp=0000ffd6 cs=9ba0 ip=084a  f=0246
enter handle_11:
   a=00000e00  b=00812200  c=00000df1  d=00090080 ds=9ba0 es=0060 ss=9000
  si=00000168 di=0000001a bp=00000000 sp=0000ffd6 cs=9ba0 ip=14c8  f=0246
enter handle_12:
   a=00004406  b=00812200  c=00000df1  d=00090080 ds=9ba0 es=0060 ss=9000
  si=00000168 di=0000001c bp=00000000 sp=0000ffd6 cs=9ba0 ip=14cb  f=0246
invalid handle_legacy_disk:701:
   a=00001500  b=00810f80  c=00000002  d=00090000 ds=9ba0 es=0060 ss=9000
  si=00000168 di=00000024 bp=00000000 sp=0000ffd6 cs=9ba0 ip=1579  f=0246
invalid handle_legacy_disk:701:
   a=00000801  b=00810f80  c=00000000  d=00090000 ds=9ba0 es=0060 ss=9000
  si=00000168 di=0000002a bp=00000000 sp=0000ffd6 cs=9ba0 ip=1597  f=0246
invalid handle_legacy_disk:701:
   a=00001560  b=0081002a  c=00000001  d=00090001 ds=9ba0 es=0060 ss=9000
  si=00000168 di=00000034 bp=00000000 sp=0000ffd6 cs=9ba0 ip=1579  f=0202
invalid handle_legacy_disk:701:
   a=00000801  b=0081002a  c=00000001  d=00090001 ds=9ba0 es=0060 ss=9000
  si=00000168 di=0000003a bp=00000000 sp=0000ffd6 cs=9ba0 ip=1597  f=0202
unimplemented handle_15XX:330:
   a=0000ec00  b=00000002  c=00000000  d=00000000 ds=9000 es=9000 ss=9000
  si=00000000 di=00000000 bp=00000000 sp=0000ffd6 cs=9000 ip=02fd  f=0003
unimplemented handle_16XX:234:
   a=00000305  b=00000000  c=00000000  d=00000000 ds=9000 es=9000 ss=9000
  si=00000000 di=00000000 bp=00000000 sp=0000ffd6 cs=9000 ip=02fd  f=0003
unimplemented handle_15XX:330:
   a=0000e980  b=00000000  c=00000000  d=47534943 ds=9000 es=9000 ss=9000
  si=00000000 di=00000000 bp=00000000 sp=0000ffd6 cs=9000 ip=02fd  f=0003
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 4.0.5 (ranma at nukunuku) (gcc version 4.9.2 (Debian 4.9.2-10) ) #15 SMP Sun Jun 7 18:17:21 CEST 2015
[...]