[Qemu-devel] fedora 7, cdrom and GPCMD_GET_EVENT_STATUS_NOTIFICATION

[Matthew Kent <matt@bravenet.com>]

[-- Attachment #1: Type: text/plain, Size: 1498 bytes --]

Been digging around for a solution or confirmation of this for a while
now without much luck. Forgive me if there's a solution to this I'm just
not seeing.

Getting some ugly libata related errors in my guest like

ata2: DRQ=1 with device error, dev_stat 0x49
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
ata2.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0x4a data 8
in
         res 41/50:03:00:00:20/00:00:00:00:00/a0 Emask 0x3 (HSM
violation)
ata2: soft resetting port
ata2.00: configured for MWDMA2
ata2: EH complete

when running a stock install of Fedora 7 (x86_64) in qemu (the stock
fedora package of qemu 0.9.0 or kvm-33). Tried upgrading to the latest
updated kernel 2.6.22.1-33.fc7, then the latest development one with no
change.

Tracked it down to hald-addon-storage which is polling the cdrom with
SG_IO and GPCMD_GET_EVENT_STATUS_NOTIFICATION which is trying to "check
if eject button was pressed". 

In my search I found a brief example program in this ticket
https://bugzilla.novell.com/show_bug.cgi?id=145147 which replicates the
issue reliably here without involving hal.

The workaround I found was to run

hal-disable-polling --device /dev/scd0

but given the lack of success I had finding other people reporting this
exact issue in libata proper, I'm guessing it might be something with
the cd-rom emulation of which fixing is way over my head :)

Guest dmesg and test case attached.

Anyone else seeing this?
-- 
Matthew Kent \ SA \ bravenet.com

