Description of problem: Starting guestfish as a non-root user and adding a guest image which you only have read permission, trying to mount will hang there. Version-Release number of selected component (if applicable): guestfish 1.3.5 How reproducible: Always Steps to Reproduce: 1. $ id yufang uid=500(yufang) gid=500(yufang) groups=500(yufang) $ ll /mnt/RHEL-Server-5.4-32-pv.raw -rw-r--r-- 1 root root 6442450944 2010-04-20 20:15 /mnt/RHEL-Server-5.4-32-pv.raw 2. As the user 'yufang', add the image as rw mode: $ fish/guestfish -a /mnt/RHEL-Server-5.4-32-pv.raw 3. launch the guest and try to do mount: ><fs> run ... ><fs> lvs lvs send_to_daemon: 0x248f070 g->state = 3, n = 28 recv_from_daemon: 0x248f070 g->state = 3, size_rtn = 0x7fff93c9f76c, buf_rtn = 0x7fff93c9f760 lvm lvs -o vg_name,lv_name --noheadings --separator / File descriptor 3 (socket:[8013]) leaked on lvm invocation. Parent PID 1: guestfsd proc 11 (lvs) took 0.04 seconds /dev/VolGroup00/LogVol00 /dev/VolGroup00/LogVol01 ><fs> mount /dev/VolGroup00/LogVol00 / mount "/dev/VolGroup00/LogVol00" "/" send_to_daemon: 0x248f070 g->state = 3, n = 64 recv_from_daemon: 0x248f070 g->state = 3, size_rtn = 0x7fff93c9f75c, buf_rtn = 0x7fff93c9f750 mount -o sync,noatime /dev/VolGroup00/LogVol00 /sysroot/ [ 59.075557] kjournald starting. Commit interval 5 seconds [ 241.549151] INFO: task mount:284 blocked for more than 120 seconds. [ 241.605020] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 241.608202] mount D 0000000000000002 0 284 1 0x00000000 [ 241.610834] ffff88001ec8da58 0000000000000086 ffff8800176aa060 ffffffff816ba6c0 [ 241.615487] 0000000000001d04 ffffffffb432624c ffff88001ec8dfd8 ffff88001ec8dfd8 [ 241.618699] ffff88001ec283d8 000000000000f980 0000000000015740 ffff88001ec283d8 [ 241.621485] Call Trace: [ 241.622533] [<ffffffff8107c359>] ? ktime_get_ts+0x85/0x8e [ 241.624602] [<ffffffff8114132a>] ? sync_buffer+0x0/0x44 [ 241.626820] [<ffffffff8114132a>] ? sync_buffer+0x0/0x44 [ 241.628784] [<ffffffff81454c1d>] io_schedule+0x43/0x5d [ 241.630546] [<ffffffff8114136a>] sync_buffer+0x40/0x44 [ 241.633142] [<ffffffff81455170>] __wait_on_bit+0x48/0x7b [ 241.634986] [<ffffffff81455211>] out_of_line_wait_on_bit+0x6e/0x79 [ 241.637579] [<ffffffff8114132a>] ? sync_buffer+0x0/0x44 [ 241.639639] [<ffffffff810748c4>] ? wake_bit_function+0x0/0x33 [ 241.641849] [<ffffffff8114128d>] __wait_on_buffer+0x24/0x26 [ 241.643979] [<ffffffff811412cc>] wait_on_buffer+0x3d/0x41 [ 241.645826] [<ffffffff811415c2>] sync_dirty_buffer+0x60/0x99 [ 241.648062] [<ffffffff81187460>] ext3_commit_super.clone.0+0x61/0x69 [ 241.653454] [<ffffffff81187bdc>] ext3_setup_super+0xf0/0x1a3 [ 241.655419] [<ffffffff811e62ab>] ? security_d_instantiate+0x24/0x26 [ 241.659701] [<ffffffff8112e66a>] ? d_instantiate+0x49/0x4e [ 241.662335] [<ffffffff8118942f>] ext3_fill_super+0x12f8/0x174e [ 241.664768] [<ffffffff8145607b>] ? __down_write_nested+0x17/0xab [ 241.667547] [<ffffffff8111d91c>] ? sget+0x3a5/0x3bb [ 241.669407] [<ffffffff8111e002>] get_sb_bdev+0x139/0x19c [ 241.671495] [<ffffffff81188137>] ? ext3_fill_super+0x0/0x174e [ 241.673643] [<ffffffff81185b38>] ext3_get_sb+0x18/0x1a [ 241.675609] [<ffffffff8111dbca>] vfs_kern_mount+0xa9/0x168 [ 241.677996] [<ffffffff8111dcf1>] do_kern_mount+0x4d/0xed [ 241.679913] [<ffffffff81135c40>] do_mount+0x731/0x793 [ 241.681763] [<ffffffff810ea72b>] ? strndup_user+0x5d/0x86 [ 241.683782] [<ffffffff81135d2a>] sys_mount+0x88/0xc2 [ 241.685505] [<ffffffff81011d32>] system_call_fastpath+0x16/0x1b [ 241.688963] INFO: task flush-253:0:286 blocked for more than 120 seconds. [ 241.692571] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 241.695593] flush-253:0 D ffffffff8114132a 0 286 2 0x00000000 [ 241.698025] ffff88001eda9900 0000000000000046 0000000000000000 ffffffff816ba6c0 [ 241.700161] 0000000000001f28 ffffffffb432624c ffff88001eda9fd8 ffff88001eda9fd8 [ 241.702187] ffff88001ec2b298 000000000000f980 0000000000015740 ffff88001ec2b298 [ 241.706802] Call Trace: [ 241.707546] [<ffffffff8107c359>] ? ktime_get_ts+0x85/0x8e [ 241.709047] [<ffffffff8114132a>] ? sync_buffer+0x0/0x44 [ 241.710799] [<ffffffff81454c1d>] io_schedule+0x43/0x5d [ 241.712136] [<ffffffff8114136a>] sync_buffer+0x40/0x44 [ 241.713593] [<ffffffff81455066>] __wait_on_bit_lock+0x46/0x8f [ 241.715388] [<ffffffff8145511d>] out_of_line_wait_on_bit_lock+0x6e/0x79 [ 241.717267] [<ffffffff8114132a>] ? sync_buffer+0x0/0x44 [ 241.718853] [<ffffffff810748c4>] ? wake_bit_function+0x0/0x33 [ 241.720442] [<ffffffff8122a47f>] ? __lookup_tag+0x6d/0x12d [ 241.721818] [<ffffffff811414e8>] __lock_buffer+0x2a/0x2c [ 241.723222] [<ffffffff81141526>] lock_buffer+0x3c/0x40 [ 241.724705] [<ffffffff811424e0>] __block_write_full_page+0x15a/0x2b3 [ 241.726630] [<ffffffff81144a96>] ? blkdev_get_block+0x0/0x63 [ 241.728528] [<ffffffff81142baf>] ? end_buffer_async_write+0x0/0x129 [ 241.730125] [<ffffffff81142baf>] ? end_buffer_async_write+0x0/0x129 [ 241.731997] [<ffffffff81144a96>] ? blkdev_get_block+0x0/0x63 [ 241.733620] [<ffffffff811426c2>] block_write_full_page_endio+0x89/0x96 [ 241.735870] [<ffffffff811426e4>] block_write_full_page+0x15/0x17 [ 241.737554] [<ffffffff8114574e>] blkdev_writepage+0x18/0x1a [ 241.739526] [<ffffffff810dcb4c>] __writepage+0x17/0x30 [ 241.741256] [<ffffffff810dd1cc>] write_cache_pages+0x25c/0x3f0 [ 241.742874] [<ffffffff810dcb35>] ? __writepage+0x0/0x30 [ 241.744273] [<ffffffff810dd384>] generic_writepages+0x24/0x26 [ 241.746227] [<ffffffff810dd3a7>] do_writepages+0x21/0x2a [ 241.747605] [<ffffffff8113a0bc>] writeback_single_inode+0xcc/0x1f1 [ 241.749394] [<ffffffff8113a85c>] writeback_inodes_wb+0x379/0x410 [ 241.752662] [<ffffffff8113aa1b>] wb_writeback+0x128/0x1a7 [ 241.754088] [<ffffffff8113ac86>] wb_do_writeback+0x13c/0x152 [ 241.755781] [<ffffffff8113acdb>] bdi_writeback_task+0x3f/0xaf [ 241.757193] [<ffffffff810ec576>] ? bdi_start_fn+0x0/0xd2 [ 241.758844] [<ffffffff810ec5e7>] bdi_start_fn+0x71/0xd2 [ 241.760191] [<ffffffff810ec576>] ? bdi_start_fn+0x0/0xd2 [ 241.762032] [<ffffffff8107459e>] kthread+0x7f/0x87 [ 241.763407] [<ffffffff81012d6a>] child_rip+0xa/0x20 [ 241.764782] [<ffffffff8107451f>] ? kthread+0x0/0x87 [ 241.766214] [<ffffffff81012d60>] ? child_rip+0x0/0x20 ... Actual results: Expected results: Additional info: If I add the image as read only mode, then mount will not hang but success without any error.
(In reply to comment #0) > 3. launch the guest and try to do mount: > ><fs> run > ... Yufang, could you show (or attach) the complete, unedited output please. I need to see what options we are using for qemu and how the kernel starts up.
(In reply to comment #1) > (In reply to comment #0) > > 3. launch the guest and try to do mount: > > ><fs> run > > ... > > Yufang, could you show (or attach) the complete, unedited output > please. I need to see what options we are using for qemu and how > the kernel starts up. Below is the output of run: ><fs> run is_config launch looking for supermin appliance in appliance looking for supermin appliance in /usr/local/lib/guestfs looking for appliance in appliance [00059ms] begin testing qemu features null_vmchannel_sock = 45055 [00671ms] finished testing qemu features accept_from_daemon: 0x22e7070 g->state = 0 /usr/bin/qemu-kvm \ -drive file=/mnt/RHEL-Server-5.4-32-pv.raw,cache=off,if=virtio \ -enable-kvm \ -nographic \ -serial stdio \ -m 500 \ -no-reboot \ -no-hpet \ -rtc-td-hack \ -net user,vlan=0,net=10.0.2.0/8 \ -net nic,model=virtio,vlan=0 \ -kernel appliance/vmlinuz.fedora-12.x86_64 \ -initrd appliance/initramfs.fedora-12.x86_64.img \ -append 'panic=1 console=ttyS0 udevtimeout=300 noapic acpi=off printk.time=1 cgroup_disable=memory selinux=0 guestfs_vmchannel=tcp:10.0.2.2:45055 guestfs_verbose=1 TERM=xterm ' Initializing cgroup subsys cpuset Initializing cgroup subsys cpu Linux version 2.6.32.11-99.fc12.x86_64 (mockbuild.fedoraproject.org) (gcc version 4.4.3 20100127 (Red Hat 4.4.3-4) (GCC) ) #1 SMP Mon Apr 5 19:59:38 UTC 2010 Command line: panic=1 console=ttyS0 udevtimeout=300 noapic acpi=off printk.time=1 cgroup_disable=memory selinux=0 guestfs_vmchannel=tcp:10.0.2.2:45055 guestfs_verbose=1 TERM=xterm KERNEL supported cpus: Intel GenuineIntel AMD AuthenticAMD Centaur CentaurHauls BIOS-provided physical RAM map: BIOS-e820: 0000000000000000 - 000000000009f000 (usable) BIOS-e820: 000000000009f000 - 00000000000a0000 (reserved) BIOS-e820: 00000000000e8000 - 0000000000100000 (reserved) BIOS-e820: 0000000000100000 - 000000001f3f0000 (usable) BIOS-e820: 000000001f3f0000 - 000000001f400000 (ACPI data) BIOS-e820: 00000000fffbc000 - 0000000100000000 (reserved) DMI 2.4 present. last_pfn = 0x1f3f0 max_arch_pfn = 0x400000000 PAT not supported by CPU. init_memory_mapping: 0000000000000000-000000001f3f0000 RAMDISK: 1d663000 - 1f3ef75e No NUMA configuration found Faking a node at 0000000000000000-000000001f3f0000 Bootmem setup node 0 0000000000000000-000000001f3f0000 NODE_DATA [0000000000009000 - 000000000001efff] bootmap [000000000001f000 - 0000000000022e7f] pages 4 (7 early reservations) ==> bootmem [0000000000 - 001f3f0000] #0 [0000000000 - 0000001000] BIOS data page ==> [0000000000 - 0000001000] #1 [0000006000 - 0000008000] TRAMPOLINE ==> [0000006000 - 0000008000] #2 [0001000000 - 0001a53ee8] TEXT DATA BSS ==> [0001000000 - 0001a53ee8] #3 [001d663000 - 001f3ef75e] RAMDISK ==> [001d663000 - 001f3ef75e] #4 [000009fc00 - 0000100000] BIOS reserved ==> [000009fc00 - 0000100000] #5 [0001a54000 - 0001a5403d] BRK ==> [0001a54000 - 0001a5403d] #6 [0000008000 - 0000009000] PGTABLE ==> [0000008000 - 0000009000] found SMP MP-table at [ffff8800000fbc20] fbc20 kvm-clock: cpu 0, msr 0:18156c1, boot clock Zone PFN ranges: DMA 0x00000000 -> 0x00001000 DMA32 0x00001000 -> 0x00100000 Normal 0x00100000 -> 0x00100000 Movable zone start PFN for each node early_node_map[2] active PFN ranges 0: 0x00000000 -> 0x0000009f 0: 0x00000100 -> 0x0001f3f0 SFI: Simple Firmware Interface v0.7 http://simplefirmware.org Intel MultiProcessor Specification v1.4 MPTABLE: OEM ID: QEMUCPU MPTABLE: Product ID: 0.1 MPTABLE: APIC at: 0xFEE00000 Processor #0 (Bootup-CPU) I/O APIC #1 Version 17 at 0xFEC00000. Processors: 1 SMP: Allowing 16 CPUs, 15 hotplug CPUs PM: Registered nosave memory: 000000000009f000 - 00000000000a0000 PM: Registered nosave memory: 00000000000a0000 - 00000000000e8000 PM: Registered nosave memory: 00000000000e8000 - 0000000000100000 Allocating PCI resources starting at 1f400000 (gap: 1f400000:e0bbc000) Booting paravirtualized kernel on KVM NR_CPUS:256 nr_cpumask_bits:256 nr_cpu_ids:16 nr_node_ids:1 PERCPU: Embedded 30 pages/cpu @ffff880001c00000 s90392 r8192 d24296 u131072 pcpu-alloc: s90392 r8192 d24296 u131072 alloc=1*2097152 pcpu-alloc: [0] 00 01 02 03 04 05 06 07 08 09 10 11 12 13 14 15 kvm-clock: cpu 0, msr 0:1c156c1, primary cpu clock Built 1 zonelists in Node order, mobility grouping on. Total pages: 126037 Policy zone: DMA32 Kernel command line: panic=1 console=ttyS0 udevtimeout=300 noapic acpi=off printk.time=1 cgroup_disable=memory selinux=0 guestfs_vmchannel=tcp:10.0.2.2:45055 guestfs_verbose=1 TERM=xterm [ 0.000000] Disabling memory control group subsystem [ 0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes) [ 0.000000] Initializing CPU#0 [ 0.000000] Checking aperture... [ 0.000000] No AGP bridge found [ 0.000000] Memory: 460232k/511936k available (4465k kernel code, 388k absent, 51316k reserved, 3720k data, 936k init) [ 0.000000] SLUB: Genslabs=14, HWalign=64, Order=0-3, MinObjects=0, CPUs=16, Nodes=1 [ 0.000000] Hierarchical RCU implementation. [ 0.000000] NR_IRQS:4352 nr_irqs:536 [ 0.000000] Console: colour VGA+ 80x25 [ 0.000000] console [ttyS0] enabled [ 0.000000] Detected 2260.832 MHz processor. [ 0.002999] Calibrating delay loop (skipped) preset value.. 4521.66 BogoMIPS (lpj=2260832) [ 0.004171] Security Framework initialized [ 0.005030] SELinux: Disabled at boot. [ 0.007824] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes) [ 0.010327] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes) [ 0.012263] Mount-cache hash table entries: 256 [ 0.015217] Initializing cgroup subsys ns [ 0.016025] Initializing cgroup subsys cpuacct [ 0.018010] Initializing cgroup subsys memory [ 0.019050] Initializing cgroup subsys devices [ 0.020010] Initializing cgroup subsys freezer [ 0.022019] Initializing cgroup subsys net_cls [ 0.025022] CPU: L1 I cache: 32K, L1 D cache: 32K [ 0.027001] CPU: L2 cache: 2048K [ 0.028014] CPU 0/0x0 -> Node 0 [ 0.030019] mce: CPU supports 10 MCE banks [ 0.032145] Performance Events: unsupported p6 CPU model 2 no PMU driver, software events only. [ 0.036195] SMP alternatives: switching to UP code [ 0.173097] ftrace: converting mcount calls to 0f 1f 44 00 00 [ 0.175016] ftrace: allocating 23786 entries in 94 pages [ 0.230299] Setting APIC routing to physical flat [ 0.232116] CPU0: Intel QEMU Virtual CPU version 0.11.0 stepping 03 [ 0.337558] Brought up 1 CPUs [ 0.338007] Total of 1 processors activated (4521.66 BogoMIPS). [ 0.341025] devtmpfs: initialized [ 0.346799] regulator: core version 0.5 [ 0.348132] Time: 13:26:45 Date: 04/20/10 [ 0.350212] NET: Registered protocol family 16 [ 0.353679] PCI: Using configuration type 1 for base access [ 0.356498] bio: create slab <bio-0> at 0 [ 0.357229] ACPI: Interpreter disabled. [ 0.359071] vgaarb: loaded [ 0.360273] SCSI subsystem initialized [ 0.361335] usbcore: registered new interface driver usbfs [ 0.363059] usbcore: registered new interface driver hub [ 0.365090] usbcore: registered new device driver usb [ 0.368175] PCI: Probing PCI hardware [ 0.371459] pci 0000:00:01.3: quirk: region b000-b03f claimed by PIIX4 ACPI [ 0.373022] pci 0000:00:01.3: quirk: region b100-b10f claimed by PIIX4 SMB [ 0.384715] vgaarb: device added: PCI:0000:00:02.0,decodes=io+mem,owns=io+mem,locks=none [ 0.386235] pci 0000:00:01.0: PIIX/ICH IRQ router [8086:7000] [ 0.390279] NetLabel: Initializing [ 0.391004] NetLabel: domain hash size = 128 [ 0.393003] NetLabel: protocols = UNLABELED CIPSOv4 [ 0.396042] NetLabel: unlabeled traffic allowed by default [ 0.397319] Switching to clocksource kvm-clock [ 0.415948] pnp: PnP ACPI: disabled [ 0.418282] NET: Registered protocol family 2 [ 0.420438] IP route cache hash table entries: 4096 (order: 3, 32768 bytes) [ 0.423918] TCP established hash table entries: 16384 (order: 6, 262144 bytes) [ 0.428303] TCP bind hash table entries: 16384 (order: 6, 262144 bytes) [ 0.431535] TCP: Hash tables configured (established 16384 bind 16384) [ 0.434524] TCP reno registered [ 0.436692] NET: Registered protocol family 1 [ 0.438906] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.441624] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.444320] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.448716] Trying to unpack rootfs image as initramfs... [ 1.390816] Freeing initrd memory: 30257k freed [ 1.412073] platform rtc_cmos: registered platform RTC device (no PNP device found) [ 1.416044] audit: initializing netlink socket (disabled) [ 1.418675] type=2000 audit(1271770007.418:1): initialized [ 1.431901] HugeTLB registered 2 MB page size, pre-allocated 0 pages [ 1.438863] VFS: Disk quotas dquot_6.5.2 [ 1.440672] Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.444409] msgmni has been set to 957 [ 1.446585] alg: No test for stdrng (krng) [ 1.448440] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252) [ 1.452062] io scheduler noop registered [ 1.453644] io scheduler anticipatory registered [ 1.456393] io scheduler deadline registered [ 1.457707] io scheduler cfq registered (default) [ 1.459177] pci_hotplug: PCI Hot Plug PCI Core version: 0.5 [ 1.461088] pciehp: PCI Express Hot Plug Controller Driver version: 0.4 [ 1.463765] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 1.467249] pci-stub: invalid id string "" [ 1.472967] Non-volatile memory driver v1.3 [ 1.474255] Linux agpgart interface v0.103 [ 1.475666] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled �[ 1.722693] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A [ 1.736319] brd: module loaded [ 1.738866] loop: module loaded [ 1.740285] input: Macintosh mouse button emulation as /devices/virtual/input/input0 [ 1.744147] scsi0 : ata_piix [ 1.744949] scsi1 : ata_piix [ 1.745705] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc000 irq 14 [ 1.747807] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc008 irq 15 [ 1.752351] Fixed MDIO Bus: probed [ 1.754003] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver [ 1.756877] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver [ 1.758841] uhci_hcd: USB Universal Host Controller Interface driver [ 1.760742] PNP: No PS/2 controller found. Probing ports directly. [ 1.763579] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 1.765370] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 1.767641] mice: PS/2 mouse device common for all mice [ 1.769676] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 1.773330] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0 [ 1.778143] rtc0: alarms up to one day, 114 bytes nvram [ 1.779983] device-mapper: uevent: version 1.0.3 [ 1.784614] device-mapper: ioctl: 4.15.0-ioctl (2009-04-01) initialised: dm-devel [ 1.788589] cpuidle: using governor ladder [ 1.789831] cpuidle: using governor menu [ 1.791494] usbcore: registered new interface driver hiddev [ 1.793682] usbcore: registered new interface driver usbhid [ 1.796074] usbhid: v2.6:USB HID core driver [ 1.797999] nf_conntrack version 0.5.0 (3831 buckets, 15324 max) [ 1.799974] CONFIG_NF_CT_ACCT is deprecated and will be removed soon. Please use [ 1.801980] nf_conntrack.acct=1 kernel parameter, acct=1 nf_conntrack module option or [ 1.804026] sysctl net.netfilter.nf_conntrack_acct=1 to enable it. [ 1.805703] ip_tables: (C) 2000-2006 Netfilter Core Team [ 1.807379] TCP cubic registered [ 1.808250] Initializing XFRM netlink socket [ 1.809435] NET: Registered protocol family 17 [ 1.811906] registered taskstats version 1 [ 1.813675] No TPM chip found, activating TPM-bypass! [ 1.816195] Magic number: 6:243:433 [ 1.819123] rtc_cmos rtc_cmos: setting system clock to 2010-04-20 13:26:47 UTC (1271770007) [ 1.821809] Initalizing network drop monitor service [ 1.905377] ata2.00: ATAPI: QEMU DVD-ROM, 0.11.0, max UDMA/100 [ 1.911903] ata2.00: configured for MWDMA2 [ 1.922924] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 0.11 PQ: 0 ANSI: 5 [ 1.933625] sr0: scsi3-mmc drive: 4x/4x xa/form2 tray [ 1.935737] Uniform CD-ROM driver Revision: 3.20 [ 1.938373] sr 1:0:0:0: Attached scsi generic sg0 type 5 [ 1.941412] Freeing unused kernel memory: 936k freed [ 1.948043] Write protecting the kernel read-only data: 6592k Starting /init script ... Starting udev: [ 2.177948] udev: starting version 145 [ 2.217087] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input2 [ 2.403206] virtio-pci 0000:00:03.0: found PCI INT A -> IRQ 11 [ 2.443920] virtio-pci 0000:00:04.0: found PCI INT A -> IRQ 11 [ 2.496888] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0xb100, revision 0 [ 2.514561] virtio-pci 0000:00:05.0: found PCI INT A -> IRQ 10 [ 2.573158] vda: vda1 vda2 [ OK ] FATAL: Module dm_mod not found. Reading all physical volumes. This may take a while... Found volume group "VolGroup00" using metadata type lvm2 2 logical volume(s) in volume group "VolGroup00" now active total 0 lrwxrwxrwx 1 root root 13 Apr 20 09:26 MAKEDEV -> /sbin/MAKEDEV drwxr-xr-x 2 root root 80 Apr 20 09:26 VolGroup00 drwxr-xr-x 2 root root 640 Apr 20 09:26 block drwxr-xr-x 2 root root 60 Apr 20 09:26 bsg lrwxrwxrwx 1 root root 3 Apr 20 2010 cdrom -> sr0 drwxr-xr-x 2 root root 2140 Apr 20 2010 char crw------- 1 root root 5, 1 Apr 20 09:26 console lrwxrwxrwx 1 root root 11 Apr 20 09:26 core -> /proc/kcore drwxr-xr-x 3 root root 60 Apr 20 09:26 cpu crw-rw---- 1 root root 10, 61 Apr 20 09:26 cpu_dma_latency drwxr-xr-x 5 root root 100 Apr 20 2010 disk brw-rw---- 1 root disk 253, 0 Apr 20 09:26 dm-0 brw-rw---- 1 root disk 253, 1 Apr 20 09:26 dm-1 lrwxrwxrwx 1 root root 13 Apr 20 09:26 fd -> /proc/self/fd crw-rw-rw- 1 root root 1, 7 Apr 20 09:26 full crw-rw-rw- 1 root root 10, 229 Apr 20 09:26 fuse drwxr-xr-x 2 root root 40 Apr 20 09:26 hugepages drwxr-xr-x 3 root root 180 Apr 20 2010 input crw-rw---- 1 root root 1, 11 Apr 20 09:26 kmsg brw-rw---- 1 root disk 7, 0 Apr 20 09:26 loop0 brw-rw---- 1 root disk 7, 1 Apr 20 09:26 loop1 brw-rw---- 1 root disk 7, 2 Apr 20 09:26 loop2 brw-rw---- 1 root disk 7, 3 Apr 20 09:26 loop3 brw-rw---- 1 root disk 7, 4 Apr 20 09:26 loop4 brw-rw---- 1 root disk 7, 5 Apr 20 09:26 loop5 brw-rw---- 1 root disk 7, 6 Apr 20 09:26 loop6 brw-rw---- 1 root disk 7, 7 Apr 20 09:26 loop7 crw-rw---- 1 root lp 6, 0 Apr 20 09:26 lp0 crw-rw---- 1 root lp 6, 1 Apr 20 09:26 lp1 crw-rw---- 1 root lp 6, 2 Apr 20 09:26 lp2 crw-rw---- 1 root lp 6, 3 Apr 20 09:26 lp3 drwxr-xr-x 2 root root 100 Apr 20 09:26 mapper crw-rw---- 1 root root 10, 227 Apr 20 09:26 mcelog crw-r----- 1 root kmem 1, 1 Apr 20 09:26 mem drwxr-xr-x 2 root root 60 Apr 20 09:26 net crw-rw---- 1 root root 10, 60 Apr 20 09:26 network_latency crw-rw---- 1 root root 10, 59 Apr 20 09:26 network_throughput crw-rw-rw- 1 root root 1, 3 Apr 20 09:26 null crw-r----- 1 root kmem 10, 144 Apr 20 09:26 nvram crw-rw---- 1 root root 1, 12 Apr 20 09:26 oldmem crw-r----- 1 root kmem 1, 4 Apr 20 09:26 port crw------- 1 root root 108, 0 Apr 20 09:26 ppp crw-rw-rw- 1 root tty 5, 2 Apr 20 09:26 ptmx drwxr-xr-x 2 root root 40 Apr 20 09:26 pts brw-rw---- 1 root disk 1, 0 Apr 20 09:26 ram0 brw-rw---- 1 root disk 1, 1 Apr 20 09:26 ram1 brw-rw---- 1 root disk 1, 10 Apr 20 09:26 ram10 brw-rw---- 1 root disk 1, 11 Apr 20 09:26 ram11 brw-rw---- 1 root disk 1, 12 Apr 20 09:26 ram12 brw-rw---- 1 root disk 1, 13 Apr 20 09:26 ram13 brw-rw---- 1 root disk 1, 14 Apr 20 09:26 ram14 brw-rw---- 1 root disk 1, 15 Apr 20 09:26 ram15 brw-rw---- 1 root disk 1, 2 Apr 20 09:26 ram2 brw-rw---- 1 root disk 1, 3 Apr 20 09:26 ram3 brw-rw---- 1 root disk 1, 4 Apr 20 09:26 ram4 brw-rw---- 1 root disk 1, 5 Apr 20 09:26 ram5 brw-rw---- 1 root disk 1, 6 Apr 20 09:26 ram6 brw-rw---- 1 root disk 1, 7 Apr 20 09:26 ram7 brw-rw---- 1 root disk 1, 8 Apr 20 09:26 ram8 brw-rw---- 1 root disk 1, 9 Apr 20 09:26 ram9 crw-rw-rw- 1 root root 1, 8 Apr 20 09:26 random drwxr-xr-x 2 root root 60 Apr 20 09:26 raw lrwxrwxrwx 1 root root 4 Apr 20 09:26 rtc -> rtc0 crw-rw---- 1 root root 254, 0 Apr 20 09:26 rtc0 lrwxrwxrwx 1 root root 3 Apr 20 2010 scd0 -> sr0 crw-rw---- 1 root cdrom 21, 0 Apr 20 09:26 sg0 drwxr-xr-x 2 root root 40 Apr 20 09:26 shm crw-rw---- 1 root root 10, 231 Apr 20 09:26 snapshot brw-rw---- 1 root cdrom 11, 0 Apr 20 09:26 sr0 lrwxrwxrwx 1 root root 15 Apr 20 09:26 stderr -> /proc/self/fd/2 lrwxrwxrwx 1 root root 15 Apr 20 09:26 stdin -> /proc/self/fd/0 lrwxrwxrwx 1 root root 15 Apr 20 09:26 stdout -> /proc/self/fd/1 crw-rw-rw- 1 root tty 5, 0 Apr 20 09:26 tty crw--w---- 1 root tty 4, 0 Apr 20 2010 tty0 crw--w---- 1 root tty 4, 1 Apr 20 09:26 tty1 crw--w---- 1 root tty 4, 10 Apr 20 09:26 tty10 crw--w---- 1 root tty 4, 11 Apr 20 09:26 tty11 crw--w---- 1 root tty 4, 12 Apr 20 09:26 tty12 crw--w---- 1 root tty 4, 13 Apr 20 09:26 tty13 crw--w---- 1 root tty 4, 14 Apr 20 09:26 tty14 crw--w---- 1 root tty 4, 15 Apr 20 09:26 tty15 crw--w---- 1 root tty 4, 16 Apr 20 09:26 tty16 crw--w---- 1 root tty 4, 17 Apr 20 09:26 tty17 crw--w---- 1 root tty 4, 18 Apr 20 09:26 tty18 crw--w---- 1 root tty 4, 19 Apr 20 09:26 tty19 crw--w---- 1 root tty 4, 2 Apr 20 09:26 tty2 crw--w---- 1 root tty 4, 20 Apr 20 09:26 tty20 crw--w---- 1 root tty 4, 21 Apr 20 09:26 tty21 crw--w---- 1 root tty 4, 22 Apr 20 09:26 tty22 crw--w---- 1 root tty 4, 23 Apr 20 09:26 tty23 crw--w---- 1 root tty 4, 24 Apr 20 09:26 tty24 crw--w---- 1 root tty 4, 25 Apr 20 09:26 tty25 crw--w---- 1 root tty 4, 26 Apr 20 09:26 tty26 crw--w---- 1 root tty 4, 27 Apr 20 09:26 tty27 crw--w---- 1 root tty 4, 28 Apr 20 09:26 tty28 crw--w---- 1 root tty 4, 29 Apr 20 09:26 tty29 crw--w---- 1 root tty 4, 3 Apr 20 09:26 tty3 crw--w---- 1 root tty 4, 30 Apr 20 09:26 tty30 crw--w---- 1 root tty 4, 31 Apr 20 09:26 tty31 crw--w---- 1 root tty 4, 32 Apr 20 09:26 tty32 crw--w---- 1 root tty 4, 33 Apr 20 09:26 tty33 crw--w---- 1 root tty 4, 34 Apr 20 09:26 tty34 crw--w---- 1 root tty 4, 35 Apr 20 09:26 tty35 crw--w---- 1 root tty 4, 36 Apr 20 09:26 tty36 crw--w---- 1 root tty 4, 37 Apr 20 09:26 tty37 crw--w---- 1 root tty 4, 38 Apr 20 09:26 tty38 crw--w---- 1 root tty 4, 39 Apr 20 09:26 tty39 crw--w---- 1 root tty 4, 4 Apr 20 09:26 tty4 crw--w---- 1 root tty 4, 40 Apr 20 09:26 tty40 crw--w---- 1 root tty 4, 41 Apr 20 09:26 tty41 crw--w---- 1 root tty 4, 42 Apr 20 09:26 tty42 crw--w---- 1 root tty 4, 43 Apr 20 09:26 tty43 crw--w---- 1 root tty 4, 44 Apr 20 09:26 tty44 crw--w---- 1 root tty 4, 45 Apr 20 09:26 tty45 crw--w---- 1 root tty 4, 46 Apr 20 09:26 tty46 crw--w---- 1 root tty 4, 47 Apr 20 09:26 tty47 crw--w---- 1 root tty 4, 48 Apr 20 09:26 tty48 crw--w---- 1 root tty 4, 49 Apr 20 09:26 tty49 crw--w---- 1 root tty 4, 5 Apr 20 09:26 tty5 crw--w---- 1 root tty 4, 50 Apr 20 09:26 tty50 crw--w---- 1 root tty 4, 51 Apr 20 09:26 tty51 crw--w---- 1 root tty 4, 52 Apr 20 09:26 tty52 crw--w---- 1 root tty 4, 53 Apr 20 09:26 tty53 crw--w---- 1 root tty 4, 54 Apr 20 09:26 tty54 crw--w---- 1 root tty 4, 55 Apr 20 09:26 tty55 crw--w---- 1 root tty 4, 56 Apr 20 09:26 tty56 crw--w---- 1 root tty 4, 57 Apr 20 09:26 tty57 crw--w---- 1 root tty 4, 58 Apr 20 09:26 tty58 crw--w---- 1 root tty 4, 59 Apr 20 09:26 tty59 crw--w---- 1 root tty 4, 6 Apr 20 09:26 tty6 crw--w---- 1 root tty 4, 60 Apr 20 09:26 tty60 crw--w---- 1 root tty 4, 61 Apr 20 09:26 tty61 crw--w---- 1 root tty 4, 62 Apr 20 09:26 tty62 crw--w---- 1 root tty 4, 63 Apr 20 09:26 tty63 crw--w---- 1 root tty 4, 7 Apr 20 09:26 tty7 crw--w---- 1 root tty 4, 8 Apr 20 09:26 tty8 crw--w---- 1 root tty 4, 9 Apr 20 09:26 tty9 crw-rw---- 1 root dialout 4, 64 Apr 20 09:26 ttyS0 crw-rw---- 1 root dialout 4, 65 Apr 20 09:26 ttyS1 crw-rw---- 1 root dialout 4, 66 Apr 20 09:26 ttyS2 crw-rw---- 1 root dialout 4, 67 Apr 20 09:26 ttyS3 crw-rw-rw- 1 root root 1, 9 Apr 20 09:26 urandom crw-rw---- 1 root root 251, 0 Apr 20 09:26 usbmon0 crw-rw---- 1 vcsa tty 7, 0 Apr 20 09:26 vcs crw-rw---- 1 vcsa tty 7, 1 Apr 20 09:26 vcs1 crw-rw---- 1 vcsa tty 7, 128 Apr 20 09:26 vcsa crw-rw---- 1 vcsa tty 7, 129 Apr 20 09:26 vcsa1 brw-rw---- 1 root disk 252, 0 Apr 20 2010 vda brw-rw---- 1 root disk 252, 1 Apr 20 2010 vda1 brw-rw---- 1 root disk 252, 2 Apr 20 2010 vda2 crw-rw---- 1 root root 10, 63 Apr 20 09:26 vga_arbiter crw-rw-rw- 1 root root 1, 5 Apr 20 09:26 zero rootfs / rootfs rw 0 0 /proc /proc proc rw,relatime 0 0 /sys /sys sysfs rw,relatime 0 0 none /dev devtmpfs rw,relatime,size=230116k,nr_inodes=57529,mode=755 0 0 PV VG Fmt Attr PSize PFree /dev/vda2 VolGroup00 lvm2 a- 5.88G 0 VG #PV #LV #SN Attr VSize VFree VolGroup00 1 2 0 wz--n- 5.88G 0 LV VG Attr LSize Origin Snap% Move Log Copy% Convert LogVol00 VolGroup00 -wi-a- 4.84G LogVol01 VolGroup00 -wi-a- 1.03G eth0 Link encap:Ethernet HWaddr 52:54:00:12:34:56 inet addr:10.0.2.10 Bcast:10.255.255.255 Mask:255.0.0.0 UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:0 errors:0 dropped:0 overruns:0 frame:0 TX packets:0 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:0 (0.0 b) TX bytes:0 (0.0 b) lo Link encap:Local Loopback inet addr:127.0.0.1 Mask:255.0.0.0 UP LOOPBACK RUNNING MTU:16436 Metric:1 RX packets:0 errors:0 dropped:0 overruns:0 frame:0 TX packets:0 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:0 RX bytes:0 (0.0 b) TX bytes:0 (0.0 b) Kernel IP routing table Destination Gateway Genmask Flags MSS Window irtt Iface 10.0.0.0 0.0.0.0 255.0.0.0 U 0 0 0 eth0 0.0.0.0 10.0.2.2 0.0.0.0 UG 0 0 0 eth0 Module Size Used by virtio_balloon 3271 0 virtio_net 14171 0 virtio_blk 4597 2 i2c_piix4 12139 0 virtio_pci 6211 0 virtio_ring 5164 1 virtio_pci i2c_core 26876 1 i2c_piix4 virtio 4282 4 virtio_balloon,virtio_net,virtio_blk,virtio_pci Tue Apr 20 09:26:49 EDT 2010 uptime: 4.36 1.22 verbose daemon enabled linux commmand line: panic=1 console=ttyS0 udevtimeout=300 noapic acpi=off printk.time=1 cgroup_disable=memory selinux=0 guestfs_vmchannel=tcp:10.0.2.2:45055 guestfs_verbose=1 TERM=xterm vmchannel: tcp:10.0.2.2:45055 recv_from_daemon: 0x22e7070 g->state = 1, size_rtn = 0x7fff82ec3aac, buf_rtn = 0x7fff82ec3a48 [10488ms] appliance is up
Which version of qemu is this? Is the filesystem that you are trying to mount ext3? XFS? Is the disk encrypted? ----- Reading around the issue, the error message "INFO: task mount ... blocked for more than 120 seconds." isn't very informative for us. It just says that an I/O operation was dropped by the block device (eg. qemu or virtio is dropping I/O operations), or else the kernel has lost track of an I/O op. But either way, mount is waiting for an I/O op to return which isn't returning, and eventually everything times out after 120 seconds. Without knowing what I/O op was dropped for what reason, there's not much we can do. FWIW I cannot reproduce this on Fedora 13, but that has a different version of qemu and a different kernel, so anything could be different.
(In reply to comment #3) > Which version of qemu is this? > > Is the filesystem that you are trying to mount ext3? XFS? > > Is the disk encrypted? Also: If you add '--ro' to the guestfish command line, does that fix the problem? How about if you use the 'mount-ro' command instead of 'mount'?
(In reply to comment #4) > (In reply to comment #3) > > Which version of qemu is this? > > > > Is the filesystem that you are trying to mount ext3? XFS? > > > > Is the disk encrypted? > > Also: > > If you add '--ro' to the guestfish command line, > does that fix the problem? Yeah, by adding the image readonly(with --ro), we could mount successfully. > How about if you use the 'mount-ro' command > instead of 'mount'? By adding the image as rw but using the 'mount-ro' command, we could also mount successfully.
(In reply to comment #3) > Which version of qemu is this? # rpm -qa | grep qemu qemu-kvm-0.10.6-9.fc11.x86_64 qemu-system-x86-0.10.6-9.fc11.x86_64 qemu-common-0.10.6-9.fc11.x86_64 qemu-img-0.10.6-9.fc11.x86_64 > Is the filesystem that you are trying to mount ext3? XFS? The filesystem is ext3, which exists on a LV. > Is the disk encrypted? The disk is not encrypted. > ----- > > Reading around the issue, the error message > "INFO: task mount ... blocked for more than 120 seconds." > isn't very informative for us. It just says that > an I/O operation was dropped by the block device > (eg. qemu or virtio is dropping I/O operations), > or else the kernel has lost track of an I/O op. But > either way, mount is waiting for an I/O op to return > which isn't returning, and eventually everything > times out after 120 seconds. Without knowing > what I/O op was dropped for what reason, there's > not much we can do. > > FWIW I cannot reproduce this on Fedora 13, > but that has a different version of qemu and > a different kernel, so anything could be > different.
(In reply to comment #6) > (In reply to comment #3) > > Which version of qemu is this? > > # rpm -qa | grep qemu > qemu-kvm-0.10.6-9.fc11.x86_64 > qemu-system-x86-0.10.6-9.fc11.x86_64 > qemu-common-0.10.6-9.fc11.x86_64 > qemu-img-0.10.6-9.fc11.x86_64 Sorry I login to wrong machine to got above qemu information, qemu information from the machine that I can reproduce the bug is as follows: # rpm -qa | grep qemu qemu-user-0.11.0-13.fc12.x86_64 gpxe-roms-qemu-0.9.9-1.20091018git.fc12.noarch qemu-system-mips-0.11.0-13.fc12.x86_64 qemu-system-sh4-0.11.0-13.fc12.x86_64 qemu-kvm-0.11.0-13.fc12.x86_64 qemu-common-0.11.0-13.fc12.x86_64 qemu-img-0.11.0-13.fc12.x86_64 qemu-system-sparc-0.11.0-13.fc12.x86_64 qemu-0.11.0-13.fc12.x86_64 qemu-system-cris-0.11.0-13.fc12.x86_64 qemu-system-ppc-0.11.0-13.fc12.x86_64 qemu-system-x86-0.11.0-13.fc12.x86_64 qemu-system-m68k-0.11.0-13.fc12.x86_64 qemu-system-arm-0.11.0-13.fc12.x86_64 > > Is the filesystem that you are trying to mount ext3? XFS? > The filesystem is ext3, which exists on a LV. > > > Is the disk encrypted? > The disk is not encrypted. > > > ----- > > > > Reading around the issue, the error message > > "INFO: task mount ... blocked for more than 120 seconds." > > isn't very informative for us. It just says that > > an I/O operation was dropped by the block device > > (eg. qemu or virtio is dropping I/O operations), > > or else the kernel has lost track of an I/O op. But > > either way, mount is waiting for an I/O op to return > > which isn't returning, and eventually everything > > times out after 120 seconds. Without knowing > > what I/O op was dropped for what reason, there's > > not much we can do. > > > > FWIW I cannot reproduce this on Fedora 13, > > but that has a different version of qemu and > > a different kernel, so anything could be > > different.
I can't reproduce the reporter's original problem. With libguestfs 1.9.18 I get this error from qemu instead: $ guestfish -N lvfs exit $ chmod -w test1.img $ ll test1.img -r--r--r--. 1 rjones rjones 104857600 Apr 12 18:56 test1.img $ guestfish -a test1.img -m /dev/VG/LV ll / qemu-kvm: -drive file=test1.img,cache=off,if=virtio: could not open disk image test1.img: Permission denied libguestfs: error: unexpected end of file when reading from daemon
Trying to reproduce this on latest upstream: $ guestfish -N lvfs exit $ chmod -w test1.img $ ll test1.img -r--r--r--. 1 rjones rjones 104857600 May 3 14:48 test1.img $ guestfish -a test1.img -m /dev/VG/LV ll / libguestfs: error: test1.img: Permission denied This is correct behaviour, and happens because I changed the permissions test in the code: http://git.annexia.org/?p=libguestfs.git;a=commitdiff;h=31bf0cf313f21bdeb0d166c4c76aad050ad32232 Therefore I am closing this bug.