[PVE-User] i see call trace in log after make backup

[Dietmar Maurer]

seems to be snapshot related. What kind on backup do you run 
exactly - OpenVZ VM or KVM VM? What kind of storage is used?
Does it work when you do not use snapshot mode?

- Dietmar

> -----Original Message-----
> From: pve-user-bounces at pve.proxmox.com [mailto:pve-user-
> bounces at pve.proxmox.com] On Behalf Of Serge
> Sent: Dienstag, 07. Dezember 2010 00:54
> To: pve-user at pve.proxmox.com
> Subject: [PVE-User] i see call trace in log after make backup
> 
> Hello ,
> 
> On backup time i getting this error:
> 
> Dec  7 01:07:01 core vzdump[3711]: INFO: starting new backup job: vzdump --
> quiet --snapshot --compress --stdexcludes --ionice 4 --storage backup --
> mailto my at mail.com --all Dec  7 01:07:01 core vzdump[3711]: INFO: Starting
> Backup of VM 101 (openvz) Dec  7 01:07:03 core kernel:
> ext3_orphan_cleanup: deleting unreferenced inode 4892775 [skip...] Dec  7
> 01:07:03 core kernel: ext3_orphan_cleanup: deleting unreferenced inode
> 4890634 Dec  7 01:07:03 core kernel: EXT3-fs: dm-4: 15 orphan inodes deleted
> Dec  7 01:07:03 core kernel: EXT3-fs: recovery complete.
> Dec  7 01:09:59 core vzdump[3711]: INFO: Finished Backup of VM 101
> (00:02:58) Dec  7 01:09:59 core vzdump[3711]: INFO: Starting Backup of VM
> 102 (openvz) Dec  7 01:10:00 core kernel: ext3_orphan_cleanup: deleting
> unreferenced inode 4890628 [skip...] Dec  7 01:10:00 core kernel:
> ext3_orphan_cleanup: deleting unreferenced inode 4890634 Dec  7 01:10:00
> core kernel: EXT3-fs: dm-4: 13 orphan inodes deleted Dec  7 01:10:00 core
> kernel: EXT3-fs: recovery complete.
> Dec  7 01:26:39 core kernel: INFO: task umount:6720 blocked for more than
> 120 seconds.
> Dec  7 01:26:39 core kernel: "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> Dec  7 01:26:39 core kernel: umount        D ffff880206663800     0  6720   3711
> 0x00000000
> Dec  7 01:26:39 core kernel: ffffffff81491c30 0000000000000086
> 0000000000000000 0000000000000086 Dec  7 01:26:39 core kernel:
> ffffffff8101657f 0000000000000086 000000000000fa40 ffff880099f5ffd8 Dec  7
> 01:26:39 core kernel: 0000000000016940 0000000000016940 ffff880206663800
> ffff880206663af8 Dec  7 01:26:39 core kernel: Call Trace:
> Dec  7 01:26:39 core kernel: [<ffffffff8101657f>] ? sched_clock+0x5/0x8 Dec  7
> 01:26:39 core kernel: [<ffffffff810b6892>] ? find_get_pages_tag+0x46/0xdd
> Dec  7 01:26:39 core kernel: [<ffffffff8110b607>] ? bdi_sched_wait+0x0/0xe
> Dec  7 01:26:39 core kernel: [<ffffffff8110b610>] ? bdi_sched_wait+0x9/0xe
> Dec  7 01:26:39 core kernel: [<ffffffff81313d8f>] ? __wait_on_bit+0x41/0x70
> Dec  7 01:26:39 core kernel: [<ffffffff8110b607>] ? bdi_sched_wait+0x0/0xe
> Dec  7 01:26:39 core kernel: [<ffffffff81313e29>] ?
> out_of_line_wait_on_bit+0x6b/0x77 Dec  7 01:26:39 core kernel:
> [<ffffffff81066864>] ? wake_bit_function+0x0/0x23 Dec  7 01:26:39 core
> kernel: [<ffffffff8110b688>] ? sync_inodes_sb+0x73/0x12a Dec  7 01:26:39
> core kernel: [<ffffffff8110f2d0>] ? __sync_filesystem+0x4c/0x72 Dec  7
> 01:26:39 core kernel: [<ffffffff810f3661>] ?
> generic_shutdown_super+0x25/0x11f Dec  7 01:26:39 core kernel:
> [<ffffffff810f377d>] ? kill_block_super+0x22/0x3a Dec  7 01:26:39 core
> kernel: [<ffffffff810f3c34>] ? deactivate_super+0x60/0x78 Dec  7 01:26:39
> core kernel: [<ffffffff8110704a>] ? sys_umount+0x2bb/0x2e6 Dec  7 01:26:39
> core kernel: [<ffffffff81010c12>] ? system_call_fastpath+0x16/0x1b Dec  7
> 01:28:39 core kernel: INFO: task umount:6720 blocked for more than 120
> seconds.
> Dec  7 01:28:39 core kernel: "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> Dec  7 01:28:39 core kernel: umount        D ffff880206663800     0  6720   3711
> 0x00000000
> Dec  7 01:28:39 core kernel: ffffffff81491c30 0000000000000086
> 0000000000000000 0000000000000086 Dec  7 01:28:39 core kernel:
> ffffffff8101657f 0000000000000086 000000000000fa40 ffff880099f5ffd8 Dec  7
> 01:28:39 core kernel: 0000000000016940 0000000000016940 ffff880206663800
> ffff880206663af8 Dec  7 01:28:39 core kernel: Call Trace:
> Dec  7 01:28:39 core kernel: [<ffffffff8101657f>] ? sched_clock+0x5/0x8 Dec  7
> 01:28:39 core kernel: [<ffffffff810b6892>] ? find_get_pages_tag+0x46/0xdd
> Dec  7 01:28:39 core kernel: [<ffffffff8110b607>] ? bdi_sched_wait+0x0/0xe
> Dec  7 01:28:39 core kernel: [<ffffffff8110b610>] ? bdi_sched_wait+0x9/0xe
> Dec  7 01:28:39 core kernel: [<ffffffff81313d8f>] ? __wait_on_bit+0x41/0x70
> Dec  7 01:28:39 core kernel: [<ffffffff8110b607>] ? bdi_sched_wait+0x0/0xe
> Dec  7 01:28:39 core kernel: [<ffffffff81313e29>] ?
> out_of_line_wait_on_bit+0x6b/0x77 Dec  7 01:28:39 core kernel:
> [<ffffffff81066864>] ? wake_bit_function+0x0/0x23 Dec  7 01:28:39 core
> kernel: [<ffffffff8110b688>] ? sync_inodes_sb+0x73/0x12a Dec  7 01:28:39
> core kernel: [<ffffffff8110f2d0>] ? __sync_filesystem+0x4c/0x72 Dec  7
> 01:28:39 core kernel: [<ffffffff810f3661>] ?
> generic_shutdown_super+0x25/0x11f Dec  7 01:28:39 core kernel:
> [<ffffffff810f377d>] ? kill_block_super+0x22/0x3a Dec  7 01:28:39 core
> kernel: [<ffffffff810f3c34>] ? deactivate_super+0x60/0x78 Dec  7 01:28:39
> core kernel: [<ffffffff8110704a>] ? sys_umount+0x2bb/0x2e6 Dec  7 01:28:39
> core kernel: [<ffffffff81010c12>] ? system_call_fastpath+0x16/0x1b Dec  7
> 01:30:39 core kernel: INFO: task umount:6720 blocked for more than 120
> seconds.
> Dec  7 01:30:39 core kernel: "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> Dec  7 01:30:39 core kernel: umount        D ffff880206663800     0  6720   3711
> 0x00000000
> Dec  7 01:30:39 core kernel: ffffffff81491c30 0000000000000086
> 0000000000000000 0000000000000086 Dec  7 01:30:39 core kernel:
> ffffffff8101657f 0000000000000086 000000000000fa40 ffff880099f5ffd8 Dec  7
> 01:30:39 core kernel: 0000000000016940 0000000000016940 ffff880206663800
> ffff880206663af8 Dec  7 01:30:39 core kernel: Call Trace:
> Dec  7 01:30:39 core kernel: [<ffffffff8101657f>] ? sched_clock+0x5/0x8 Dec  7
> 01:30:39 core kernel: [<ffffffff810b6892>] ? find_get_pages_tag+0x46/0xdd
> Dec  7 01:30:39 core kernel: [<ffffffff8110b607>] ? bdi_sched_wait+0x0/0xe
> Dec  7 01:30:39 core kernel: [<ffffffff8110b610>] ? bdi_sched_wait+0x9/0xe
> Dec  7 01:30:39 core kernel: [<ffffffff81313d8f>] ? __wait_on_bit+0x41/0x70
> Dec  7 01:30:39 core kernel: [<ffffffff8110b607>] ? bdi_sched_wait+0x0/0xe
> Dec  7 01:30:39 core kernel: [<ffffffff81313e29>] ?
> out_of_line_wait_on_bit+0x6b/0x77 Dec  7 01:30:39 core kernel:
> [<ffffffff81066864>] ? wake_bit_function+0x0/0x23 Dec  7 01:30:39 core
> kernel: [<ffffffff8110b688>] ? sync_inodes_sb+0x73/0x12a Dec  7 01:30:39
> core kernel: [<ffffffff8110f2d0>] ? __sync_filesystem+0x4c/0x72 Dec  7
> 01:30:39 core kernel: [<ffffffff810f3661>] ?
> generic_shutdown_super+0x25/0x11f Dec  7 01:30:39 core kernel:
> [<ffffffff810f377d>] ? kill_block_super+0x22/0x3a Dec  7 01:30:39 core
> kernel: [<ffffffff810f3c34>] ? deactivate_super+0x60/0x78 Dec  7 01:30:39
> core kernel: [<ffffffff8110704a>] ? sys_umount+0x2bb/0x2e6 Dec  7 01:30:39
> core kernel: [<ffffffff81010c12>] ? system_call_fastpath+0x16/0x1b Dec  7
> 01:30:53 core vzdump[3711]: INFO: Finished Backup of VM 102 (00:20:54) Dec
> 7 01:30:53 core vzdump[3711]: INFO: Starting Backup of VM 103 (openvz)
> 
> Is it possible to fix this and should i worry about my backups and/or disks  ?
> 
> My server detais:
> 
> # pveversion -v
> pve-manager: 1.7-10 (pve-manager/1.7/5323) running kernel: 2.6.32-4-pve
> proxmox-ve-2.6.32: 1.7-29
> pve-kernel-2.6.32-4-pve: 2.6.32-29
> pve-kernel-2.6.18-4-pve: 2.6.18-10
> qemu-server: 1.1-27
> pve-firmware: 1.0-9
> libpve-storage-perl: 1.0-16
> vncterm: 0.9-2
> vzctl: 3.0.24-1pve4
> vzdump: 1.2-10
> vzprocps: 2.0.11-1dso2
> vzquota: 3.0.11-1
> pve-qemu-kvm: 0.13.0-2
> ksm-control-daemon: 1.0-4
> 
> Linux core.server.com 2.6.32-4-pve #1 SMP Fri Nov 26 06:42:28 CET 2010
> x86_64 GNU/Linux
> 
> It is Hetzner EQ server (corei7 8gb ram)
> 
> Thank you for your help.
> 
> --
> With Best Regards,
> Serge