[-- Attachment #2: bug-145147_getevent.c --]
[-- Type: text/x-csrc, Size: 1074 bytes --]

#include <stdio.h>
#include <unistd.h>
#include <fcntl.h>
#include <string.h>
#include <sys/ioctl.h>
#include <scsi/sg.h>

void hexdump(unsigned char *b, int len)
{
	int i;
	for (i = 0; i < len; i++)
		printf("%02x", b[i]);

	printf("\n");
}

int do_getev(int fd)
{
	unsigned char cdb[10] = { 0x4a, 1, 0, 0, 16, 0, 0, 0, 8, };
	unsigned char buffer[8];
	struct sg_io_hdr h;
	int ret;

	memset(buffer, 0, sizeof(buffer));
	memset(&h, 0, sizeof(h));

	h.interface_id = 'S';
	h.cmd_len = sizeof(cdb);
	h.dxfer_direction = SG_DXFER_FROM_DEV;
	h.dxfer_len = sizeof(buffer);
	h.dxferp = buffer;
	h.cmdp = cdb;
	h.timeout = 5000;

	ret = ioctl(fd, SG_IO, &h);
	if (ret) {
		printf("SG_IO failed\n");
		return -1;
	}

	printf("status %d\n", h.status);
	if (!h.status)
		hexdump(buffer, sizeof(buffer));
	return h.status;
}

int main(int argc, char *argv[])
{
	int fd;

	if (argc < 2) {
		fprintf(stderr, "%s: device\n", argv[0]);
		return 1;
	}

	fd = open(argv[1], O_RDONLY | O_NONBLOCK);
	if (fd == -1) {
		perror("open");
		return 1;
	}

	do_getev(fd);

	close(fd);
	return 0;
}

[-- Attachment #3: dmesg --]
[-- Type: text/plain, Size: 12817 bytes --]

Linux version 2.6.22.1-33.fc7 (kojibuilder@xenbuilder2.fedora.redhat.com) (gcc version 4.1.2 20070502 (Red Hat 4.1.2-12)) #1 SMP Mon Jul 23 16:59:15 EDT 2007
Command line: ro root=/dev/VolGroup00/LogVol00
BIOS-provided physical RAM map:
 BIOS-e820: 0000000000000000 - 000000000009fc00 (usable)
 BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved)
 BIOS-e820: 00000000000e8000 - 0000000000100000 (reserved)
 BIOS-e820: 0000000000100000 - 000000001fff0000 (usable)
 BIOS-e820: 000000001fff0000 - 0000000020000000 (ACPI data)
 BIOS-e820: 00000000fffc0000 - 0000000100000000 (reserved)
Entering add_active_range(0, 0, 159) 0 entries of 3200 used
Entering add_active_range(0, 256, 131056) 1 entries of 3200 used
end_pfn_map = 1048576
DMI not present or invalid.
ACPI: RSDP 000FA5D0, 0014 (r0 QEMU  )
ACPI: RSDT 1FFF0000, 002C (r0 QEMU   QEMURSDT        1 QEMU        1)
ACPI: FACP 1FFF002C, 0074 (r0 QEMU   QEMUFACP        1 QEMU        1)
ACPI: DSDT 1FFF0100, 0832 (r1   BXPC   BXDSDT        1 INTL 20060912)
ACPI: FACS 1FFF00C0, 0040
ACPI: APIC 1FFF0938, 0040 (r0 QEMU   QEMUAPIC        1 QEMU        1)
No NUMA configuration found
Faking a node at 0000000000000000-000000001fff0000
Entering add_active_range(0, 0, 159) 0 entries of 3200 used
Entering add_active_range(0, 256, 131056) 1 entries of 3200 used
Bootmem setup node 0 0000000000000000-000000001fff0000
No mptable found.
Zone PFN ranges:
  DMA             0 ->     4096
  DMA32        4096 ->  1048576
  Normal    1048576 ->  1048576
early_node_map[2] active PFN ranges
    0:        0 ->      159
    0:      256 ->   131056
On node 0 totalpages: 130959
  DMA zone: 56 pages used for memmap
  DMA zone: 1297 pages reserved
  DMA zone: 2646 pages, LIFO batch:0
  DMA32 zone: 1735 pages used for memmap
  DMA32 zone: 125225 pages, LIFO batch:31
  Normal zone: 0 pages used for memmap
ACPI: PM-Timer IO Port: 0xb008
ACPI: Local APIC address 0xfee00000
ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
Processor #0 (Bootup-CPU)
ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0])
IOAPIC[0]: apic_id 1, address 0xfec00000, GSI 0-23
ACPI: IRQ11 used by override.
Setting APIC routing to flat
Using ACPI (MADT) for SMP configuration information
swsusp: Registered nosave memory region: 000000000009f000 - 00000000000a0000
swsusp: Registered nosave memory region: 00000000000a0000 - 00000000000e8000
swsusp: Registered nosave memory region: 00000000000e8000 - 0000000000100000
Allocating PCI resources starting at 30000000 (gap: 20000000:dffc0000)
SMP: Allowing 1 CPUs, 0 hotplug CPUs
PERCPU: Allocating 40968 bytes of per cpu data
Built 1 zonelists.  Total pages: 127871
Kernel command line: ro root=/dev/VolGroup00/LogVol00
Initializing CPU#0
PID hash table entries: 2048 (order: 11, 16384 bytes)
time.c: Detected 2400.209 MHz processor.
Console: colour VGA+ 80x25
Checking aperture...
Calgary: detecting Calgary via BIOS EBDA area
Calgary: Unable to locate Rio Grande table in EBDA - bailing!
Memory: 507540k/524224k available (2361k kernel code, 16296k reserved, 1401k data, 312k init)
SLUB: Genslabs=23, HWalign=64, Order=0-1, MinObjects=4, CPUs=1, Nodes=1
Calibrating delay using timer specific routine.. 9611.40 BogoMIPS (lpj=4805704)
Security Framework v1.0.0 initialized
SELinux:  Initializing.
SELinux:  Starting in permissive mode
selinux_register_security:  Registering secondary module capability
Capability LSM initialized as secondary
Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)
Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)
Mount-cache hash table entries: 256
CPU: L1 I Cache: 64K (64 bytes/line), D cache 64K (64 bytes/line)
CPU: L2 Cache: 512K (64 bytes/line)
CPU 0/0 -> Node 0
SMP alternatives: switching to UP code
Freeing SMP alternatives: 28k freed
ACPI: Core revision 20070126
Using local APIC timer interrupts.
result 62509235
Detected 62.509 MHz APIC timer.
Brought up 1 CPUs
sizeof(vma)=176 bytes
sizeof(page)=56 bytes
sizeof(inode)=560 bytes
sizeof(dentry)=208 bytes
sizeof(ext3inode)=760 bytes
sizeof(buffer_head)=104 bytes
sizeof(skbuff)=232 bytes
sizeof(task_struct)=2048 bytes
NET: Registered protocol family 16
ACPI: bus type pci registered
PCI: Using configuration type 1
ACPI: Interpreter enabled
ACPI: (supports S5)
ACPI: Using IOAPIC for interrupt routing
ACPI: PCI Root Bridge [PCI0] (0000:00)
PCI: Probing PCI hardware (bus 00)
* Found PM-Timer Bug on the chipset. Due to workarounds for a bug,
* this clock source is slow. Consider trying other clock sources
PCI quirk: region b000-b03f claimed by PIIX4 ACPI
PCI quirk: region b100-b10f claimed by PIIX4 SMB
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 9 10 *11 12)
ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 7 *9 10 11 12)
ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 5 6 7 9 10 *11 12)
ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 6 7 *9 10 11 12)
Linux Plug and Play Support v0.97 (c) Adam Belay
pnp: PnP ACPI init
ACPI: bus type pnp registered
pnp: PnP ACPI: found 6 devices
ACPI: ACPI bus type pnp unregistered
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
PCI: Using ACPI for IRQ routing
PCI: If a device doesn't work, try "pci=routeirq".  If it helps, post a report
NetLabel: Initializing
NetLabel:  domain hash size = 128
NetLabel:  protocols = UNLABELED CIPSOv4
NetLabel:  unlabeled traffic allowed by default
PCI-GART: No AMD northbridge found.
Time: tsc clocksource has been installed.
NET: Registered protocol family 2
IP route cache hash table entries: 4096 (order: 3, 32768 bytes)
TCP established hash table entries: 16384 (order: 6, 393216 bytes)
TCP bind hash table entries: 16384 (order: 6, 262144 bytes)
TCP: Hash tables configured (established 16384 bind 16384)
TCP reno registered
checking if image is initramfs... it is
Freeing initrd memory: 3751k freed
audit: initializing netlink socket (disabled)
audit(1185547631.924:1): initialized
Total HugeTLB memory allocated, 0
VFS: Disk quotas dquot_6.5.1
Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
SELinux:  Registering netfilter hooks
ksign: Installing public key data
Loading keyring
- Added public key 84686AF648AEAA42
- User ID: Red Hat, Inc. (Kernel Module GPG key)
io scheduler noop registered
io scheduler anticipatory registered
io scheduler deadline registered
io scheduler cfq registered (default)
Limiting direct PCI/PCI transfers.
PCI: PIIX3: Enabling Passive Release on 0000:00:01.0
Activating ISA DMA hang workarounds.
Boot video device is 0000:00:02.0
pci_hotplug: PCI Hot Plug PCI Core version: 0.5
Generic RTC Driver v1.07
Non-volatile memory driver v1.2
Linux agpgart interface v0.102 (c) Dave Jones
Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing enabled
00:05: ttyS0 at I/O 0x3f8 (irq = 4) is a 16450
RAMDISK driver initialized: 16 RAM disks of 16384K size 4096 blocksize
input: Macintosh mouse button emulation as /class/input/input0
PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
serio: i8042 KBD port at 0x60,0x64 irq 1
serio: i8042 AUX port at 0x60,0x64 irq 12
mice: PS/2 mouse device common for all mice
input: AT Translated Set 2 keyboard as /class/input/input1
usbcore: registered new interface driver hiddev
usbcore: registered new interface driver usbhid
drivers/hid/usbhid/hid-core.c: v2.6:USB HID core driver
TCP cubic registered
Initializing XFRM netlink socket
NET: Registered protocol family 1
NET: Registered protocol family 17
powernow-k8: Processor cpuid 623 not supported
drivers/rtc/hctosys.c: unable to open rtc device (rtc0)
Freeing unused kernel memory: 312k freed
Write protecting the kernel read-only data: 1060k
input: ImExPS/2 Generic Explorer Mouse as /class/input/input2
USB Universal Host Controller Interface driver v3.0
ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 9
ACPI: PCI Interrupt 0000:00:01.2[D] -> Link [LNKD] -> GSI 9 (level, low) -> IRQ 9
PCI: Setting latency timer of device 0000:00:01.2 to 64
uhci_hcd 0000:00:01.2: UHCI Host Controller
uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
uhci_hcd 0000:00:01.2: irq 9, io base 0x0000c020
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 2 ports detected
ohci_hcd: 2006 August 04 USB 1.1 'Open' Host Controller (OHCI) Driver
usb 1-2: new full speed USB device using uhci_hcd and address 2
SCSI subsystem initialized
libata version 2.21 loaded.
ata_piix 0000:00:01.1: version 2.11
PCI: Setting latency timer of device 0000:00:01.1 to 64
scsi0 : ata_piix
scsi1 : ata_piix
ata1: PATA max MWDMA2 cmd 0x00000000000101f0 ctl 0x00000000000103f6 bmdma 0x000000000001c000 irq 14
ata2: PATA max MWDMA2 cmd 0x0000000000010170 ctl 0x0000000000010376 bmdma 0x000000000001c008 irq 15
usb 1-2: configuration #1 chosen from 1 choice
input: QEMU 0.9.0 QEMU USB Tablet as /class/input/input3
input: USB HID v0.01 Pointer [QEMU 0.9.0 QEMU USB Tablet] on usb-0000:00:01.2-2
ata1.00: ATA-7: QEMU HARDDISK, 0.9.0, max UDMA/100
ata1.00: 8388608 sectors, multi 16: LBA48 
ata1.00: configured for MWDMA2
ata2.00: ATAPI: QEMU CD-ROM, 0.9.0, max UDMA/100
ata2.00: configured for MWDMA2
scsi 0:0:0:0: Direct-Access     ATA      QEMU HARDDISK    0.9. PQ: 0 ANSI: 5
sd 0:0:0:0: [sda] 8388608 512-byte hardware sectors (4295 MB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
sd 0:0:0:0: [sda] 8388608 512-byte hardware sectors (4295 MB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
 sda: sda1 sda2
sd 0:0:0:0: [sda] Attached SCSI disk
scsi 1:0:0:0: CD-ROM            QEMU     QEMU CD-ROM      0.9. PQ: 0 ANSI: 5
device-mapper: ioctl: 4.11.0-ioctl (2006-10-12) initialised: dm-devel@redhat.com
kjournald starting.  Commit interval 5 seconds
EXT3-fs: mounted filesystem with ordered data mode.
audit(1185547638.275:2): enforcing=1 old_enforcing=0 auid=4294967295
security:  3 users, 6 roles, 1816 types, 78 bools, 1 sens, 1024 cats
security:  60 classes, 65638 rules
SELinux:  Completing initialization.
SELinux:  Setting up existing superblocks.
SELinux: initialized (dev dm-0, type ext3), uses xattr
SELinux: initialized (dev usbfs, type usbfs), uses genfs_contexts
SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
SELinux: initialized (dev debugfs, type debugfs), uses genfs_contexts
SELinux: initialized (dev selinuxfs, type selinuxfs), uses genfs_contexts
SELinux: initialized (dev mqueue, type mqueue), uses transition SIDs
SELinux: initialized (dev hugetlbfs, type hugetlbfs), uses genfs_contexts
SELinux: initialized (dev devpts, type devpts), uses transition SIDs
SELinux: initialized (dev inotifyfs, type inotifyfs), uses genfs_contexts
SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
SELinux: initialized (dev futexfs, type futexfs), uses genfs_contexts
SELinux: initialized (dev anon_inodefs, type anon_inodefs), not configured for labeling
SELinux: initialized (dev pipefs, type pipefs), uses task SIDs
SELinux: initialized (dev sockfs, type sockfs), uses task SIDs
SELinux: initialized (dev cpuset, type cpuset), uses genfs_contexts
SELinux: initialized (dev proc, type proc), uses genfs_contexts
SELinux: initialized (dev bdev, type bdev), uses genfs_contexts
SELinux: initialized (dev rootfs, type rootfs), uses genfs_contexts
SELinux: initialized (dev sysfs, type sysfs), uses genfs_contexts
audit(1185547640.046:3): policy loaded auid=4294967295
sd 0:0:0:0: Attached scsi generic sg0 type 0
scsi 1:0:0:0: Attached scsi generic sg1 type 5
sr0: scsi3-mmc drive: 4x/4x xa/form2 tray
Uniform CD-ROM driver Revision: 3.20
sr 1:0:0:0: Attached scsi CD-ROM sr0
ne2k-pci.c:v1.03 9/22/2003 D. Becker/P. Gortmaker
ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 10
ACPI: PCI Interrupt 0000:00:03.0[A] -> Link [LNKC] -> GSI 10 (level, low) -> IRQ 10
eth0: RealTek RTL-8029 found at 0xc100, IRQ 10, 52:54:00:12:34:56.
parport_pc 00:04: reported by Plug and Play ACPI
parport0: PC-style at 0x378, irq 7 [PCSPP,EPP]
loop: module loaded
FDC 0 is a S82078B
lp0: using parport0 (interrupt-driven).
lp0: console ready
No dock devices found.
device-mapper: multipath: version 1.0.5 loaded
EXT3 FS on dm-0, internal journal
kjournald starting.  Commit interval 5 seconds
EXT3 FS on sda1, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
SELinux: initialized (dev sda1, type ext3), uses xattr
SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
Adding 1048568k swap on /dev/VolGroup00/LogVol01.  Priority:-1 extents:1 across:1048568k
SELinux: initialized (dev binfmt_misc, type binfmt_misc), uses genfs_contexts