From mboxrd@z Thu Jan 1 00:00:00 1970 From: Andres Lagar Cavilla Subject: Re: Live migration hanging for a CPU intensive task Date: Thu, 13 Apr 2006 18:20:33 -0400 Message-ID: <443ECEB1.2040100@cs.toronto.edu> References: <443EC987.8000108@cs.toronto.edu> <443ECB28.3030102@us.ibm.com> Mime-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Return-path: In-Reply-To: <443ECB28.3030102@us.ibm.com> List-Unsubscribe: , List-Post: List-Help: List-Subscribe: , Sender: xen-devel-bounces@lists.xensource.com Errors-To: xen-devel-bounces@lists.xensource.com To: Anthony Liguori , xen-devel@lists.xensource.com List-Id: xen-devel@lists.xenproject.org Anthony, migration doesn't go on forever. There's a limit on the amount of memory you can transmit and the number of iterations you can do. Hitting one of those limits means that the last non-live iteration will be a bit longer than expected. However, the test stalls right at the beginning of that last iteration, before being able to move a single page, because the suspend hangs. I'm trying to get to the suspend operation. I see that xc_linux_save.c prints "suspend" to the python wrapper XendChekpoint.py, which in turn places a transaction on xenstore. Am I right so far? what happens next? Andres > > If this is the case, wouldn't you expect that migration could never > complete? If the VM is dirty more pages than it transmit, the > algorithm will not converge. Is there something else going on here? > > Regards, > > Anthony Liguori > >> This is due to the heavy processing going on and the restricted >> network conditions (100Mbps, 33 ms RTT). If I run the same test in a >> Gigabit LAN, migration finishes succesfully. >> After suspend begins, the VM becomes unresponsive, as expected. >> However, xm top indicates a steady CPU utilization of 99% >> >> I would appreciate if someone with insight on the migration/suspend >> code can give me a hint. In principle, I need to add more debugging >> messages to the suspend code. I'm thinking that given the length of >> the migration and the rate of page dirtying, the shadow page tables >> get "overloaded" (whatever that might be) and that causes weirdness >> while suspending. But that's just a wild conjecture. >> Thanks indeed for any feedback >> Andres >> >> xend.log ----------------------------- >> >> [2006-04-12 15:55:08 xend.XendDomainInfo] DEBUG (XendDomainInfo:177) >> XendDomainInfo.create(['vm', ['name', 'xenbox'], ['memory', '512'], >> ['vcpus', '4'], ['image', ['linux', ['kernel', >> '/boot/vmlinuz-2.6.12.6-xenU'], ['ip', ':1.2.3.4::::eth0:dhcp'], >> ['root', '/dev/sda1 ro'], ['args', '4']]], ['device', ['vbd', >> ['uname', 'phy:hdk'], ['dev', 'sda1'], ['mode', 'w']]], ['device', >> ['vif', ['mac', '00:a0:24:60:31:67']]]]) >> [2006-04-12 15:55:08 xend.XendDomainInfo] DEBUG (XendDomainInfo:282) >> parseConfig: config is ['vm', ['name', 'xenbox'], ['memory', '512'], >> ['vcpus', '4'], ['image', ['linux', ['kernel', >> '/boot/vmlinuz-2.6.12.6-xenU'], ['ip', ':1.2.3.4::::eth0:dhcp'], >> ['root', '/dev/sda1 ro'], ['args', '4']]], ['device', ['vbd', >> ['uname', 'phy:hdk'], ['dev', 'sda1'], ['mode', 'w']]], ['device', >> ['vif', ['mac', '00:a0:24:60:31:67']]]] >> [2006-04-12 15:55:08 xend.XendDomainInfo] DEBUG (XendDomainInfo:376) >> parseConfig: result is {'ssidref': None, 'uuid': None, 'on_crash': >> None, 'on_reboot': None, 'image': ['linux', ['kernel', >> '/boot/vmlinuz-2.6.12.6-xenU'], ['ip', ':1.2.3.4::::eth0:dhcp'], >> ['root', '/dev/sda1 ro'], ['args', '4']], 'on_poweroff': None, >> 'cpus': None, 'name': 'xenbox', 'backend': [], 'vcpus': 4, >> 'cpu_weight': None, 'vcpu_avail': None, 'memory': 512, 'device': >> [('vbd', ['vbd', ['uname', 'phy:hdk'], ['dev', 'sda1'], ['mode', >> 'w']]), ('vif', ['vif', ['mac', '00:a0:24:60:31:67']])], >> 'bootloader': None, 'cpu': None, 'maxmem': None} >> [2006-04-12 15:55:08 xend.XendDomainInfo] DEBUG (XendDomainInfo:1130) >> XendDomainInfo.construct: None 0 >> [2006-04-12 15:55:08 xend.XendDomainInfo] DEBUG (XendDomainInfo:1162) >> XendDomainInfo.initDomain: 31 1.0 >> [2006-04-12 15:55:08 xend] DEBUG (balloon:84) Balloon: free 1025; >> need 513; done. >> [2006-04-12 15:55:08 xend] INFO (image:133) buildDomain os=linux >> dom=31 vcpus=4 >> [2006-04-12 15:55:08 xend] DEBUG (image:171) dom = 31 >> [2006-04-12 15:55:08 xend] DEBUG (image:172) image = >> /boot/vmlinuz-2.6.12.6-xenU >> [2006-04-12 15:55:08 xend] DEBUG (image:173) store_evtchn = 1 >> [2006-04-12 15:55:08 xend] DEBUG (image:174) console_evtchn = 2 >> [2006-04-12 15:55:08 xend] DEBUG (image:175) cmdline = >> ip=:1.2.3.4::::eth0:dhcp root=/dev/sda1 ro 4 >> [2006-04-12 15:55:08 xend] DEBUG (image:176) ramdisk = >> [2006-04-12 15:55:08 xend] DEBUG (image:177) vcpus = 4 >> [2006-04-12 15:55:08 xend] DEBUG (DevController:103) DevController: >> writing {'virtual-device': '2049', 'backend-id': '0', 'state': '1', >> 'backend': '/local/domain/0/backend/vbd/31/2049'} to >> /local/domain/31/device/vbd/2049. >> [2006-04-12 15:55:08 xend] DEBUG (DevController:105) DevController: >> writing {'domain': 'xenbox', 'frontend': >> '/local/domain/31/device/vbd/2049', 'dev': 'sda1', 'state': '1', >> 'params': 'hdk', 'mode': 'w', 'frontend-id': '31', 'type': 'phy'} to >> /local/domain/0/backend/vbd/31/2049. >> [2006-04-12 15:55:08 xend] DEBUG (DevController:103) DevController: >> writing {'backend-id': '0', 'mac': '00:a0:24:60:31:67', 'handle': >> '0', 'state': '1', 'backend': '/local/domain/0/backend/vif/31/0'} to >> /local/domain/31/device/vif/0. >> [2006-04-12 15:55:08 xend] DEBUG (DevController:105) DevController: >> writing {'mac': '00:a0:24:60:31:67', 'state': '1', 'handle': '0', >> 'script': '/etc/xen/scripts/vif-bridge', 'frontend-id': '31', >> 'domain': 'xenbox', 'frontend': '/local/domain/31/device/vif/0'} to >> /local/domain/0/backend/vif/31/0. >> [2006-04-12 15:55:08 xend.XendDomainInfo] DEBUG (XendDomainInfo:663) >> Storing VM details: {'ssidref': '0', 'uuid': >> '78c48e6b-4d9c-5478-15f2-5aa295db9cde', 'on_reboot': 'restart', >> 'start_time': '1144871708.44', 'on_poweroff': 'destroy', 'name': >> 'xenbox', 'vcpus': '4', 'vcpu_avail': '15', 'memory': '512', >> 'on_crash': 'restart', 'image': "(linux (kernel >> /boot/vmlinuz-2.6.12.6-xenU) (ip :1.2.3.4::::eth0:dhcp) (root >> '/dev/sda1 ro') (args 4))", 'maxmem': '512'} >> [2006-04-12 15:55:08 xend.XendDomainInfo] DEBUG (XendDomainInfo:688) >> Storing domain details: {'console/ring-ref': '50152', 'console/port': >> '2', 'cpu/3/availability': 'online', 'name': 'xenbox', >> 'console/limit': '1048576', 'cpu/2/availability': 'online', 'vm': >> '/vm/78c48e6b-4d9c-5478-15f2-5aa295db9cde', 'domid': '31', >> 'cpu/0/availability': 'online', 'memory/target': '524288', >> 'store/ring-ref': '443869', 'cpu/1/availability': 'online', >> 'store/port': '1'} >> [2006-04-12 15:55:08 xend] DEBUG (DevController:132) Waiting for >> devices vif. >> [2006-04-12 15:55:08 xend] DEBUG (DevController:138) Waiting for 0. >> [2006-04-12 15:55:08 xend] DEBUG (DevController:403) >> hotplugStatusCallback /local/domain/0/backend/vif/31/0/hotplug-status. >> [2006-04-12 15:55:08 xend] DEBUG (DevController:403) >> hotplugStatusCallback /local/domain/0/backend/vif/31/0/hotplug-status. >> [2006-04-12 15:55:08 xend] DEBUG (DevController:417) >> hotplugStatusCallback 1. >> [2006-04-12 15:55:08 xend] DEBUG (DevController:132) Waiting for >> devices usb. >> [2006-04-12 15:55:08 xend] DEBUG (DevController:132) Waiting for >> devices vbd. >> [2006-04-12 15:55:08 xend] DEBUG (DevController:138) Waiting for 2049. >> [2006-04-12 15:55:08 xend] DEBUG (DevController:403) >> hotplugStatusCallback >> /local/domain/0/backend/vbd/31/2049/hotplug-status. >> [2006-04-12 15:55:09 xend] DEBUG (DevController:403) >> hotplugStatusCallback >> /local/domain/0/backend/vbd/31/2049/hotplug-status. >> [2006-04-12 15:55:09 xend] DEBUG (DevController:417) >> hotplugStatusCallback 1. >> [2006-04-12 15:55:09 xend] DEBUG (DevController:132) Waiting for >> devices pci. >> [2006-04-12 15:55:09 xend] DEBUG (DevController:132) Waiting for >> devices ioports. >> [2006-04-12 15:55:09 xend] DEBUG (DevController:132) Waiting for >> devices vtpm. >> [2006-04-12 15:55:09 xend] INFO (XendDomain:360) Domain xenbox (31) >> unpaused. >> [2006-04-12 15:56:09 xend] DEBUG (XendCheckpoint:80) [xc_save]: >> /usr/lib/xen/bin/xc_save 11 17 31 0 0 1 >> [2006-04-12 15:56:09 xend] ERROR (XendCheckpoint:227) Had 0 >> unexplained entries in p2m table >> [2006-04-12 15:57:10 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 1 0% 6% 11% 16% 21%PT Race: >> [10000000,904] pte=bdc063, mfn=00000bdc >> [2006-04-12 15:57:10 xend] ERROR (XendCheckpoint:227) PT Race: >> [10000000,905] pte=bdd063, mfn=00000bdd >> [2006-04-12 15:57:10 xend] ERROR (XendCheckpoint:227) PT Race: >> [10000000,906] pte=bde063, mfn=00000bde >> [2006-04-12 15:57:10 xend] ERROR (XendCheckpoint:227) PT Race: >> [10000000,907] pte=bdf063, mfn=00000bdf >> [2006-04-12 15:57:10 xend] ERROR (XendCheckpoint:227) PT Race: >> [10000000,908] pte=bd9063, mfn=00000bd9 >> [2006-04-12 15:59:44 xend] ERROR >> (XendCheckpoint:227)  26% 31% 36% 41% 46% 51% >> 56% 61% 66% 71% 76% 81% 86% 92% 97% >> 1: sent 98834, skipped 32238, delta 215040ms, dom0 6%, target 22%, >> sent 15Mb/s, dirtied 6Mb/s 39757 pages >> [2006-04-12 16:00:17 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 2 0% 5% 13% 18% 23% 28% 33% >> 43% 48% 75% >> 2: sent 15081, skipped 24676, delta 32749ms, dom0 6%, target 23%, >> sent 15Mb/s, dirtied 37Mb/s 37093 pages >> [2006-04-12 16:00:17 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 3 0%netbuf race: iter 3, pfn 401. mfn ffffffff >> [2006-04-12 16:00:19 xend] ERROR (XendCheckpoint:227) netbuf race: >> iter 3, pfn 5760. mfn ffffffff >> [2006-04-12 16:00:49 xend] ERROR >> (XendCheckpoint:227)  5% 17% 26% 31% 36% 41% >> 48% 54% 78% >> 3: sent 14415, skipped 22676, delta 31370ms, dom0 6%, target 23%, >> sent 15Mb/s, dirtied 38Mb/s 37102 pages >> [2006-04-12 16:00:49 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 4 0%netbuf race: iter 4, pfn 32b8. mfn ffffffff >> [2006-04-12 16:01:24 xend] ERROR >> (XendCheckpoint:227)  5% 16% 24% 33% 38% 44% >> 49% 54% 63% 96% >> 4: sent 16474, skipped 20627, delta 35812ms, dom0 6%, target 23%, >> sent 15Mb/s, dirtied 31Mb/s 34655 pages >> [2006-04-12 16:01:24 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 5 0%netbuf race: iter 5, pfn 36a0. mfn ffffffff >> [2006-04-12 16:01:27 xend] ERROR (XendCheckpoint:227) netbuf race: >> iter 5, pfn 5760. mfn ffffffff >> [2006-04-12 16:01:40 xend] ERROR >> (XendCheckpoint:227)  6% 16% 21%netbuf race: iter 5, pfn >> 3b52. mfn ffffffff >> [2006-04-12 16:01:44 xend] ERROR (XendCheckpoint:227)  29%netbuf >> race: iter 5, pfn 327f. mfn ffffffff >> [2006-04-12 16:01:51 xend] ERROR (XendCheckpoint:227)  34%netbuf >> race: iter 5, pfn 34cd. mfn ffffffff >> [2006-04-12 16:02:00 xend] ERROR (XendCheckpoint:227)  40% >> 46%netbuf race: iter 5, pfn 390a. mfn ffffffff >> [2006-04-12 16:02:33 xend] ERROR >> (XendCheckpoint:227)  52% 57% 62% 67% 75% 81% >> 87% 92%netbuf race: iter 5, pfn 2df0. mfn ffffffff >> [2006-04-12 16:02:33 xend] ERROR (XendCheckpoint:227) netbuf race: >> iter 5, pfn 2df1. mfn ffffffff >> [2006-04-12 16:02:38 xend] ERROR (XendCheckpoint:227)  99% >> 5: sent 33877, skipped 770, delta 73629ms, dom0 5%, target 31%, sent >> 15Mb/s, dirtied 0Mb/s 816 pages >> [2006-04-12 16:02:40 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 6 0% >> 6: sent 816, skipped 0, delta 1783ms, dom0 6%, target 31%, sent >> 14Mb/s, dirtied 1Mb/s 94 pages >> [2006-04-12 16:02:40 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 7 0% >> 7: sent 94, skipped 0, delta 169ms, dom0 7%, target 28%, sent 18Mb/s, >> dirtied 11Mb/s 59 pages >> [2006-04-12 16:02:40 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 8 0% >> 8: sent 59, skipped 0, delta 128ms, dom0 7%, target 28%, sent 15Mb/s, >> dirtied 6Mb/s 25 pages >> [2006-04-12 16:02:40 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 9 0% >> 9: sent 25, skipped 0, Start last iteration >> [2006-04-12 16:02:40 xend] DEBUG (XendCheckpoint:200) suspend >> [2006-04-12 16:02:40 xend] DEBUG (XendCheckpoint:83) In >> saveInputHandler suspend >> [2006-04-12 16:02:40 xend] DEBUG (XendCheckpoint:85) Suspending 31 ... >> --> After 7 minutes I kill the thing <--- >> [2006-04-12 16:09:36 xend.XendDomainInfo] DEBUG (XendDomainInfo:1272) >> XendDomainInfo.destroy: domid=31 >> [2006-04-12 16:09:36 xend.XendDomainInfo] DEBUG (XendDomainInfo:1280) >> XendDomainInfo.destroyDomain(31) >> [2006-04-12 16:09:36 xend] INFO (XendCheckpoint:88) Domain 31 suspended. >> [2006-04-12 16:09:36 xend] ERROR (XendCheckpoint:99) Save failed on >> domain xenbox (31). >> Traceback (most recent call last): >> File "/usr/lib/python/xen/xend/XendCheckpoint.py", line 93, in save >> forkHelper(cmd, fd, saveInputHandler, False) >> File "/usr/lib/python/xen/xend/XendCheckpoint.py", line 206, in >> forkHelper >> raise XendError('Error reading from child process for %s: %s' % >> XendError: Error reading from child process for >> ['/usr/lib/xen/bin/xc_save', '11', '17', '31', '0', '0', '1']: [Errno >> 32] Broken pipe >> ----> Another try <----- >> [2006-04-12 16:35:44 xend.XendDomainInfo] DEBUG (XendDomainInfo:177) >> XendDomainInfo.create(['vm', ['name', 'xenbox'], ['memory', '512'], >> ['vcpus', '4'], ['image', ['linux', ['kernel', >> '/boot/vmlinuz-2.6.12.6-xenU'], ['ip', ':1.2.3.4::::eth0:dhcp'], >> ['root', '/dev/sda1 ro'], ['args', '4']]], ['device', ['vbd', >> ['uname', 'phy:hdk'], ['dev', 'sda1'], ['mode', 'w']]], ['device', >> ['vif', ['mac', '00:a0:24:60:31:67']]]]) >> [2006-04-12 16:35:44 xend.XendDomainInfo] DEBUG (XendDomainInfo:282) >> parseConfig: config is ['vm', ['name', 'xenbox'], ['memory', '512'], >> ['vcpus', '4'], ['image', ['linux', ['kernel', >> '/boot/vmlinuz-2.6.12.6-xenU'], ['ip', ':1.2.3.4::::eth0:dhcp'], >> ['root', '/dev/sda1 ro'], ['args', '4']]], ['device', ['vbd', >> ['uname', 'phy:hdk'], ['dev', 'sda1'], ['mode', 'w']]], ['device', >> ['vif', ['mac', '00:a0:24:60:31:67']]]] >> [2006-04-12 16:35:44 xend.XendDomainInfo] DEBUG (XendDomainInfo:376) >> parseConfig: result is {'ssidref': None, 'uuid': None, 'on_crash': >> None, 'on_reboot': None, 'image': ['linux', ['kernel', >> '/boot/vmlinuz-2.6.12.6-xenU'], ['ip', ':1.2.3.4::::eth0:dhcp'], >> ['root', '/dev/sda1 ro'], ['args', '4']], 'on_poweroff': None, >> 'cpus': None, 'name': 'xenbox', 'backend': [], 'vcpus': 4, >> 'cpu_weight': None, 'vcpu_avail': None, 'memory': 512, 'device': >> [('vbd', ['vbd', ['uname', 'phy:hdk'], ['dev', 'sda1'], ['mode', >> 'w']]), ('vif', ['vif', ['mac', '00:a0:24:60:31:67']])], >> 'bootloader': None, 'cpu': None, 'maxmem': None} >> [2006-04-12 16:35:44 xend.XendDomainInfo] DEBUG (XendDomainInfo:1130) >> XendDomainInfo.construct: None 0 >> [2006-04-12 16:35:44 xend.XendDomainInfo] DEBUG (XendDomainInfo:1162) >> XendDomainInfo.initDomain: 32 1.0 >> [2006-04-12 16:35:44 xend] DEBUG (balloon:84) Balloon: free 1025; >> need 513; done. >> [2006-04-12 16:35:44 xend] INFO (image:133) buildDomain os=linux >> dom=32 vcpus=4 >> [2006-04-12 16:35:44 xend] DEBUG (image:171) dom = 32 >> [2006-04-12 16:35:44 xend] DEBUG (image:172) image = >> /boot/vmlinuz-2.6.12.6-xenU >> [2006-04-12 16:35:44 xend] DEBUG (image:173) store_evtchn = 1 >> [2006-04-12 16:35:44 xend] DEBUG (image:174) console_evtchn = 2 >> [2006-04-12 16:35:44 xend] DEBUG (image:175) cmdline = >> ip=:1.2.3.4::::eth0:dhcp root=/dev/sda1 ro 4 >> [2006-04-12 16:35:44 xend] DEBUG (image:176) ramdisk = >> [2006-04-12 16:35:44 xend] DEBUG (image:177) vcpus = 4 >> [2006-04-12 16:35:45 xend] DEBUG (DevController:103) DevController: >> writing {'virtual-device': '2049', 'backend-id': '0', 'state': '1', >> 'backend': '/local/domain/0/backend/vbd/32/2049'} to >> /local/domain/32/device/vbd/2049. >> [2006-04-12 16:35:45 xend] DEBUG (DevController:105) DevController: >> writing {'domain': 'xenbox', 'frontend': >> '/local/domain/32/device/vbd/2049', 'dev': 'sda1', 'state': '1', >> 'params': 'hdk', 'mode': 'w', 'frontend-id': '32', 'type': 'phy'} to >> /local/domain/0/backend/vbd/32/2049. >> [2006-04-12 16:35:45 xend] DEBUG (DevController:103) DevController: >> writing {'backend-id': '0', 'mac': '00:a0:24:60:31:67', 'handle': >> '0', 'state': '1', 'backend': '/local/domain/0/backend/vif/32/0'} to >> /local/domain/32/device/vif/0. >> [2006-04-12 16:35:45 xend] DEBUG (DevController:105) DevController: >> writing {'mac': '00:a0:24:60:31:67', 'state': '1', 'handle': '0', >> 'script': '/etc/xen/scripts/vif-bridge', 'frontend-id': '32', >> 'domain': 'xenbox', 'frontend': '/local/domain/32/device/vif/0'} to >> /local/domain/0/backend/vif/32/0. >> [2006-04-12 16:35:45 xend.XendDomainInfo] DEBUG (XendDomainInfo:663) >> Storing VM details: {'ssidref': '0', 'uuid': >> 'd21e4e32-4f12-3fe7-bddc-2fab6cd9c60d', 'on_reboot': 'restart', >> 'start_time': '1144874145.05', 'on_poweroff': 'destroy', 'name': >> 'xenbox', 'vcpus': '4', 'vcpu_avail': '15', 'memory': '512', >> 'on_crash': 'restart', 'image': "(linux (kernel >> /boot/vmlinuz-2.6.12.6-xenU) (ip :1.2.3.4::::eth0:dhcp) (root >> '/dev/sda1 ro') (args 4))", 'maxmem': '512'} >> [2006-04-12 16:35:45 xend.XendDomainInfo] DEBUG (XendDomainInfo:688) >> Storing domain details: {'console/ring-ref': '441914', >> 'console/port': '2', 'cpu/3/availability': 'online', 'name': >> 'xenbox', 'console/limit': '1048576', 'cpu/2/availability': 'online', >> 'vm': '/vm/d21e4e32-4f12-3fe7-bddc-2fab6cd9c60d', 'domid': '32', >> 'cpu/0/availability': 'online', 'memory/target': '524288', >> 'store/ring-ref': '23533', 'cpu/1/availability': 'online', >> 'store/port': '1'} >> [2006-04-12 16:35:45 xend] DEBUG (DevController:132) Waiting for >> devices vif. >> [2006-04-12 16:35:45 xend] DEBUG (DevController:138) Waiting for 0. >> [2006-04-12 16:35:45 xend] DEBUG (DevController:403) >> hotplugStatusCallback /local/domain/0/backend/vif/32/0/hotplug-status. >> [2006-04-12 16:35:45 xend] DEBUG (DevController:417) >> hotplugStatusCallback 1. >> [2006-04-12 16:35:45 xend] DEBUG (DevController:132) Waiting for >> devices usb. >> [2006-04-12 16:35:45 xend] DEBUG (DevController:132) Waiting for >> devices vbd. >> [2006-04-12 16:35:45 xend] DEBUG (DevController:138) Waiting for 2049. >> [2006-04-12 16:35:45 xend] DEBUG (DevController:403) >> hotplugStatusCallback >> /local/domain/0/backend/vbd/32/2049/hotplug-status. >> [2006-04-12 16:35:45 xend] DEBUG (DevController:403) >> hotplugStatusCallback >> /local/domain/0/backend/vbd/32/2049/hotplug-status. >> [2006-04-12 16:35:45 xend] DEBUG (DevController:417) >> hotplugStatusCallback 1. >> [2006-04-12 16:35:45 xend] DEBUG (DevController:132) Waiting for >> devices pci. >> [2006-04-12 16:35:45 xend] DEBUG (DevController:132) Waiting for >> devices ioports. >> [2006-04-12 16:35:45 xend] DEBUG (DevController:132) Waiting for >> devices vtpm. >> [2006-04-12 16:35:45 xend] INFO (XendDomain:360) Domain xenbox (32) >> unpaused. >> [2006-04-12 16:36:46 xend] DEBUG (XendCheckpoint:80) [xc_save]: >> /usr/lib/xen/bin/xc_save 11 17 32 0 0 1 >> [2006-04-12 16:36:46 xend] ERROR (XendCheckpoint:227) Had 0 >> unexplained entries in p2m table >> [2006-04-12 16:37:36 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 1 0% 5% 10% 15% 21%PT Race: >> [10000000,904] pte=bdc063, mfn=00000bdc >> [2006-04-12 16:37:36 xend] ERROR (XendCheckpoint:227) PT Race: >> [10000000,905] pte=bdd063, mfn=00000bdd >> [2006-04-12 16:37:36 xend] ERROR (XendCheckpoint:227) PT Race: >> [10000000,906] pte=bde063, mfn=00000bde >> [2006-04-12 16:37:36 xend] ERROR (XendCheckpoint:227) PT Race: >> [10000000,907] pte=bdf063, mfn=00000bdf >> [2006-04-12 16:37:36 xend] ERROR (XendCheckpoint:227) PT Race: >> [10000000,908] pte=bd9063, mfn=00000bd9 >> [2006-04-12 16:39:50 xend] ERROR >> (XendCheckpoint:227)  26% 31% 36% 41% 46% 51% >> 56% 61% 66% 71% 76% 81% 86% 92% 97% >> 1: sent 101026, skipped 30046, delta 184259ms, dom0 7%, target 22%, >> sent 17Mb/s, dirtied 7Mb/s 39422 pages >> [2006-04-12 16:39:54 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 2 0%netbuf race: iter 2, pfn 6638. mfn ffffffff >> [2006-04-12 16:40:22 xend] ERROR >> (XendCheckpoint:227)  5% 10% 17% 25% 30% 38% >> 44% 51% 70% 97% >> 2: sent 17510, skipped 21911, delta 31895ms, dom0 7%, target 22%, >> sent 17Mb/s, dirtied 37Mb/s 36685 pages >> [2006-04-12 16:40:26 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 3 0%netbuf race: iter 3, pfn 6638. mfn ffffffff >> [2006-04-12 16:40:54 xend] ERROR >> (XendCheckpoint:227)  5% 13% 20% 25% 31% 36% >> 41% 47% 52% 59% 72% 86% >> 3: sent 17601, skipped 19083, delta 32029ms, dom0 7%, target 22%, >> sent 18Mb/s, dirtied 37Mb/s 36597 pages >> [2006-04-12 16:40:58 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 4 0%netbuf race: iter 4, pfn 6638. mfn ffffffff >> [2006-04-12 16:41:28 xend] ERROR >> (XendCheckpoint:227)  5% 15% 23% 32% 41% 46% >> 52% 57% 69% 77% 93% >> 4: sent 18460, skipped 18136, delta 33650ms, dom0 7%, target 22%, >> sent 17Mb/s, dirtied 35Mb/s 36693 pages >> [2006-04-12 16:41:31 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 5 0%netbuf race: iter 5, pfn 6638. mfn ffffffff >> [2006-04-12 16:42:00 xend] ERROR >> (XendCheckpoint:227)  6% 13% 18% 27% 32% 37% >> 42% 48% 53% 67% 76% 85% 94% >> 5: sent 17853, skipped 18839, delta 32543ms, dom0 7%, target 22%, >> sent 17Mb/s, dirtied 26Mb/s 26304 pages >> [2006-04-12 16:42:02 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 6 0%netbuf race: iter 6, pfn 6638. mfn ffffffff >> [2006-04-12 16:42:18 xend] ERROR >> (XendCheckpoint:227)  9% 19% 27% 38% 51% 67% >> 78% 90% >> 6: sent 9973, skipped 16330, delta 18135ms, dom0 7%, target 22%, sent >> 18Mb/s, dirtied 52Mb/s 28903 pages >> [2006-04-12 16:42:22 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 7 0%netbuf race: iter 7, pfn 6638. mfn ffffffff >> [2006-04-12 16:42:40 xend] ERROR >> (XendCheckpoint:227)  9% 18% 25% 32% 37% 44% >> 51% 74% >> 7: sent 11736, skipped 17166, delta 21407ms, dom0 7%, target 22%, >> sent 17Mb/s, dirtied 52Mb/s 34244 pages >> [2006-04-12 16:42:43 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 8 0%netbuf race: iter 8, pfn 6638. mfn ffffffff >> [2006-04-12 16:43:08 xend] ERROR >> (XendCheckpoint:227)  5% 13% 19% 26% 32% 38% >> 44%netbuf race: iter 8, pfn 173c3. mfn ffffffff >> [2006-04-12 16:43:10 xend] ERROR (XendCheckpoint:227) netbuf race: >> iter 8, pfn 1651. mfn ffffffff >> [2006-04-12 16:43:21 xend] ERROR >> (XendCheckpoint:227)  50% 55% 65%netbuf race: iter 8, pfn >> 395b. mfn ffffffff >> [2006-04-12 16:43:23 xend] ERROR (XendCheckpoint:227) netbuf race: >> iter 8, pfn 18e15. mfn ffffffff >> [2006-04-12 16:43:28 xend] ERROR (XendCheckpoint:227)  74%netbuf >> race: iter 8, pfn 1f197. mfn ffffffff >> [2006-04-12 16:43:36 xend] ERROR (XendCheckpoint:227)  80% >> 86%netbuf race: iter 8, pfn 475e. mfn ffffffff >> [2006-04-12 16:43:39 xend] ERROR (XendCheckpoint:227)  92%netbuf >> race: iter 8, pfn 1c7d6. mfn ffffffff >> [2006-04-12 16:43:42 xend] ERROR (XendCheckpoint:227)  98% >> 8: sent 34027, skipped 209, delta 61914ms, dom0 6%, target 23%, sent >> 18Mb/s, dirtied 0Mb/s 232 pages >> [2006-04-12 16:43:42 xend] ERROR (XendCheckpoint:227) Saving memory >> pages: iter 9 0% >> 9: sent 232, skipped 0, Start last iteration >> [2006-04-12 16:43:42 xend] DEBUG (XendCheckpoint:200) suspend >> [2006-04-12 16:43:42 xend] DEBUG (XendCheckpoint:83) In >> saveInputHandler suspend >> [2006-04-12 16:43:42 xend] DEBUG (XendCheckpoint:85) Suspending 32 ... >> [2006-04-12 16:47:28 xend.XendDomainInfo] DEBUG (XendDomainInfo:1272) >> XendDomainInfo.destroy: domid=32 >> [2006-04-12 16:47:28 xend.XendDomainInfo] DEBUG (XendDomainInfo:1280) >> XendDomainInfo.destroyDomain(32) >> [2006-04-12 16:47:28 xend] INFO (XendCheckpoint:88) Domain 32 suspended. >> [2006-04-12 16:47:28 xend] ERROR (XendCheckpoint:99) Save failed on >> domain xenbox (32). >> Traceback (most recent call last): >> File "/usr/lib/python/xen/xend/XendCheckpoint.py", line 93, in save >> forkHelper(cmd, fd, saveInputHandler, False) >> File "/usr/lib/python/xen/xend/XendCheckpoint.py", line 206, in >> forkHelper >> raise XendError('Error reading from child process for %s: %s' % >> >> >> >> _______________________________________________ >> Xen-devel mailing list >> Xen-devel@lists.xensource.com >> http://lists.xensource.com/xen-devel > >