Re: Process blocked for more than 120 seconds.

2012-12-14 Thread Stefan Hajnoczi
On Wed, Dec 12, 2012 at 1:01 PM, Andrew Holway  wrote:
> No the NFS is not hung and yes I can access the image on the host.
>
> Its just seems to happen occasionally with some VMs..

Not sure how to approach this besides looking at Linux and QEMU
sources and deciding what to trace/debug, sorry.

Stefan
--
To unsubscribe from this list: send the line "unsubscribe kvm" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: Process blocked for more than 120 seconds.

2012-12-12 Thread Andrew Holway
Hi,

No the NFS is not hung and yes I can access the image on the host.

Its just seems to happen occasionally with some VMs..

Thanks,

Andrew


On Dec 11, 2012, at 11:59 AM, Stefan Hajnoczi wrote:

> On Fri, Dec 7, 2012 at 1:09 PM, Andrew Holway  wrote:
>> -drivefile=/rhev/data-center/3ecf6306-3fa6-11e2-b544-00215e253fcc/b2a3daf4-7315-4cd8-a076-4ab005db7410/images/8c3541ea-9b89-4837-b98a-ae97feae6765/c90ceaf1-9c3a-42e6-b1a2-939fc1403fcb
>> if=none
>> id=drive-virtio-disk0
>> format=raw
>> serial=8c3541ea-9b89-4837-b98a-ae97feae6765
>> cache=none
>> werror=stop
>> rerror=stop
>> aio=threads-devicevirtio-blk-pci
>> scsi=off
>> bus=pci.0
>> addr=0x5
>> drive=drive-virtio-disk0
>> id=virtio-disk0
> 
> Is NFS hung - can you access the image from the host?
> 
> Stefan
> --
> To unsubscribe from this list: send the line "unsubscribe kvm" in
> the body of a message to majord...@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html


--
To unsubscribe from this list: send the line "unsubscribe kvm" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: Process blocked for more than 120 seconds.

2012-12-11 Thread Stefan Hajnoczi
On Fri, Dec 7, 2012 at 1:09 PM, Andrew Holway  wrote:
> -drivefile=/rhev/data-center/3ecf6306-3fa6-11e2-b544-00215e253fcc/b2a3daf4-7315-4cd8-a076-4ab005db7410/images/8c3541ea-9b89-4837-b98a-ae97feae6765/c90ceaf1-9c3a-42e6-b1a2-939fc1403fcb
> if=none
> id=drive-virtio-disk0
> format=raw
> serial=8c3541ea-9b89-4837-b98a-ae97feae6765
> cache=none
> werror=stop
> rerror=stop
> aio=threads-devicevirtio-blk-pci
> scsi=off
> bus=pci.0
> addr=0x5
> drive=drive-virtio-disk0
> id=virtio-disk0

Is NFS hung - can you access the image from the host?

Stefan
--
To unsubscribe from this list: send the line "unsubscribe kvm" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: Process blocked for more than 120 seconds.

2012-12-07 Thread Andrew Holway
sorry. I forgot to mention that my images are being created on a Solaris based 
NFS / ZFS server.

Thanks,

Andrew


On Dec 7, 2012, at 1:09 PM, Andrew Holway wrote:

> Hello,
> 
> I have been using rhev 3.1 and created a few VMs. I have provisioning system 
> that boots machines via pxe with centos 6.3 images.
> 
> It creates the following:
> 
> /dev/vda1 on / type ext3 (rw,noatime,nodiratime)
> /dev/vda6 on /local type ext3 (rw,noatime,nodiratime)
> /dev/vda3 on /tmp type ext3 (rw,nosuid,nodev,noatime,nodiratime)
> /dev/vda2 on /var type ext3 (rw,noatime,nodiratime)
> 
> With:  Kernel:  2.6.32-279.el6.x86_64 #1 SMP Fri Jun 22 12:19:21 UTC 2012 
> x86_64 x86_64 x86_64 GNU/Linux
> 
> Thanks,
> 
> Andrew
> 
> 
> Dec  7 12:22:01 cheese04 kernel: imklog 4.6.2, log source = /proc/kmsg 
> started.
> Dec  7 12:22:01 cheese04 rsyslogd: [origin software="rsyslogd" 
> swVersion="4.6.2" x-pid="2790" x-info="http://www.rsyslog.com";] (re)start
> Dec  7 12:29:56 cheese04 kernel: INFO: task kjournald:2520 blocked for more 
> than 120 seconds.
> Dec  7 12:29:56 cheese04 kernel: "echo 0 > 
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> Dec  7 12:29:56 cheese04 kernel: kjournald D  0  2520 
>  2 0x0080
> Dec  7 12:29:56 cheese04 kernel: 880101005d50 0046 
> 81a8d020 8160b400
> Dec  7 12:29:56 cheese04 kernel:  88011fc23080 
> 880101005da0 8105b483
> Dec  7 12:29:56 cheese04 kernel: 880117f99af8 880101005fd8 
> fb88 880117f99af8
> Dec  7 12:29:56 cheese04 kernel: Call Trace:
> Dec  7 12:29:56 cheese04 kernel: [] ? 
> perf_event_task_sched_out+0x33/0x80
> Dec  7 12:29:56 cheese04 kernel: [] ? 
> prepare_to_wait+0x4e/0x80
> Dec  7 12:29:56 cheese04 kernel: [] 
> journal_commit_transaction+0x161/0x1310 [jbd]
> Dec  7 12:29:56 cheese04 kernel: [] ? 
> autoremove_wake_function+0x0/0x40
> Dec  7 12:29:56 cheese04 kernel: [] ? 
> try_to_del_timer_sync+0x7b/0xe0
> Dec  7 12:29:56 cheese04 kernel: [] kjournald+0xe8/0x250 
> [jbd]
> Dec  7 12:29:56 cheese04 kernel: [] ? 
> autoremove_wake_function+0x0/0x40
> Dec  7 12:29:56 cheese04 kernel: [] ? kjournald+0x0/0x250 
> [jbd]
> Dec  7 12:29:56 cheese04 kernel: [] kthread+0x96/0xa0
> Dec  7 12:29:56 cheese04 kernel: [] child_rip+0xa/0x20
> Dec  7 12:29:56 cheese04 kernel: [] ? kthread+0x0/0xa0
> Dec  7 12:29:56 cheese04 kernel: [] ? child_rip+0x0/0x20
> Dec  7 12:29:56 cheese04 kernel: INFO: task master:3023 blocked for more than 
> 120 seconds.
> Dec  7 12:29:56 cheese04 kernel: "echo 0 > 
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> Dec  7 12:29:56 cheese04 kernel: masterD  0  3023 
>  1 0x0084
> Dec  7 12:29:56 cheese04 kernel: 8801013dd968 0082 
>  0792d63945c4
> Dec  7 12:29:56 cheese04 kernel: 8801013dd928 880117e21e50 
> 0007884e af3e39ec
> Dec  7 12:29:56 cheese04 kernel: 8800c4282638 8801013ddfd8 
> fb88 8800c4282638
> Dec  7 12:29:56 cheese04 kernel: Call Trace:
> Dec  7 12:29:56 cheese04 kernel: [] ? sync_buffer+0x0/0x50
> Dec  7 12:29:56 cheese04 kernel: [] io_schedule+0x73/0xc0
> Dec  7 12:29:56 cheese04 kernel: [] sync_buffer+0x40/0x50
> Dec  7 12:29:56 cheese04 kernel: [] 
> __wait_on_bit_lock+0x5a/0xc0
> Dec  7 12:29:56 cheese04 kernel: [] ? sync_buffer+0x0/0x50
> Dec  7 12:29:56 cheese04 kernel: [] 
> out_of_line_wait_on_bit_lock+0x78/0x90
> Dec  7 12:29:56 cheese04 kernel: [] ? 
> wake_bit_function+0x0/0x50
> Dec  7 12:29:56 cheese04 kernel: [] ? 
> pvclock_clocksource_read+0x58/0xd0
> Dec  7 12:29:56 cheese04 kernel: [] __lock_buffer+0x36/0x40
> Dec  7 12:29:56 cheese04 kernel: [] 
> do_get_write_access+0x483/0x500 [jbd]
> Dec  7 12:29:56 cheese04 kernel: [] ? __getblk+0x2c/0x2e0
> Dec  7 12:29:56 cheese04 kernel: [] 
> journal_get_write_access+0x31/0x50 [jbd]
> Dec  7 12:29:56 cheese04 kernel: [] 
> __ext3_journal_get_write_access+0x2d/0x60 [ext3]
> Dec  7 12:29:56 cheese04 kernel: [] 
> ext3_reserve_inode_write+0x7b/0xa0 [ext3]
> Dec  7 12:29:56 cheese04 kernel: [] 
> ext3_mark_inode_dirty+0x48/0xa0 [ext3]
> Dec  7 12:29:56 cheese04 kernel: [] 
> ext3_dirty_inode+0x61/0xa0 [ext3]
> Dec  7 12:29:56 cheese04 kernel: [] 
> __mark_inode_dirty+0x3b/0x160
> Dec  7 12:29:56 cheese04 kernel: [] 
> file_update_time+0xf2/0x170
> Dec  7 12:29:56 cheese04 kernel: [] pipe_write+0x2d2/0x650
> Dec  7 12:29:56 cheese04 kernel: [] do_sync_write+0xfa/0x140
> Dec  7 12:29:56 cheese04 kernel: [] ? 
> autoremove_wake_function+0x0/0x40
> Dec  7 12:29:56 cheese04 kernel: [] ? 
> selinux_file_permission+0xfb/0x150
> Dec  7 12:29:56 cheese04 kernel: [] ? 
> security_file_permission+0x16/0x20
> Dec  7 12:29:56 cheese04 kernel: [] vfs_write+0xb8/0x1a0
> Dec  7 12:29:56 cheese04 kernel: [] sys_write+0x51/0x90
> Dec  7 12:29:56 cheese04 kernel: [] 
> system_call_fastpath+0x16/0x1b
> 
> [root@cheese04 ~]# dumpe2fs /

Process blocked for more than 120 seconds.

2012-12-07 Thread Andrew Holway
Hello,

I have been using rhev 3.1 and created a few VMs. I have provisioning system 
that boots machines via pxe with centos 6.3 images.

It creates the following:

/dev/vda1 on / type ext3 (rw,noatime,nodiratime)
/dev/vda6 on /local type ext3 (rw,noatime,nodiratime)
/dev/vda3 on /tmp type ext3 (rw,nosuid,nodev,noatime,nodiratime)
/dev/vda2 on /var type ext3 (rw,noatime,nodiratime)

With:  Kernel:  2.6.32-279.el6.x86_64 #1 SMP Fri Jun 22 12:19:21 UTC 2012 
x86_64 x86_64 x86_64 GNU/Linux

Thanks,

Andrew


Dec  7 12:22:01 cheese04 kernel: imklog 4.6.2, log source = /proc/kmsg started.
Dec  7 12:22:01 cheese04 rsyslogd: [origin software="rsyslogd" 
swVersion="4.6.2" x-pid="2790" x-info="http://www.rsyslog.com";] (re)start
Dec  7 12:29:56 cheese04 kernel: INFO: task kjournald:2520 blocked for more 
than 120 seconds.
Dec  7 12:29:56 cheese04 kernel: "echo 0 > 
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec  7 12:29:56 cheese04 kernel: kjournald D  0  2520   
   2 0x0080
Dec  7 12:29:56 cheese04 kernel: 880101005d50 0046 
81a8d020 8160b400
Dec  7 12:29:56 cheese04 kernel:  88011fc23080 
880101005da0 8105b483
Dec  7 12:29:56 cheese04 kernel: 880117f99af8 880101005fd8 
fb88 880117f99af8
Dec  7 12:29:56 cheese04 kernel: Call Trace:
Dec  7 12:29:56 cheese04 kernel: [] ? 
perf_event_task_sched_out+0x33/0x80
Dec  7 12:29:56 cheese04 kernel: [] ? 
prepare_to_wait+0x4e/0x80
Dec  7 12:29:56 cheese04 kernel: [] 
journal_commit_transaction+0x161/0x1310 [jbd]
Dec  7 12:29:56 cheese04 kernel: [] ? 
autoremove_wake_function+0x0/0x40
Dec  7 12:29:56 cheese04 kernel: [] ? 
try_to_del_timer_sync+0x7b/0xe0
Dec  7 12:29:56 cheese04 kernel: [] kjournald+0xe8/0x250 [jbd]
Dec  7 12:29:56 cheese04 kernel: [] ? 
autoremove_wake_function+0x0/0x40
Dec  7 12:29:56 cheese04 kernel: [] ? kjournald+0x0/0x250 
[jbd]
Dec  7 12:29:56 cheese04 kernel: [] kthread+0x96/0xa0
Dec  7 12:29:56 cheese04 kernel: [] child_rip+0xa/0x20
Dec  7 12:29:56 cheese04 kernel: [] ? kthread+0x0/0xa0
Dec  7 12:29:56 cheese04 kernel: [] ? child_rip+0x0/0x20
Dec  7 12:29:56 cheese04 kernel: INFO: task master:3023 blocked for more than 
120 seconds.
Dec  7 12:29:56 cheese04 kernel: "echo 0 > 
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec  7 12:29:56 cheese04 kernel: masterD  0  3023   
   1 0x0084
Dec  7 12:29:56 cheese04 kernel: 8801013dd968 0082 
 0792d63945c4
Dec  7 12:29:56 cheese04 kernel: 8801013dd928 880117e21e50 
0007884e af3e39ec
Dec  7 12:29:56 cheese04 kernel: 8800c4282638 8801013ddfd8 
fb88 8800c4282638
Dec  7 12:29:56 cheese04 kernel: Call Trace:
Dec  7 12:29:56 cheese04 kernel: [] ? sync_buffer+0x0/0x50
Dec  7 12:29:56 cheese04 kernel: [] io_schedule+0x73/0xc0
Dec  7 12:29:56 cheese04 kernel: [] sync_buffer+0x40/0x50
Dec  7 12:29:56 cheese04 kernel: [] 
__wait_on_bit_lock+0x5a/0xc0
Dec  7 12:29:56 cheese04 kernel: [] ? sync_buffer+0x0/0x50
Dec  7 12:29:56 cheese04 kernel: [] 
out_of_line_wait_on_bit_lock+0x78/0x90
Dec  7 12:29:56 cheese04 kernel: [] ? 
wake_bit_function+0x0/0x50
Dec  7 12:29:56 cheese04 kernel: [] ? 
pvclock_clocksource_read+0x58/0xd0
Dec  7 12:29:56 cheese04 kernel: [] __lock_buffer+0x36/0x40
Dec  7 12:29:56 cheese04 kernel: [] 
do_get_write_access+0x483/0x500 [jbd]
Dec  7 12:29:56 cheese04 kernel: [] ? __getblk+0x2c/0x2e0
Dec  7 12:29:56 cheese04 kernel: [] 
journal_get_write_access+0x31/0x50 [jbd]
Dec  7 12:29:56 cheese04 kernel: [] 
__ext3_journal_get_write_access+0x2d/0x60 [ext3]
Dec  7 12:29:56 cheese04 kernel: [] 
ext3_reserve_inode_write+0x7b/0xa0 [ext3]
Dec  7 12:29:56 cheese04 kernel: [] 
ext3_mark_inode_dirty+0x48/0xa0 [ext3]
Dec  7 12:29:56 cheese04 kernel: [] 
ext3_dirty_inode+0x61/0xa0 [ext3]
Dec  7 12:29:56 cheese04 kernel: [] 
__mark_inode_dirty+0x3b/0x160
Dec  7 12:29:56 cheese04 kernel: [] 
file_update_time+0xf2/0x170
Dec  7 12:29:56 cheese04 kernel: [] pipe_write+0x2d2/0x650
Dec  7 12:29:56 cheese04 kernel: [] do_sync_write+0xfa/0x140
Dec  7 12:29:56 cheese04 kernel: [] ? 
autoremove_wake_function+0x0/0x40
Dec  7 12:29:56 cheese04 kernel: [] ? 
selinux_file_permission+0xfb/0x150
Dec  7 12:29:56 cheese04 kernel: [] ? 
security_file_permission+0x16/0x20
Dec  7 12:29:56 cheese04 kernel: [] vfs_write+0xb8/0x1a0
Dec  7 12:29:56 cheese04 kernel: [] sys_write+0x51/0x90
Dec  7 12:29:56 cheese04 kernel: [] 
system_call_fastpath+0x16/0x1b

[root@cheese04 ~]# dumpe2fs /dev/vda1 
dumpe2fs 1.41.12 (17-May-2010)
Filesystem volume name:   
Last mounted on:  
Filesystem UUID:  79efe567-75c2-4fd1-800c-429d0530b945
Filesystem magic number:  0xEF53
Filesystem revision #:1 (dynamic)
Filesystem features:  has_journal ext_attr resize_inode dir_index filetype 
needs_recovery sparse_super large_file
Filesystem flags: signed_directory_hash