[Xen-API] XCP 1.1b1: problems with Centos6 migration

[George Shuklin <george.shuklin@xxxxxxxxx>]

Good day.

I was too optimistic last in my previous report: Migration works fine 
within single host (localhost migration), but migration between two 
hosts make things much worse.
After few migration CentOS6 (PV, 1 VCPU, native centos kernel, lvmoiscsi 
shared SR) it hangs. I do few series, usually problem appear in 3-15 loops.
Symptoms: domain is present, have state 'r' in xentop (running), but 
consume 0.0 seconds of time, do not response via network and console at 
all (no output, no reaction to input, incuding the magic kernel keys 
(Ctrl-O t, f.e.).
After that (next attempts) only VM_FAILED_SHUTDOWN_ACKNOWLEDGMENT: [  ] 
As far as I understand this is issue with pv-ops kernel (-xen kernels 
seems work fine, f.e. centos 5.6 fly befween hosts without any troubles).
... and I don't really know how to debug this problem any deeper: How I 
can see what happens in (unsuccessfully) starting domain before any 
console output?
In xensource.log (sorry for long quotation, nothing but logs below):

RECIPIENT:

[20110717T03:25:22.985Z| info|srv-xh6|588 inet_rpc|sm_exec 
D:bbc19f84d324|xapi] Session.destroy 
trackid=55deffe6654a23d2a9cc602c2716f6a6
[20110717T03:25:22.987Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|storage_access] Executed activate succesfully on VDI 
'OpaqueRef:c34b2134-fe3e-0780-a5bf-12e4cd3edd4e'; activate refcount now: 1
[20110717T03:25:22.990Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|xapi] Receiver 7a1. Calling Vmops._restore_devices (domid 
= 2) for non-CD devices [doing this now because we call after activate]
[20110717T03:25:23.007Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|xapi] To restore this domain we need VBDs: [ 
0/xvda:2c6f0960-2742-48ab-9935-4ddb2d5fcb28 ]
[20110717T03:25:23.027Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|xenops] Device.Vbd.add (virtpath=xvda | 
physpath=/dev/sm/backend/3aa703ca-6699-36bd-35c3-ad03fc8718c9/2c6f0960-2742-48ab-9935-4ddb2d5fcb28 
| phystype=vhd)
[20110717T03:25:23.028Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|xenops] adding device  
B0[/local/domain/0/backend/vbd/2/51712]  
F2[/local/domain/2/device/vbd/51712]  H[/xapi/2/hotplug/vbd/51712]
[20110717T03:25:23.031Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|hotplug] Hotplug.wait_for_plug: frontend (domid=2 | 
kind=vbd | devid=51712); backend (domid=0 | kind=vbd | devid=51712)
[20110717T03:25:23.031Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|xenops] watch: watching xenstore paths: [ 
/xapi/2/hotplug/vbd/51712/hotplug ] with timeout 1200.000000 seconds
[20110717T03:25:23.331Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|hotplug] Synchronised ok with hotplug script: frontend 
(domid=2 | kind=vbd | devid=51712); backend (domid=0 | kind=vbd | 
devid=51712)
[20110717T03:25:23.334Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|xapi] set_currently_attached to true for VBD uuid 
82a3fd30-9f00-4cd7-b9f9-afdd01ba3012
[20110717T03:25:23.357Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|xapi] Trying to attach PIF: 
f710b21e-2c64-9614-bfca-6b77f376796e
[20110717T03:25:23.387Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|xenops] Device.Vif.add domid=2 devid=0 
mac=a2:ef:dc:c5:06:12 carrier=true rate=none other_config=[] 
extra_private_keys=[ref=OpaqueRef:cf60a63e-2823-691e-c03f-8d988cfab422; 
vif-uuid=a8c2db6c-c948-51f6-5e15-1778d86b1e70; 
network-uuid=b6da77c9-c514-61d9-6810-a4ae821885fc]
[20110717T03:25:23.387Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|xenops] adding device  
B0[/local/domain/0/backend/vif/2/0]  F2[/local/domain/2/device/vif/0]  
H[/xapi/2/hotplug/vif/0]
[20110717T03:25:23.391Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|hotplug] Hotplug.wait_for_plug: frontend (domid=2 | 
kind=vif | devid=0); backend (domid=0 | kind=vif | devid=0)
[20110717T03:25:23.391Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|xenops] watch: watching xenstore paths: [ 
/xapi/2/hotplug/vif/0/hotplug ] with timeout 1200.000000 seconds
[20110717T03:25:23.538Z| info|srv-xh6|31 heartbeat|Heartbeat 
D:d80b0889665c|http] stunnel pid: 10354 (cached = false) connected to 
10.1.3.5:443
[20110717T03:25:23.794Z|debug|srv-xh6|236 xal_listen||event] VM (domid: 
2) device_event = HotplugChanged on 0 {""->online}
[20110717T03:25:23.795Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|hotplug] Synchronised ok with hotplug script: frontend 
(domid=2 | kind=vif | devid=0); backend (domid=0 | kind=vif | devid=0)
[20110717T03:25:23.798Z|debug|srv-xh6|236 xal_listen|VM (domid: 2) 
device_event = HotplugChanged on 0 {""->online} D:06ba0c69ccd3|event] 
Adding Resync.vif to queue
[20110717T03:25:23.798Z|debug|srv-xh6|236 xal_listen|VM (domid: 2) 
device_event = HotplugChanged on 0 {""->online} 
D:06ba0c69ccd3|locking_helpers] push(per-VM queue, HotplugChanged(vif, 
0) domid: 2); queue = [ HotplugChanged(vif, 0) domid: 2 ](1)
[20110717T03:25:23.800Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|xapi] setting current number of vcpus to 1 (out of 1)
[20110717T03:25:23.803Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|xapi] Receiver 7b. unpausing domain
[20110717T03:25:23.812Z|debug|srv-xh6|236 xal_listen||event] VM (domid: 
2) device_event = device thread {51712} pid=10424
[20110717T03:25:23.813Z| info|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|http] stunnel pid: 9963 (cached = true) connected to 
10.1.3.5:443
[20110717T03:25:23.835Z|debug|srv-xh6|236 xal_listen|VM (domid: 2) 
device_event = device thread {51712} pid=10424 D:8489d7fe9933|event] 
Adding Vbdops.set_vbd_qos to queue
[20110717T03:25:23.835Z|debug|srv-xh6|236 xal_listen|VM (domid: 2) 
device_event = device thread {51712} pid=10424 
D:8489d7fe9933|locking_helpers] push(per-VM queue, DevThread(51712, 
10424) domid 2); queue = [ HotplugChanged(vif, 0) domid: 2; 
DevThread(51712, 10424) domid 2 ](2)
[20110717T03:25:23.836Z|debug|srv-xh6|236 xal_listen||event] VM (domid: 
2) device_event = device thread {51760} pid=10425
[20110717T03:25:23.839Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|xapi] Receiver 8. signalling sender that we're done
[20110717T03:25:23.839Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|xapi] Receiver 9a Success
[20110717T03:25:23.839Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|locking_helpers] pop(per-VM queue) = HotplugChanged(vif, 
0) domid: 2
[20110717T03:25:24.009Z|debug|srv-xh6|236 xal_listen|VM (domid: 2) 
device_event = device thread {51760} pid=10425 D:7ebcccec7c2c|event] 
Adding Vbdops.set_vbd_qos to queue
[20110717T03:25:24.009Z|debug|srv-xh6|236 xal_listen|VM (domid: 2) 
device_event = device thread {51760} pid=10425 
D:7ebcccec7c2c|thread_queue] push(vm_lifecycle_op, DevThread(51760, 
10425) domid 2): queue = [ DevThread(51760, 10425) domid 2 ](1)
[20110717T03:25:24.009Z|debug|srv-xh6|261||thread_queue] 
pop(vm_lifecycle_op) = DevThread(51760, 10425) domid 2
[20110717T03:25:24.010Z|debug|srv-xh6|261||event] VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf: grabbing lock to 
perform: DevThread(51760, 10425) domid 2
[20110717T03:25:24.011Z|debug|srv-xh6|588 inet_rpc|VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf: processing 
HotplugChanged(vif, 0) domid: 2 D:96e513f93cbe|event] VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf: about to perform: 
HotplugChanged(vif, 0) domid: 2
[20110717T03:25:24.014Z|debug|srv-xh6|588 inet_rpc|VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf: processing 
HotplugChanged(vif, 0) domid: 2 D:96e513f93cbe|event] VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf (domid: 2) Resync.vif 
OpaqueRef:cf60a63e-2823-691e-c03f-8d988cfab422
[20110717T03:25:24.021Z|debug|srv-xh6|588 inet_rpc|VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf: processing 
HotplugChanged(vif, 0) domid: 2 D:96e513f93cbe|event] VIF 
OpaqueRef:cf60a63e-2823-691e-c03f-8d988cfab422: is_attached = true; 
online = true
[20110717T03:25:24.021Z|debug|srv-xh6|588 inet_rpc|VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf: processing 
HotplugChanged(vif, 0) domid: 2 D:96e513f93cbe|event] 
VIF.currently_attached field is in sync
[20110717T03:25:24.021Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|locking_helpers] pop(per-VM queue) = DevThread(51712, 
10424) domid 2
[20110717T03:25:24.023Z|debug|srv-xh6|588 inet_rpc|VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf: processing 
DevThread(51712, 10424) domid 2 D:a38442a2eb2e|event] VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf: about to perform: 
DevThread(51712, 10424) domid 2
[20110717T03:25:24.028Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|locking_helpers] Released lock on VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf with token 10
[20110717T03:25:24.028Z|debug|srv-xh6|261||locking_helpers] Acquired 
lock on VM OpaqueRef:dd860476-057f-2b22-6120-7668828720cf with token 11
[20110717T03:25:24.036Z|debug|srv-xh6|588 inet_rpc|VM.pool_migrate 
R:524e127c00dc|taskhelper] forwarded task destroyed
[20110717T03:25:24.038Z|debug|srv-xh6|261|VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf: processing 
DevThread(51760, 10425) domid 2 D:973a5d8631fb|event] VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf: about to perform: 
DevThread(51760, 10425) domid 2
[20110717T03:25:24.042Z|debug|srv-xh6|261||locking_helpers] Released 
lock on VM OpaqueRef:dd860476-057f-2b22-6120-7668828720cf with token 11


SENDER:

[20110717T03:25:01.740Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-d5cf70da-0e07-f363-3579-dd11117ae164 
D:27f4c75cf51a|dispatcher] Unknown rpc 
"unknown-message-d5cf70da-0e07-f363-3579-dd11117ae164"
[20110717T03:25:01.743Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:session.get_uuid D:5337c58feb87 created by task D:af663a5fb7f0
[20110717T03:25:01.749Z|debug|srv-xh5|861 
inet-RPC|dispatch:unknown-message-0eb150ce-acbd-f892-3d22-69521767303e 
D:ab180dd3e254|dispatcher] Unknown rpc 
"unknown-message-0eb150ce-acbd-f892-3d22-69521767303e"
[20110717T03:25:01.751Z|debug|srv-xh5|861 inet-RPC||cli] xe vm-migrate 
uuid=a0e508db-fb6d-4ad9-4d68-9e6d20a0d2c5 host=srv-xh6 username=root 
password=null
[20110717T03:25:01.989Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|audit] VM.pool_migrate: VM = 
'a0e508db-fb6d-4ad9-4d68-9e6d20a0d2c5 (1499_5393)'; host = 
'0923dc25-9db9-43ad-b4e6-df8c10aa7e94 (srv-xh6)'
[20110717T03:25:01.993Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Raised at db_cache_types.ml:75.27-76 -> 
db_cache_types.ml:118.2-40 -> pervasiveext.ml:22.2-9
[20110717T03:25:01.994Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] host srv-xh6; available_memory = 50067652608; 
memory_required = 1084227584
[20110717T03:25:01.994Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi_ha_vm_failover] 
assert_configuration_change_preserves_ha_plan c = configuration_change = 
{ old_vms_leaving = [  ]; new_vms_arriving = [ 4f82279c (srv-xh6) 
dd860476 (1499_5393) ]; hosts_to_disable = [  ]; num_failures = no 
change; new_vms = [  ] }
[20110717T03:25:01.999Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|thread_queue] push(long_running_op, VM.pool_migrate 
VM.pool_migrate R:524e127c00dc): queue = [ VM.pool_migrate 
VM.pool_migrate R:524e127c00dc ](1)
[20110717T03:25:02.000Z|debug|srv-xh5|872||thread_queue] 
pop(long_running_op) = VM.pool_migrate VM.pool_migrate R:524e127c00dc
[20110717T03:25:02.000Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|locking_helpers] Acquired lock on VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf with token 6
[20110717T03:25:02.001Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] VM is running; attempting migration
[20110717T03:25:02.001Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Sender doing a dead migration
[20110717T03:25:02.002Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Sender 1. Logging into remote server
[20110717T03:25:02.004Z|debug|srv-xh5|874 unix-RPC||dummytaskhelper] 
task dispatch:session.slave_login D:bcc430648842 created by task 
R:524e127c00dc
[20110717T03:25:02.009Z| info|srv-xh5|874 unix-RPC|session.slave_login 
D:9067ddf4f38a|xapi] Session.create 
trackid=fe7e3d8d48fcd164b2a29b75c4a2147b pool=true uname= 
is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
[20110717T03:25:02.012Z|debug|srv-xh5|875 unix-RPC||dummytaskhelper] 
task dispatch:session.get_uuid D:1d7451396ce3 created by task D:9067ddf4f38a
[20110717T03:25:02.015Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|memory_control] rebalance_memory
[20110717T03:25:02.015Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenstore-rpc] Checking pid 6807
[20110717T03:25:02.016Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenstore-rpc] Written request using id: 
4fb7bfff-7ae1-8b8b-e7fa-ab47552facfe
[20110717T03:25:02.016Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] watch: watching xenstore paths: [ 
/squeezed/rpc/response/balance-memory/4fb7bfff-7ae1-8b8b-e7fa-ab47552facfe 
] with timeout 1200.000000 seconds
[20110717T03:25:02.020Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Sender 2. Transmitting an HTTP CONNECT to URI: 
/migrate?ref=OpaqueRef:dd860476-057f-2b22-6120-7668828720cf&memory_required_kib=1048576
[20110717T03:25:02.035Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-1b727ec6-2845-b957-ce71-04ab690be24d 
D:c8d559522194|dispatcher] Unknown rpc 
"unknown-message-1b727ec6-2845-b957-ce71-04ab690be24d"
[20110717T03:25:02.038Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:session.slave_login D:8b953fb837f0 created by task 
D:eaf893862dbe
[20110717T03:25:02.041Z| info|srv-xh5|769 inet-RPC|session.slave_login 
D:d266425e2834|xapi] Session.create 
trackid=a4a82daebd2b29a9dad6114e986271a3 pool=true uname= 
is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
[20110717T03:25:02.043Z|debug|srv-xh5|877 unix-RPC||dummytaskhelper] 
task dispatch:session.get_uuid D:85916d34d95b created by task D:d266425e2834
[20110717T03:25:02.048Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-16044a28-af26-93a6-ce4e-a92d1c8b6a64 
D:81ab25a8e098|dispatcher] Unknown rpc 
"unknown-message-16044a28-af26-93a6-ce4e-a92d1c8b6a64"
[20110717T03:25:02.051Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:pool.audit_log_append D:234e98efa72f created by task 
D:eaf893862dbe
[20110717T03:25:02.054Z| info|srv-xh5|769 
inet-RPC|dispatch:pool.audit_log_append D:234e98efa72f|taskhelper] task 
pool.audit_log_append R:108324b9a15a 
(uuid:a0a66d00-c651-ab85-d22b-9726af8faf2b) created 
(trackid=a4a82daebd2b29a9dad6114e986271a3) by task D:eaf893862dbe
[20110717T03:25:02.058Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-9527f44a-683f-a50d-1227-45a9e49aa111 
D:c17e4dd3c5f5|dispatcher] Unknown rpc 
"unknown-message-9527f44a-683f-a50d-1227-45a9e49aa111"
[20110717T03:25:02.061Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:session.logout D:f7a3ba820dce created by task D:eaf893862dbe
[20110717T03:25:02.063Z| info|srv-xh5|769 inet-RPC|session.logout 
D:026cf0ac142a|xapi] Session.destroy 
trackid=a4a82daebd2b29a9dad6114e986271a3
[20110717T03:25:02.118Z|debug|srv-xh5|506 inet-RPC||xapi] Raised at 
db_cache_types.ml:75.27-76 -> db_cache_types.ml:118.2-40 -> 
pervasiveext.ml:22.2-9
[20110717T03:25:02.132Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-f32cf413-5ead-09cc-ebe1-c134931037db 
D:f541b82fb842|dispatcher] Unknown rpc 
"unknown-message-f32cf413-5ead-09cc-ebe1-c134931037db"
[20110717T03:25:02.135Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:session.get_uuid D:d0a51881c600 created by task D:7873d345ba5c
[20110717T03:25:02.217Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-2ecdc50f-5f61-8ae8-e00d-0b0c96dee087 
D:db3950aa4a50|dispatcher] Unknown rpc 
"unknown-message-2ecdc50f-5f61-8ae8-e00d-0b0c96dee087"
[20110717T03:25:02.220Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:f2196d9b65be created by task 
R:524e127c00dc
[20110717T03:25:02.228Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-8c594cdc-028c-c846-071f-312931eab03e 
D:9148389a81ef|dispatcher] Unknown rpc 
"unknown-message-8c594cdc-028c-c846-071f-312931eab03e"
[20110717T03:25:02.232Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:28863224bcf7 created by task 
R:524e127c00dc
[20110717T03:25:02.238Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-ace421d9-05e7-56ae-a22f-7205beaa0e4a 
D:2e4608f366d6|dispatcher] Unknown rpc 
"unknown-message-ace421d9-05e7-56ae-a22f-7205beaa0e4a"
[20110717T03:25:02.241Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:PBD.get_all_records D:da5c53e47e69 created by task 
R:524e127c00dc
[20110717T03:25:02.255Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-7ead9cf4-6d0f-b8c2-311b-7a8269ee1cfd 
D:b3ca1554cff8|dispatcher] Unknown rpc 
"unknown-message-7ead9cf4-6d0f-b8c2-311b-7a8269ee1cfd"
[20110717T03:25:02.258Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:9ae1d8a347e5 created by task R:524e127c00dc
[20110717T03:25:02.265Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-6281ddf3-7779-7ef5-dcce-4bf19d36caff 
D:be361fa5c4e6|dispatcher] Unknown rpc 
"unknown-message-6281ddf3-7779-7ef5-dcce-4bf19d36caff"
[20110717T03:25:02.269Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:322103060db5 created by task 
R:524e127c00dc
[20110717T03:25:02.313Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-947529a2-837a-fae5-5e62-99286ca60145 
D:cb4404e7f87f|dispatcher] Unknown rpc 
"unknown-message-947529a2-837a-fae5-5e62-99286ca60145"
[20110717T03:25:02.316Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:PBD.get_all_records D:b9e9aa63b911 created by task 
R:524e127c00dc
[20110717T03:25:02.329Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-8bcea59c-ffbd-34b4-43eb-b0b5fd7fc820 
D:1b825c719144|dispatcher] Unknown rpc 
"unknown-message-8bcea59c-ffbd-34b4-43eb-b0b5fd7fc820"
[20110717T03:25:02.333Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:SR.get_other_config D:173e14c71a41 created by task 
R:524e127c00dc
[20110717T03:25:02.340Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-1fb7f3da-15c5-e3ec-b804-85e90312e7b1 
D:eec2cca57fcb|dispatcher] Unknown rpc 
"unknown-message-1fb7f3da-15c5-e3ec-b804-85e90312e7b1"
[20110717T03:25:02.343Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:7313dbb4784b created by task R:524e127c00dc
[20110717T03:25:02.457Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-5e026680-cbf4-4658-9e26-5bbf129cfe77 
D:915f97e05f7a|dispatcher] Unknown rpc 
"unknown-message-5e026680-cbf4-4658-9e26-5bbf129cfe77"
[20110717T03:25:02.460Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:SR.get_other_config D:8e9499647984 created by task 
R:524e127c00dc
[20110717T03:25:02.467Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-7fbc503f-a46e-84d5-0077-52243d919e8f 
D:08dc80f181e2|dispatcher] Unknown rpc 
"unknown-message-7fbc503f-a46e-84d5-0077-52243d919e8f"
[20110717T03:25:02.470Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:e114d1d174c6 created by task R:524e127c00dc
[20110717T03:25:02.517Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-53b2daa6-19c2-3a95-3d8c-0713616915ee 
D:7189557e47fe|dispatcher] Unknown rpc 
"unknown-message-53b2daa6-19c2-3a95-3d8c-0713616915ee"
[20110717T03:25:02.520Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:VDI.get_sm_config D:00d59f14e36e created by task 
R:524e127c00dc
[20110717T03:25:02.554Z|debug|srv-xh5|506 inet-RPC||xapi] Raised at 
db_cache_types.ml:75.27-76 -> db_cache_types.ml:118.2-40 -> 
pervasiveext.ml:22.2-9
[20110717T03:25:02.566Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-5e8b73e7-21c7-8d28-c388-4946ae443687 
D:ee3e651e1c02|dispatcher] Unknown rpc 
"unknown-message-5e8b73e7-21c7-8d28-c388-4946ae443687"
[20110717T03:25:02.569Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:session.get_uuid D:92ce25fd9e93 created by task D:3cc1fbecd2cf
[20110717T03:25:02.649Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-90a874a4-1763-f5d3-f38a-14ccb238bd8c 
D:1686de56f91f|dispatcher] Unknown rpc 
"unknown-message-90a874a4-1763-f5d3-f38a-14ccb238bd8c"
[20110717T03:25:02.652Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:82af869b00d0 created by task 
R:524e127c00dc
[20110717T03:25:02.659Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-02c62b3f-990b-b6be-71e7-2b47e5b0e373 
D:cb8f1708f741|dispatcher] Unknown rpc 
"unknown-message-02c62b3f-990b-b6be-71e7-2b47e5b0e373"
[20110717T03:25:02.662Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:PBD.get_all_records D:63d5d25b5ecd created by task 
R:524e127c00dc
[20110717T03:25:02.674Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-34dfd6f8-54cb-cf3c-9f3d-cc032e8189c6 
D:fb5ea6cf3151|dispatcher] Unknown rpc 
"unknown-message-34dfd6f8-54cb-cf3c-9f3d-cc032e8189c6"
[20110717T03:25:02.677Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:45244eaabb53 created by task R:524e127c00dc
[20110717T03:25:03.096Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Sender 4. calling Domain.suspend (domid = 1; hvm = 
false)
[20110717T03:25:03.097Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Domain.suspend domid=1
[20110717T03:25:03.097Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] connect: args = [ -fd 
322504e6-b5e0-c620-3b8f-c94aae892555 -mode save -domid 1 -fork true ]
[20110717T03:25:03.105Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Blocking for suspend notification from xenguest
[20110717T03:25:03.109Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] got suspend notification from xenguesthelper
[20110717T03:25:03.109Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Requesting shutdown of domain 1
[20110717T03:25:03.110Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Waiting for PV domain 1 to acknowledge shutdown 
request
[20110717T03:25:03.111Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] watch: watching xenstore paths: [ 
/local/domain/1/control/shutdown ] with timeout 10.000000 seconds
[20110717T03:25:03.111Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Domain acknowledged shutdown request
[20110717T03:25:03.111Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] MTC: calling xal.wait_release timeout=1.000000
[20110717T03:25:04.114Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] MTC: calling xal.wait_release timeout=1.000000
[20110717T03:25:04.114Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] done\n
[20110717T03:25:04.121Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] Had 0 unexplained entries in p2m 
table\nSaving memory pages: iter 1   0%
[20110717T03:25:17.066Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b  5%
[20110717T03:25:17.415Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 10%
[20110717T03:25:17.594Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 15%
[20110717T03:25:17.773Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 20%
[20110717T03:25:17.941Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 25%
[20110717T03:25:18.123Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 30%
[20110717T03:25:18.310Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 35%
[20110717T03:25:18.488Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 40%
[20110717T03:25:18.670Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 45%
[20110717T03:25:18.834Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 50%
[20110717T03:25:19.018Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 55%
[20110717T03:25:19.201Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 60%
[20110717T03:25:19.384Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 65%
[20110717T03:25:19.567Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 70%
[20110717T03:25:19.735Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 75%
[20110717T03:25:19.922Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 80%
[20110717T03:25:20.101Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 85%
[20110717T03:25:20.290Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 90%
[20110717T03:25:20.474Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \b\b\b\b 95%
[20110717T03:25:20.640Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] \r 1: sent 262144, skipped 0,
[20110717T03:25:20.640Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] delta 16520ms, dom0 11%, target 0%, sent 
519Mb/s, dirtied 730Mb/s -1217028608 pages\n
[20110717T03:25:20.640Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] Total pages sent= 262144 (1.00x)\n
[20110717T03:25:20.640Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] (of which 0 were fixups)\n
[20110717T03:25:20.640Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] All memory is saved\n
[20110717T03:25:20.652Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenguesthelper] Save exit rc=0\n
[20110717T03:25:20.653Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] migration_progress = 1.00
[20110717T03:25:20.653Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Final result:
[20110717T03:25:20.653Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Suspend for domid 1 finished
[20110717T03:25:20.654Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Sender 5. waiting for blocks to flush
[20110717T03:25:20.654Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Device.Vbd.request_shutdown frontend (domid=1 | 
kind=vbd | devid=51712); backend (domid=0 | kind=vbd | devid=51712) force
[20110717T03:25:20.654Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-write 
/local/domain/0/backend/vbd/1/51712/shutdown-request = force
[20110717T03:25:20.654Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] watch: watching xenstore paths: [ 
/local/domain/0/backend/vbd/1/51712/shutdown-done ] with timeout 
1200.000000 seconds
[20110717T03:25:20.656Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] VBD backends have flushed
[20110717T03:25:20.656Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Sender 5a. Deactivating VDIs
[20110717T03:25:20.656Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|storage_access] Considering execute deactivate on VDI 
'OpaqueRef:c34b2134-fe3e-0780-a5bf-12e4cd3edd4e'; activate refcount now: 1
[20110717T03:25:20.656Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|sm] SM lvmoiscsi vdi_deactivate 
sr=OpaqueRef:a1077822-9453-de43-0efa-ecb0fe508f59 
vdi=OpaqueRef:c34b2134-fe3e-0780-a5bf-12e4cd3edd4e
[20110717T03:25:20.657Z|debug|srv-xh5|861 inet-RPC|sm_exec 
D:30b89d60d8c5|xapi] Raised at db_cache_types.ml:75.27-76 -> 
db_cache_types.ml:118.2-40 -> pervasiveext.ml:22.2-9
[20110717T03:25:20.659Z| info|srv-xh5|861 inet-RPC|sm_exec 
D:a422fab8f94a|xapi] Session.create 
trackid=8a1c909d031af45eef1af1c16b83bfa4 pool=false uname= 
is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
[20110717T03:25:20.660Z|debug|srv-xh5|326 xal_listen||event] VM (domid: 
1) device_event = device shutdown {vbd,51712}
[20110717T03:25:20.661Z|debug|srv-xh5|326 xal_listen|VM (domid: 1) 
device_event = device shutdown {vbd,51712} D:8fcb1674e914|event] Adding 
Resync.vbd to queue
[20110717T03:25:20.661Z|debug|srv-xh5|326 xal_listen|VM (domid: 1) 
device_event = device shutdown {vbd,51712} 
D:8fcb1674e914|locking_helpers] push(per-VM queue, DevShutdownDone(vbd, 
51712) domid: 1); queue = [ DevShutdownDone(vbd, 51712) domid: 1 ](1)
[20110717T03:25:20.662Z|debug|srv-xh5|878 unix-RPC||dummytaskhelper] 
task dispatch:session.get_uuid D:6416926c95c6 created by task D:a422fab8f94a
[20110717T03:25:20.739Z|debug|srv-xh5|879 unix-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:e4492518324b created by task 
R:524e127c00dc
[20110717T03:25:20.745Z|debug|srv-xh5|880 unix-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:aa523fad6d08 created by task 
R:524e127c00dc
[20110717T03:25:20.749Z|debug|srv-xh5|881 unix-RPC||dummytaskhelper] 
task dispatch:PBD.get_all_records D:e342bdc29be7 created by task 
R:524e127c00dc
[20110717T03:25:20.758Z|debug|srv-xh5|882 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:862b4dd2b17e created by task R:524e127c00dc
[20110717T03:25:20.763Z|debug|srv-xh5|883 unix-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:62e0206f0a8d created by task 
R:524e127c00dc
[20110717T03:25:20.805Z|debug|srv-xh5|884 unix-RPC||dummytaskhelper] 
task dispatch:PBD.get_all_records D:018837a3a115 created by task 
R:524e127c00dc
[20110717T03:25:20.814Z|debug|srv-xh5|885 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_other_config D:7b621f89b5eb created by task 
R:524e127c00dc
[20110717T03:25:20.819Z|debug|srv-xh5|886 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:4ee5086a1b4a created by task R:524e127c00dc
[20110717T03:25:20.968Z|debug|srv-xh5|887 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_other_config D:5dc86257d8aa created by task 
R:524e127c00dc
[20110717T03:25:20.973Z|debug|srv-xh5|888 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:2b0f3370d6b8 created by task R:524e127c00dc
[20110717T03:25:21.053Z|debug|srv-xh5|889 unix-RPC||dummytaskhelper] 
task dispatch:VDI.get_sm_config D:1365c96ff65b created by task 
R:524e127c00dc
[20110717T03:25:21.059Z|debug|srv-xh5|890 unix-RPC||dummytaskhelper] 
task dispatch:VDI.get_by_uuid D:3a06e3935dae created by task R:524e127c00dc
[20110717T03:25:21.063Z|debug|srv-xh5|891 unix-RPC||dummytaskhelper] 
task dispatch:VDI.get_sm_config D:1551b544d4d7 created by task 
R:524e127c00dc
[20110717T03:25:21.146Z| info|srv-xh5|892 
unix-RPC|session.login_with_password D:fc6e0fd55e5c|xapi] Session.create 
trackid=c7254b4ee213f904468db9d99aad81e3 pool=false uname=root 
is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
[20110717T03:25:21.148Z|debug|srv-xh5|893 unix-RPC||dummytaskhelper] 
task dispatch:session.get_uuid D:3e2ef7bc707b created by task D:fc6e0fd55e5c
[20110717T03:25:21.176Z| info|srv-xh5|899 
unix-RPC|dispatch:VDI.remove_from_sm_config D:0739bca94433|api_effect] 
VDI.remove_from_sm_config
[20110717T03:25:21.181Z| info|srv-xh5|900 
unix-RPC|dispatch:VDI.remove_from_sm_config D:c291a6652eb0|api_effect] 
VDI.remove_from_sm_config
[20110717T03:25:21.186Z| info|srv-xh5|901 unix-RPC|session.logout 
D:95729441ad3f|xapi] Session.destroy 
trackid=c7254b4ee213f904468db9d99aad81e3
[20110717T03:25:21.189Z|debug|srv-xh5|902 unix-RPC||dummytaskhelper] 
task dispatch:VDI.get_by_uuid D:82977ea7716e created by task R:524e127c00dc
[20110717T03:25:21.194Z|debug|srv-xh5|903 unix-RPC||dummytaskhelper] 
task dispatch:VDI.get_SR D:ecb0b5029946 created by task R:524e127c00dc
[20110717T03:25:21.199Z|debug|srv-xh5|904 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_uuid D:19633a79a896 created by task R:524e127c00dc
[20110717T03:25:21.203Z|debug|srv-xh5|905 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_by_uuid D:8e2bca902494 created by task R:524e127c00dc
[20110717T03:25:21.208Z|debug|srv-xh5|906 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_type D:febefab168b5 created by task R:524e127c00dc
[20110717T03:25:21.213Z|debug|srv-xh5|907 unix-RPC||dummytaskhelper] 
task dispatch:SM.get_all_records_where D:7af199168cea created by task 
R:524e127c00dc
[20110717T03:25:21.219Z|debug|srv-xh5|908 unix-RPC||dummytaskhelper] 
task dispatch:SM.get_driver_filename D:13305f374ecc created by task 
R:524e127c00dc
[20110717T03:25:21.224Z|debug|srv-xh5|909 unix-RPC||dummytaskhelper] 
task dispatch:VM.get_all_records_where D:8cffc0c4d82c created by task 
R:524e127c00dc
[20110717T03:25:21.233Z|debug|srv-xh5|910 unix-RPC||dummytaskhelper] 
task dispatch:PBD.get_all_records_where D:200b58202c7e created by task 
R:524e127c00dc
[20110717T03:25:21.238Z|debug|srv-xh5|911 unix-RPC||dummytaskhelper] 
task dispatch:PBD.get_device_config D:6c10b06d167f created by task 
R:524e127c00dc
[20110717T03:25:21.860Z|debug|srv-xh5|924 unix-RPC||dummytaskhelper] 
task dispatch:VDI.get_by_uuid D:5c20f2c1bd1d created by task R:524e127c00dc
[20110717T03:25:21.865Z|debug|srv-xh5|925 unix-RPC||dummytaskhelper] 
task dispatch:host.get_by_uuid D:40b691ff7cc3 created by task R:524e127c00dc
[20110717T03:25:21.869Z|debug|srv-xh5|926 unix-RPC||dummytaskhelper] 
task dispatch:VDI.get_sm_config D:d58b855d3328 created by task 
R:524e127c00dc
[20110717T03:25:21.874Z|debug|srv-xh5|927 unix-RPC||dummytaskhelper] 
task dispatch:VDI.remove_from_sm_config D:4894e9f33205 created by task 
R:524e127c00dc
[20110717T03:25:21.875Z| info|srv-xh5|927 
unix-RPC|dispatch:VDI.remove_from_sm_config D:4894e9f33205|api_effect] 
VDI.remove_from_sm_config
[20110717T03:25:21.886Z| info|srv-xh5|861 inet-RPC|sm_exec 
D:a422fab8f94a|xapi] Session.destroy 
trackid=8a1c909d031af45eef1af1c16b83bfa4
[20110717T03:25:21.887Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|storage_access] Executed deactivate in backend succesfully
[20110717T03:25:21.887Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Sender 6. signalling remote to unpause
[20110717T03:25:21.887Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Sender 6a. Detaching VDIs
[20110717T03:25:21.888Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|sm] SM lvmoiscsi vdi_detach 
sr=OpaqueRef:a1077822-9453-de43-0efa-ecb0fe508f59 
vdi=OpaqueRef:c34b2134-fe3e-0780-a5bf-12e4cd3edd4e
[20110717T03:25:21.889Z|debug|srv-xh5|861 inet-RPC|sm_exec 
D:69c3c89d6b89|xapi] Raised at db_cache_types.ml:75.27-76 -> 
db_cache_types.ml:118.2-40 -> pervasiveext.ml:22.2-9
[20110717T03:25:21.891Z| info|srv-xh5|861 inet-RPC|sm_exec 
D:d42fb7605e99|xapi] Session.create 
trackid=2d11838049b96a0d313ba1a9ac738e13 pool=false uname= 
is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
[20110717T03:25:21.896Z|debug|srv-xh5|928 unix-RPC||dummytaskhelper] 
task dispatch:session.get_uuid D:8c60fd0b9b5f created by task D:d42fb7605e99
[20110717T03:25:21.909Z|debug|srv-xh5|506 inet-RPC||xapi] Raised at 
db_cache_types.ml:75.27-76 -> db_cache_types.ml:118.2-40 -> 
pervasiveext.ml:22.2-9
[20110717T03:25:21.922Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-0cb119d4-35f0-1cf5-16b0-aae0867cab6d 
D:8c37aa00f8d1|dispatcher] Unknown rpc 
"unknown-message-0cb119d4-35f0-1cf5-16b0-aae0867cab6d"
[20110717T03:25:21.925Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:session.get_uuid D:75a3345c8b11 created by task D:bbc19f84d324
[20110717T03:25:21.978Z|debug|srv-xh5|929 unix-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:b68b9332216b created by task 
R:524e127c00dc
[20110717T03:25:21.983Z|debug|srv-xh5|930 unix-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:5564ca8c5e13 created by task 
R:524e127c00dc
[20110717T03:25:21.988Z|debug|srv-xh5|931 unix-RPC||dummytaskhelper] 
task dispatch:PBD.get_all_records D:144dc57ac00c created by task 
R:524e127c00dc
[20110717T03:25:21.996Z|debug|srv-xh5|932 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:706f2466d7ed created by task R:524e127c00dc
[20110717T03:25:22.001Z|debug|srv-xh5|933 unix-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:1b25419f79f4 created by task 
R:524e127c00dc
[20110717T03:25:22.008Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-7380fac6-3be3-0383-a351-ca2a9e18bf06 
D:3b360231c009|dispatcher] Unknown rpc 
"unknown-message-7380fac6-3be3-0383-a351-ca2a9e18bf06"
[20110717T03:25:22.011Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:67aa8722cce1 created by task 
R:524e127c00dc
[20110717T03:25:22.018Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-cd5a58d6-fd21-c7de-4030-6c7638be5b83 
D:b16de4eb8789|dispatcher] Unknown rpc 
"unknown-message-cd5a58d6-fd21-c7de-4030-6c7638be5b83"
[20110717T03:25:22.021Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:5b97b5e565c3 created by task 
R:524e127c00dc
[20110717T03:25:22.028Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-a30634f2-8bff-21d9-36da-c5b46415d361 
D:af0d9427b045|dispatcher] Unknown rpc 
"unknown-message-a30634f2-8bff-21d9-36da-c5b46415d361"
[20110717T03:25:22.031Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:PBD.get_all_records D:201c11015bef created by task 
R:524e127c00dc
[20110717T03:25:22.044Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-744cfaaf-903f-0817-d1e4-17262d7c6ba5 
D:dd90d844bfb8|dispatcher] Unknown rpc 
"unknown-message-744cfaaf-903f-0817-d1e4-17262d7c6ba5"
[20110717T03:25:22.047Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:4d4a0a0c29ca created by task R:524e127c00dc
[20110717T03:25:22.050Z|debug|srv-xh5|934 unix-RPC||dummytaskhelper] 
task dispatch:PBD.get_all_records D:624c666c6f30 created by task 
R:524e127c00dc
[20110717T03:25:22.055Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-f9ac5050-d729-4bc0-7ec2-5eb3a9a16dcd 
D:10f75014e727|dispatcher] Unknown rpc 
"unknown-message-f9ac5050-d729-4bc0-7ec2-5eb3a9a16dcd"
[20110717T03:25:22.058Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:1e139dff25df created by task 
R:524e127c00dc
[20110717T03:25:22.059Z|debug|srv-xh5|935 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_other_config D:acc65ba88f3b created by task 
R:524e127c00dc
[20110717T03:25:22.064Z|debug|srv-xh5|936 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:1f7a34b66475 created by task R:524e127c00dc
[20110717T03:25:22.103Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-ddf14d28-8825-d57e-decf-f878807c7086 
D:a5006b262f0c|dispatcher] Unknown rpc 
"unknown-message-ddf14d28-8825-d57e-decf-f878807c7086"
[20110717T03:25:22.106Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:PBD.get_all_records D:8757edab0ee9 created by task 
R:524e127c00dc
[20110717T03:25:22.119Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-ed21bedc-7fe6-fd92-dcd1-d8bf6389ac1e 
D:8f81d874312a|dispatcher] Unknown rpc 
"unknown-message-ed21bedc-7fe6-fd92-dcd1-d8bf6389ac1e"
[20110717T03:25:22.122Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:SR.get_other_config D:ed9284c21981 created by task 
R:524e127c00dc
[20110717T03:25:22.128Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-48a21f3b-e4ac-725b-448d-7718c98ba70b 
D:b48119e5e24a|dispatcher] Unknown rpc 
"unknown-message-48a21f3b-e4ac-725b-448d-7718c98ba70b"
[20110717T03:25:22.131Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:7d421515431f created by task R:524e127c00dc
[20110717T03:25:22.147Z|debug|srv-xh5|937 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_other_config D:43d6228f2840 created by task 
R:524e127c00dc
[20110717T03:25:22.151Z|debug|srv-xh5|938 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:c76ff4bac18d created by task R:524e127c00dc
[20110717T03:25:22.231Z|debug|srv-xh5|939 unix-RPC||dummytaskhelper] 
task dispatch:VDI.get_sm_config D:f57b2562de78 created by task 
R:524e127c00dc
[20110717T03:25:22.243Z| info|srv-xh5|861 inet-RPC|sm_exec 
D:d42fb7605e99|xapi] Session.destroy 
trackid=2d11838049b96a0d313ba1a9ac738e13
[20110717T03:25:22.244Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|storage_access] Executed detach succesfully on VDI 
'2c6f0960-2742-48ab-9935-4ddb2d5fcb28'; attach refcount now: 0
[20110717T03:25:22.244Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|monitor_rrds] Sending RRD for VM 
uuid=a0e508db-fb6d-4ad9-4d68-9e6d20a0d2c5 to remote host for migrate
[20110717T03:25:22.244Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|monitor_rrds] Sending RRD for object 
uuid=a0e508db-fb6d-4ad9-4d68-9e6d20a0d2c5 archiving=false to address: 
10.1.3.6
[20110717T03:25:22.247Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|monitor_rrds] Sending rrd to 10.1.3.6
[20110717T03:25:22.251Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-cfee954c-c29c-d757-15d0-c417c69ad27f 
D:d640eaea2606|dispatcher] Unknown rpc 
"unknown-message-cfee954c-c29c-d757-15d0-c417c69ad27f"
[20110717T03:25:22.256Z| info|srv-xh5|769 inet-RPC|session.slave_login 
D:2dd78dfe096d|xapi] Session.create 
trackid=daa4d955ccd60ddf8c85db270114ebc1 pool=true uname= 
is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
[20110717T03:25:22.258Z|debug|srv-xh5|940 unix-RPC||dummytaskhelper] 
task dispatch:session.get_uuid D:5f84c9640436 created by task D:2dd78dfe096d
[20110717T03:25:22.282Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|monitor_rrds] Sent
[20110717T03:25:22.286Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-d7eeef81-adea-76b2-5bcd-c7809df26a53 
D:9ce50fca6acb|dispatcher] Unknown rpc 
"unknown-message-d7eeef81-adea-76b2-5bcd-c7809df26a53"
[20110717T03:25:22.286Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Sender 7. waiting for all-clear from remote
[20110717T03:25:22.303Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-41e746f3-f874-4bed-891e-3e85c23802cd 
D:c6808dbcafc7|dispatcher] Unknown rpc 
"unknown-message-41e746f3-f874-4bed-891e-3e85c23802cd"
[20110717T03:25:22.303Z|debug|srv-xh5|941 inet-RPC||dummytaskhelper] 
task dispatch:SR.get_other_config D:f58fd6b46485 created by task 
R:524e127c00dc
[20110717T03:25:22.307Z| info|srv-xh5|769 inet-RPC|session.logout 
D:1e7eb98da29a|xapi] Session.destroy 
trackid=daa4d955ccd60ddf8c85db270114ebc1
[20110717T03:25:22.310Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-efff5417-af73-cfd5-d9a3-125179744ff7 
D:f57cd3b3f8c8|dispatcher] Unknown rpc 
"unknown-message-efff5417-af73-cfd5-d9a3-125179744ff7"
[20110717T03:25:22.313Z|debug|srv-xh5|941 inet-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:37efa8c4e1df created by task R:524e127c00dc
[20110717T03:25:22.361Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-ab65508c-a174-9467-4f33-42ba51540ba0 
D:5d8e466229d4|dispatcher] Unknown rpc 
"unknown-message-ab65508c-a174-9467-4f33-42ba51540ba0"
[20110717T03:25:22.364Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:VDI.get_sm_config D:62c3b9bcbe83 created by task 
R:524e127c00dc
[20110717T03:25:22.372Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-72015697-be9e-3b4c-8eb2-b419d6a8947b 
D:ca521ca62002|dispatcher] Unknown rpc 
"unknown-message-72015697-be9e-3b4c-8eb2-b419d6a8947b"
[20110717T03:25:22.375Z|debug|srv-xh5|941 inet-RPC||dummytaskhelper] 
task dispatch:VDI.get_by_uuid D:08e7832abcc7 created by task R:524e127c00dc
[20110717T03:25:22.382Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-cfbae17d-bab7-9935-0b36-c97337a8622f 
D:e79db0a98e7e|dispatcher] Unknown rpc 
"unknown-message-cfbae17d-bab7-9935-0b36-c97337a8622f"
[20110717T03:25:22.385Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:host.get_by_uuid D:a750b6ed78dd created by task R:524e127c00dc
[20110717T03:25:22.392Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-b2a4aaf8-3449-83ef-6b5f-517d777abc4f 
D:6c67599f57fc|dispatcher] Unknown rpc 
"unknown-message-b2a4aaf8-3449-83ef-6b5f-517d777abc4f"
[20110717T03:25:22.395Z|debug|srv-xh5|941 inet-RPC||dummytaskhelper] 
task dispatch:VDI.get_sm_config D:9f34b4a304dd created by task 
R:524e127c00dc
[20110717T03:25:22.402Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-163bc2b9-1311-dd60-c7d1-259d254e267d 
D:ea6b50defeb6|dispatcher] Unknown rpc 
"unknown-message-163bc2b9-1311-dd60-c7d1-259d254e267d"
[20110717T03:25:22.405Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:VDI.add_to_sm_config D:666c34cd9dc0 created by task 
R:524e127c00dc
[20110717T03:25:22.405Z| info|srv-xh5|769 
inet-RPC|dispatch:VDI.add_to_sm_config D:666c34cd9dc0|api_effect] 
VDI.add_to_sm_config
[20110717T03:25:22.411Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-e2791ba2-4a82-1b2b-2c44-68b8b2a4e31d 
D:0917a1a3249e|dispatcher] Unknown rpc 
"unknown-message-e2791ba2-4a82-1b2b-2c44-68b8b2a4e31d"
[20110717T03:25:22.414Z|debug|srv-xh5|941 inet-RPC||dummytaskhelper] 
task dispatch:VDI.get_sm_config D:e503a8fd11e7 created by task 
R:524e127c00dc
[20110717T03:25:22.421Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-cabb0496-9c71-d2a4-f4b7-1e901efc0318 
D:1952f9dc400a|dispatcher] Unknown rpc 
"unknown-message-cabb0496-9c71-d2a4-f4b7-1e901efc0318"
[20110717T03:25:22.424Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:VDI.get_by_uuid D:b45d956a9969 created by task R:524e127c00dc
[20110717T03:25:22.431Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-b2164bef-c3b7-9376-da4e-9b03d67fc29f 
D:4262505e022c|dispatcher] Unknown rpc 
"unknown-message-b2164bef-c3b7-9376-da4e-9b03d67fc29f"
[20110717T03:25:22.434Z|debug|srv-xh5|941 inet-RPC||dummytaskhelper] 
task dispatch:VDI.get_SR D:c762a3654966 created by task R:524e127c00dc
[20110717T03:25:22.441Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-05524297-c362-5c92-9bc0-fd7ff7c0d2f8 
D:5b7c4ef29ee1|dispatcher] Unknown rpc 
"unknown-message-05524297-c362-5c92-9bc0-fd7ff7c0d2f8"
[20110717T03:25:22.444Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:SR.get_uuid D:9af3cc84037f created by task R:524e127c00dc
[20110717T03:25:22.450Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-9bd0df06-96c5-b337-c171-81c5f35f7208 
D:1b1be302da52|dispatcher] Unknown rpc 
"unknown-message-9bd0df06-96c5-b337-c171-81c5f35f7208"
[20110717T03:25:22.454Z|debug|srv-xh5|941 inet-RPC||dummytaskhelper] 
task dispatch:SR.get_by_uuid D:98ee43cfd1f3 created by task R:524e127c00dc
[20110717T03:25:22.461Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-c271b4de-3409-84ed-4441-a69c4d06bada 
D:65836aad2fda|dispatcher] Unknown rpc 
"unknown-message-c271b4de-3409-84ed-4441-a69c4d06bada"
[20110717T03:25:22.464Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:SR.get_type D:fd9ca00af80a created by task R:524e127c00dc
[20110717T03:25:22.470Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-31aa1014-9595-fb4d-0d5c-97e63fb488e7 
D:b80255077d67|dispatcher] Unknown rpc 
"unknown-message-31aa1014-9595-fb4d-0d5c-97e63fb488e7"
[20110717T03:25:22.473Z|debug|srv-xh5|941 inet-RPC||dummytaskhelper] 
task dispatch:SM.get_all_records_where D:86eb822f25f7 created by task 
R:524e127c00dc
[20110717T03:25:22.483Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-7c3182c5-325e-fa8f-8afd-5181a8697278 
D:f47892577d4a|dispatcher] Unknown rpc 
"unknown-message-7c3182c5-325e-fa8f-8afd-5181a8697278"
[20110717T03:25:22.486Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:SM.get_driver_filename D:955957f17b89 created by task 
R:524e127c00dc
[20110717T03:25:22.493Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-ec61df76-912b-5aae-c9da-25c7c947fb3c 
D:31f15425ea50|dispatcher] Unknown rpc 
"unknown-message-ec61df76-912b-5aae-c9da-25c7c947fb3c"
[20110717T03:25:22.496Z|debug|srv-xh5|941 inet-RPC||dummytaskhelper] 
task dispatch:VM.get_all_records_where D:83a00dbee0fd created by task 
R:524e127c00dc
[20110717T03:25:22.510Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-24e59ec8-94ce-dada-e5db-9069bbdd0980 
D:e35591a8faf9|dispatcher] Unknown rpc 
"unknown-message-24e59ec8-94ce-dada-e5db-9069bbdd0980"
[20110717T03:25:22.513Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:PBD.get_all_records_where D:a27cc948a937 created by task 
R:524e127c00dc
[20110717T03:25:22.520Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-9b8e6ed2-1d5e-b28a-fdf4-6a37835d7963 
D:b7b17293b509|dispatcher] Unknown rpc 
"unknown-message-9b8e6ed2-1d5e-b28a-fdf4-6a37835d7963"
[20110717T03:25:22.523Z|debug|srv-xh5|941 inet-RPC||dummytaskhelper] 
task dispatch:PBD.get_device_config D:7fc588726092 created by task 
R:524e127c00dc
[20110717T03:25:22.530Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-9c2718d0-2a78-d2f0-11b0-387715ed6e22 
D:efa785340286|dispatcher] Unknown rpc 
"unknown-message-9c2718d0-2a78-d2f0-11b0-387715ed6e22"
[20110717T03:25:22.540Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-b4b2ccfa-3b63-04a7-ca83-786871db76b9 
D:b5c58a02e594|dispatcher] Unknown rpc 
"unknown-message-b4b2ccfa-3b63-04a7-ca83-786871db76b9"
[20110717T03:25:22.551Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-61af23b7-d6e0-688b-9b4e-5cf226ca9261 
D:00e98908b99a|dispatcher] Unknown rpc 
"unknown-message-61af23b7-d6e0-688b-9b4e-5cf226ca9261"
[20110717T03:25:22.565Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-c4f68dab-56db-1371-48cc-3bb35d971fdb 
D:cf528a20b69f|dispatcher] Unknown rpc 
"unknown-message-c4f68dab-56db-1371-48cc-3bb35d971fdb"
[20110717T03:25:22.576Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-d481656e-8cdc-b92a-c31e-33a22472c414 
D:562e10cfcd2f|dispatcher] Unknown rpc 
"unknown-message-d481656e-8cdc-b92a-c31e-33a22472c414"
[20110717T03:25:22.620Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-481dbfb5-a905-f846-ebb8-f731c506b885 
D:8835fe2b52fe|dispatcher] Unknown rpc 
"unknown-message-481dbfb5-a905-f846-ebb8-f731c506b885"
[20110717T03:25:22.636Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-1d870de2-68d2-1da8-ed63-cf5bb467576d 
D:a3202584d31a|dispatcher] Unknown rpc 
"unknown-message-1d870de2-68d2-1da8-ed63-cf5bb467576d"
[20110717T03:25:22.645Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-a45485d8-6bae-ed18-4dce-fd18b6898808 
D:234cad4e2f96|dispatcher] Unknown rpc 
"unknown-message-a45485d8-6bae-ed18-4dce-fd18b6898808"
[20110717T03:25:22.695Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-6c8cef2e-e2e1-4c21-73ce-60fede66328f 
D:89bb5da8f980|dispatcher] Unknown rpc 
"unknown-message-6c8cef2e-e2e1-4c21-73ce-60fede66328f"
[20110717T03:25:22.705Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-7bd78c4f-5e90-1a06-8b25-e3cd517f22e7 
D:5be67a7a8653|dispatcher] Unknown rpc 
"unknown-message-7bd78c4f-5e90-1a06-8b25-e3cd517f22e7"
[20110717T03:25:22.754Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-e10e4fe4-e9e0-4d48-1009-0d46cfcc47c4 
D:2165286a6678|dispatcher] Unknown rpc 
"unknown-message-e10e4fe4-e9e0-4d48-1009-0d46cfcc47c4"
[20110717T03:25:22.848Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-6fe7a47f-58bf-fc35-43cb-e0ac2c601b13 
D:ea44b70baa57|dispatcher] Unknown rpc 
"unknown-message-6fe7a47f-58bf-fc35-43cb-e0ac2c601b13"
[20110717T03:25:22.852Z| info|srv-xh5|941 
inet-RPC|dispatch:VDI.remove_from_xenstore_data 
D:fb2cd6d7e05a|api_effect] VDI.remove_from_xenstore_data
[20110717T03:25:22.859Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-cd0d5837-211d-0b4d-c82a-cec4b00fcd9d 
D:8b6e130fc92c|dispatcher] Unknown rpc 
"unknown-message-cd0d5837-211d-0b4d-c82a-cec4b00fcd9d"
[20110717T03:25:22.862Z| info|srv-xh5|769 
inet-RPC|dispatch:VDI.remove_from_xenstore_data 
D:1f574cdac0fa|api_effect] VDI.remove_from_xenstore_data
[20110717T03:25:22.868Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-c854d6b7-9e2f-a053-885f-92d47200af0e 
D:3a1eb9a57b73|dispatcher] Unknown rpc 
"unknown-message-c854d6b7-9e2f-a053-885f-92d47200af0e"
[20110717T03:25:22.872Z| info|srv-xh5|941 
inet-RPC|dispatch:VDI.remove_from_xenstore_data 
D:50b18054e7c2|api_effect] VDI.remove_from_xenstore_data
[20110717T03:25:22.878Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-5828f761-f246-b296-d7ac-6fd545c9523a 
D:e746b3c1afff|dispatcher] Unknown rpc 
"unknown-message-5828f761-f246-b296-d7ac-6fd545c9523a"
[20110717T03:25:22.882Z| info|srv-xh5|769 
inet-RPC|dispatch:VDI.remove_from_xenstore_data 
D:32ce62f2351b|api_effect] VDI.remove_from_xenstore_data
[20110717T03:25:22.887Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-96e9321f-cd26-4602-783a-6108ddf5f60e 
D:5c50553f6986|dispatcher] Unknown rpc 
"unknown-message-96e9321f-cd26-4602-783a-6108ddf5f60e"
[20110717T03:25:22.890Z| info|srv-xh5|941 
inet-RPC|dispatch:VDI.add_to_xenstore_data D:af32f2a61c7d|api_effect] 
VDI.add_to_xenstore_data
[20110717T03:25:22.896Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-1fbf77fc-4f7c-0fe8-8bab-6514313f8d99 
D:8869860dc5c2|dispatcher] Unknown rpc 
"unknown-message-1fbf77fc-4f7c-0fe8-8bab-6514313f8d99"
[20110717T03:25:22.900Z| info|srv-xh5|769 
inet-RPC|dispatch:VDI.add_to_xenstore_data D:ce0845d4e2a4|api_effect] 
VDI.add_to_xenstore_data
[20110717T03:25:22.906Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-a8848c70-f812-3fa7-8fa9-cf8e71d172d6 
D:313535d0b437|dispatcher] Unknown rpc 
"unknown-message-a8848c70-f812-3fa7-8fa9-cf8e71d172d6"
[20110717T03:25:22.909Z| info|srv-xh5|941 
inet-RPC|dispatch:VDI.add_to_xenstore_data D:12ab872bca8b|api_effect] 
VDI.add_to_xenstore_data
[20110717T03:25:22.916Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-c58fca96-03f3-a982-903a-17f4efaae085 
D:f82c4dcd4074|dispatcher] Unknown rpc 
"unknown-message-c58fca96-03f3-a982-903a-17f4efaae085"
[20110717T03:25:22.919Z| info|srv-xh5|769 
inet-RPC|dispatch:VDI.remove_from_xenstore_data 
D:80846e1bb1ba|api_effect] VDI.remove_from_xenstore_data
[20110717T03:25:22.925Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-04fe9fef-c43c-af37-2402-0fc5ef2c77ca 
D:f00eb080a6b6|dispatcher] Unknown rpc 
"unknown-message-04fe9fef-c43c-af37-2402-0fc5ef2c77ca"
[20110717T03:25:22.929Z| info|srv-xh5|941 
inet-RPC|dispatch:VDI.remove_from_xenstore_data 
D:3ce94a530657|api_effect] VDI.remove_from_xenstore_data
[20110717T03:25:22.935Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-6b9aa06d-663b-6e57-cff7-d90bbcfc7ec1 
D:903dc56876e8|dispatcher] Unknown rpc 
"unknown-message-6b9aa06d-663b-6e57-cff7-d90bbcfc7ec1"
[20110717T03:25:22.938Z| info|srv-xh5|769 
inet-RPC|dispatch:VDI.add_to_xenstore_data D:4a8cc5d3f569|api_effect] 
VDI.add_to_xenstore_data
[20110717T03:25:22.945Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-53a68458-5014-b6e3-f7d1-3f7bd7d21c30 
D:feaf7a5008b9|dispatcher] Unknown rpc 
"unknown-message-53a68458-5014-b6e3-f7d1-3f7bd7d21c30"
[20110717T03:25:22.948Z| info|srv-xh5|941 
inet-RPC|dispatch:VDI.add_to_xenstore_data D:b23fef1a8024|api_effect] 
VDI.add_to_xenstore_data
[20110717T03:25:23.351Z|debug|srv-xh5|506 inet-RPC||xapi] Raised at 
db_cache_types.ml:75.27-76 -> db_cache_types.ml:118.2-40 -> 
pervasiveext.ml:22.2-9
[20110717T03:25:23.811Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-ff7e2de6-99fc-750c-583a-25da8c269a71 
D:03b6fca3f655|dispatcher] Unknown rpc 
"unknown-message-ff7e2de6-99fc-750c-583a-25da8c269a71"
[20110717T03:25:23.814Z|debug|srv-xh5|769 inet-RPC||dummytaskhelper] 
task dispatch:VM.atomic_set_resident_on D:0c2315ff6cf1 created by task 
R:524e127c00dc
[20110717T03:25:23.817Z| info|srv-xh5|769 
inet-RPC|dispatch:VM.atomic_set_resident_on D:0c2315ff6cf1|taskhelper] 
task VM.atomic_set_resident_on R:ff0239377c59 
(uuid:a69c3e66-efad-d7b3-f955-d5f45c62e6d7) created 
(trackid=fe7e3d8d48fcd164b2a29b75c4a2147b) by task R:524e127c00dc
[20110717T03:25:23.817Z|debug|srv-xh5|769 
inet-RPC|VM.atomic_set_resident_on R:ff0239377c59|audit] 
VM.atomic_set_resident_on: VM = 'a0e508db-fb6d-4ad9-4d68-9e6d20a0d2c5 
(1499_5393)'
[20110717T03:25:23.839Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Sender cleaning up by destroying remains of local 
domain
[20110717T03:25:23.840Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Domain.destroy: all known devices = [ frontend 
(domid=1 | kind=vbd | devid=51760); backend (domid=0 | kind=vbd | 
devid=51760); frontend (domid=1 | kind=vbd | devid=51712); backend 
(domid=0 | kind=vbd | devid=51712); frontend (domid=1 | kind=vif | 
devid=0); backend (domid=0 | kind=vif | devid=0) ]
[20110717T03:25:23.840Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Domain.destroy calling Xc.domain_destroy (domid 1)
[20110717T03:25:24.001Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] No qemu-dm pid in xenstore; assuming this domain 
was PV
[20110717T03:25:24.001Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Device.Vbd.hard_shutdown frontend (domid=1 | 
kind=vbd | devid=51760); backend (domid=0 | kind=vbd | devid=51760)
[20110717T03:25:24.001Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Device.Vbd.request_shutdown frontend (domid=1 | 
kind=vbd | devid=51760); backend (domid=0 | kind=vbd | devid=51760) force
[20110717T03:25:24.001Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-write 
/local/domain/0/backend/vbd/1/51760/shutdown-request = force
[20110717T03:25:24.002Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] watch: watching xenstore paths: [ 
/local/domain/0/backend/vbd/1/51760/shutdown-done ] with timeout 
1200.000000 seconds
[20110717T03:25:24.004Z|debug|srv-xh5|326 xal_listen||event] VM (domid: 
1) device_event = device shutdown {vbd,51760}
[20110717T03:25:24.005Z|debug|srv-xh5|326 xal_listen|VM (domid: 1) 
device_event = device shutdown {vbd,51760} D:c5aaca9f5d15|event] Adding 
Resync.vbd to queue
[20110717T03:25:24.005Z|debug|srv-xh5|326 xal_listen|VM (domid: 1) 
device_event = device shutdown {vbd,51760} 
D:c5aaca9f5d15|locking_helpers] push(per-VM queue, DevShutdownDone(vbd, 
51760) domid: 1); queue = [ DevShutdownDone(vbd, 51712) domid: 1; 
DevShutdownDone(vbd, 51760) domid: 1 ](2)
[20110717T03:25:24.005Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Device.rm_device_state frontend (domid=1 | 
kind=vbd | devid=51760); backend (domid=0 | kind=vbd | devid=51760)
[20110717T03:25:24.005Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-rm /local/domain/1/device/vbd/51760
[20110717T03:25:24.006Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-rm /local/domain/0/backend/vbd/1/51760
[20110717T03:25:24.006Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-rm /local/domain/0/error/backend/vbd/1
[20110717T03:25:24.006Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-rm /local/domain/1/error/device/vbd/51760
[20110717T03:25:24.007Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Device.Vbd.hard_shutdown complete
[20110717T03:25:24.007Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Device.Vbd.hard_shutdown frontend (domid=1 | 
kind=vbd | devid=51712); backend (domid=0 | kind=vbd | devid=51712)
[20110717T03:25:24.007Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Device.Vbd.request_shutdown frontend (domid=1 | 
kind=vbd | devid=51712); backend (domid=0 | kind=vbd | devid=51712) force
[20110717T03:25:24.007Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-write 
/local/domain/0/backend/vbd/1/51712/shutdown-request = force
[20110717T03:25:24.007Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] watch: watching xenstore paths: [ 
/local/domain/0/backend/vbd/1/51712/shutdown-done ] with timeout 
1200.000000 seconds
[20110717T03:25:24.008Z|debug|srv-xh5|326 xal_listen||event] VM (domid: 
1) device_event = device shutdown {vbd,51712}
[20110717T03:25:24.009Z|debug|srv-xh5|326 xal_listen|VM (domid: 1) 
device_event = device shutdown {vbd,51712} D:1620aa41d366|event] Adding 
Resync.vbd to queue
[20110717T03:25:24.009Z|debug|srv-xh5|326 xal_listen|VM (domid: 1) 
device_event = device shutdown {vbd,51712} 
D:1620aa41d366|locking_helpers] push(per-VM queue, DevShutdownDone(vbd, 
51712) domid: 1); queue = [ DevShutdownDone(vbd, 51712) domid: 1; 
DevShutdownDone(vbd, 51760) domid: 1; DevShutdownDone(vbd, 51712) domid: 
1 ](3)
[20110717T03:25:24.009Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Device.rm_device_state frontend (domid=1 | 
kind=vbd | devid=51712); backend (domid=0 | kind=vbd | devid=51712)
[20110717T03:25:24.010Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-rm /local/domain/1/device/vbd/51712
[20110717T03:25:24.010Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-rm /local/domain/0/backend/vbd/1/51712
[20110717T03:25:24.011Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-rm /local/domain/0/error/backend/vbd/1
[20110717T03:25:24.011Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-rm /local/domain/1/error/device/vbd/51712
[20110717T03:25:24.011Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Device.Vbd.hard_shutdown complete
[20110717T03:25:24.011Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Device.Vif.hard_shutdown frontend (domid=1 | 
kind=vif | devid=0); backend (domid=0 | kind=vif | devid=0)
[20110717T03:25:24.011Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-write 
/local/domain/0/backend/vif/1/0/online = 0
[20110717T03:25:24.011Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Device.Vif.hard_shutdown about to blow away frontend
[20110717T03:25:24.012Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-rm /local/domain/1/device/vif/0
[20110717T03:25:24.012Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] watch: watching xenstore paths: [ 
/xapi/1/hotplug/vif/0/hotplug ] with timeout 1200.000000 seconds
[20110717T03:25:24.686Z|debug|srv-xh5|326 xal_listen||event] VM (domid: 
1) device_event = HotplugChanged on 0 {online->""}
[20110717T03:25:24.687Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Device.Vif.hard_shutdown about to blow away 
backend and error paths
[20110717T03:25:24.687Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Device.rm_device_state frontend (domid=1 | 
kind=vif | devid=0); backend (domid=0 | kind=vif | devid=0)
[20110717T03:25:24.687Z|error|srv-xh5|326 xal_listen|VM (domid: 1) 
device_event = HotplugChanged on 0 {online->""} D:ec045c4a68c9|event] 
device_event could not be processed because VM record not in database
[20110717T03:25:24.687Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-rm /local/domain/1/device/vif/0
[20110717T03:25:24.687Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-rm /local/domain/0/backend/vif/1/0
[20110717T03:25:24.688Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-rm /local/domain/0/error/backend/vif/1
[20110717T03:25:24.688Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] xenstore-rm /local/domain/1/error/device/vif/0
20110717T03:25:24.688Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|hotplug] Hotplug.release: frontend (domid=1 | kind=vbd | 
devid=51760); backend (domid=0 | kind=vbd | devid=51760)
[20110717T03:25:24.688Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|hotplug] Hotplug.wait_for_unplug: frontend (domid=1 | 
kind=vbd | devid=51760); backend (domid=0 | kind=vbd | devid=51760)
[20110717T03:25:24.688Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] watch: watching xenstore paths: [ 
/xapi/1/hotplug/vbd/51760/hotplug ] with timeout 1200.000000 seconds
[20110717T03:25:24.689Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|hotplug] Synchronised ok with hotplug script: frontend 
(domid=1 | kind=vbd | devid=51760); backend (domid=0 | kind=vbd | 
devid=51760)
[20110717T03:25:24.689Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|hotplug] Hotplug.release releasing /dev/loop7
[20110717T03:25:24.696Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|hotplug] Hotplug.release: frontend (domid=1 | kind=vbd | 
devid=51712); backend (domid=0 | kind=vbd | devid=51712)
[20110717T03:25:24.696Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|hotplug] Hotplug.wait_for_unplug: frontend (domid=1 | 
kind=vbd | devid=51712); backend (domid=0 | kind=vbd | devid=51712)
[20110717T03:25:24.696Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] watch: watching xenstore paths: [ 
/xapi/1/hotplug/vbd/51712/hotplug ] with timeout 1200.000000 seconds
[20110717T03:25:24.697Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|hotplug] Synchronised ok with hotplug script: frontend 
(domid=1 | kind=vbd | devid=51712); backend (domid=0 | kind=vbd | 
devid=51712)
[20110717T03:25:24.697Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|hotplug] Hotplug.release: frontend (domid=1 | kind=vif | 
devid=0); backend (domid=0 | kind=vif | devid=0)
[20110717T03:25:24.697Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|hotplug] Hotplug.wait_for_unplug: frontend (domid=1 | 
kind=vif | devid=0); backend (domid=0 | kind=vif | devid=0)
[20110717T03:25:24.697Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] watch: watching xenstore paths: [ 
/xapi/1/hotplug/vif/0/hotplug ] with timeout 1200.000000 seconds
[20110717T03:25:24.697Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|hotplug] Synchronised ok with hotplug script: frontend 
(domid=1 | kind=vif | devid=0); backend (domid=0 | kind=vif | devid=0)
[20110717T03:25:24.697Z| warn|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|hotplug] Warning, deleting 'vif' entry from 
/xapi/1/hotplug/vif/0
[20110717T03:25:24.698Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Domain.destroy: rm /local/domain/1
[20110717T03:25:24.698Z|debug|srv-xh5|326 xal_listen||event] VM (domid: 
1) device_event = ChangeUncooperative false
[20110717T03:25:24.699Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Domain.destroy: deleting backend paths
[20110717T03:25:24.702Z|error|srv-xh5|326 xal_listen|VM (domid: 1) 
device_event = ChangeUncooperative false D:bd8f207fa01d|event] 
device_event could not be processed because VM record not in database
[20110717T03:25:24.702Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Xc.domain_getinfo 1 threw: getinfo failed: domain 
1: getinfo failed: domain 1: getinfo failed: domain 1: hypercall 36 
fail: 11: Resource temporarily unavailable (ret -1) -- assuming domain 
nolonger exists
[20110717T03:25:24.702Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xenops] Xc.domain_getinfo 1 threw: getinfo failed: domain 
1: getinfo failed: domain 1: getinfo failed: domain 1: getinfo failed: 
domain 1: hypercall 36 fail: 11: Resource temporarily unavailable (ret 
-1) -- assuming domain nolonger exists
[20110717T03:25:24.702Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|storage_access] vdi refcount violation (on detach): 
hashtbl reports '0' for VDI '2c6f0960-2742-48ab-9935-4ddb2d5fcb28'
[20110717T03:25:24.702Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|sm] SM lvmoiscsi vdi_detach 
sr=OpaqueRef:a1077822-9453-de43-0efa-ecb0fe508f59 
vdi=OpaqueRef:c34b2134-fe3e-0780-a5bf-12e4cd3edd4e
[20110717T03:25:24.703Z|debug|srv-xh5|861 inet-RPC|sm_exec 
D:dae4922e7f32|xapi] Raised at db_cache_types.ml:75.27-76 -> 
db_cache_types.ml:118.2-40 -> pervasiveext.ml:22.2-9
[20110717T03:25:24.706Z| info|srv-xh5|861 inet-RPC|sm_exec 
D:68e0f95eaa4c|xapi] Session.create 
trackid=d877d75ed8b11fa0707952ac666775e3 pool=false uname= 
is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
[20110717T03:25:24.708Z|debug|srv-xh5|944 unix-RPC||dummytaskhelper] 
task dispatch:session.get_uuid D:800b77fd9b6b created by task D:68e0f95eaa4c
[20110717T03:25:24.786Z|debug|srv-xh5|945 unix-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:d5d2dd28b15e created by task 
R:524e127c00dc
[20110717T03:25:24.791Z|debug|srv-xh5|946 unix-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:69c9b6712ebe created by task 
R:524e127c00dc
[20110717T03:25:24.796Z|debug|srv-xh5|947 unix-RPC||dummytaskhelper] 
task dispatch:PBD.get_all_records D:c64123009034 created by task 
R:524e127c00dc
[20110717T03:25:24.804Z|debug|srv-xh5|948 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:774ef164c97c created by task R:524e127c00dc
[20110717T03:25:24.809Z|debug|srv-xh5|949 unix-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:96b14ab38fff created by task 
R:524e127c00dc
[20110717T03:25:24.850Z|debug|srv-xh5|950 unix-RPC||dummytaskhelper] 
task dispatch:PBD.get_all_records D:6bba887bd3c5 created by task 
R:524e127c00dc
[20110717T03:25:24.859Z|debug|srv-xh5|951 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_other_config D:1cefb90e3af2 created by task 
R:524e127c00dc
[20110717T03:25:24.863Z|debug|srv-xh5|952 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:330984d04c06 created by task R:524e127c00dc
[20110717T03:25:25.019Z|debug|srv-xh5|953 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_other_config D:9782795ccb43 created by task 
R:524e127c00dc
[20110717T03:25:25.024Z|debug|srv-xh5|954 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:8f7cd02d4617 created by task R:524e127c00dc
[20110717T03:25:25.104Z|debug|srv-xh5|955 unix-RPC||dummytaskhelper] 
task dispatch:VDI.get_sm_config D:18960ea23f60 created by task 
R:524e127c00dc
[20110717T03:25:25.116Z| info|srv-xh5|861 inet-RPC|sm_exec 
D:68e0f95eaa4c|xapi] Session.destroy 
trackid=d877d75ed8b11fa0707952ac666775e3
[20110717T03:25:25.116Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|storage_access] Executed detach succesfully on VDI 
'2c6f0960-2742-48ab-9935-4ddb2d5fcb28'; attach refcount now: 0
[20110717T03:25:25.117Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|sm] SM iso vdi_detach 
sr=OpaqueRef:47c6426c-0ef1-dfa5-8730-1fde4210814a 
vdi=OpaqueRef:20abc7c0-7fb7-4f7d-1bd7-8f08e6331cf8
[20110717T03:25:25.118Z|debug|srv-xh5|861 inet-RPC|sm_exec 
D:df56ae240a2d|xapi] Raised at db_cache_types.ml:75.27-76 -> 
db_cache_types.ml:118.2-40 -> pervasiveext.ml:22.2-9
[20110717T03:25:25.120Z| info|srv-xh5|861 inet-RPC|sm_exec 
D:17f564e2566b|xapi] Session.create 
trackid=479aa14f2dfb536c21505cb28371af06 pool=false uname= 
is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
[20110717T03:25:25.122Z|debug|srv-xh5|956 unix-RPC||dummytaskhelper] 
task dispatch:session.get_uuid D:f69023151d55 created by task D:17f564e2566b
[20110717T03:25:25.198Z|debug|srv-xh5|957 unix-RPC||dummytaskhelper] 
task dispatch:host.get_other_config D:a42dc9aa7e0a created by task 
R:524e127c00dc
[20110717T03:25:25.203Z|debug|srv-xh5|958 unix-RPC||dummytaskhelper] 
task dispatch:PBD.get_all_records D:b34b75f199d2 created by task 
R:524e127c00dc
[20110717T03:25:25.212Z|debug|srv-xh5|959 unix-RPC||dummytaskhelper] 
task dispatch:SR.get_sm_config D:26988c9740f9 created by task R:524e127c00dc
[20110717T03:25:25.222Z| info|srv-xh5|861 inet-RPC|sm_exec 
D:17f564e2566b|xapi] Session.destroy 
trackid=479aa14f2dfb536c21505cb28371af06
[20110717T03:25:25.222Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|storage_access] Executed detach succesfully on VDI 
'017fb470-d643-4f44-abeb-8b8749aeb114'; attach refcount now: 0
[20110717T03:25:25.222Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Sender 8.Logging out of remote server
[20110717T03:25:25.224Z|debug|srv-xh5|960 unix-RPC||dummytaskhelper] 
task dispatch:session.logout D:78f8ff3daa03 created by task R:524e127c00dc
[20110717T03:25:25.226Z| info|srv-xh5|960 unix-RPC|session.logout 
D:8509467bc136|xapi] Session.destroy 
trackid=fe7e3d8d48fcd164b2a29b75c4a2147b
[20110717T03:25:25.226Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Sender 9. Closing memory image transfer socket
[20110717T03:25:25.226Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|locking_helpers] pop(per-VM queue) = DevShutdownDone(vbd, 
51712) domid: 1
[20110717T03:25:25.227Z|debug|srv-xh5|861 inet-RPC|VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf: processing 
DevShutdownDone(vbd, 51712) domid: 1 D:ffac7ef4b754|event] VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf (1499_5393) resident_on 
other host OpaqueRef:4f82279c-1222-368c-4e8f-8667e88485d9 (srv-xh5): 
taking no action
[20110717T03:25:25.227Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|locking_helpers] pop(per-VM queue) = DevShutdownDone(vbd, 
51760) domid: 1
[20110717T03:25:25.228Z|debug|srv-xh5|861 inet-RPC|VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf: processing 
DevShutdownDone(vbd, 51760) domid: 1 D:0a90204d1a02|event] VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf (1499_5393) resident_on 
other host OpaqueRef:4f82279c-1222-368c-4e8f-8667e88485d9 (srv-xh5): 
taking no action
[20110717T03:25:25.228Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|locking_helpers] pop(per-VM queue) = DevShutdownDone(vbd, 
51712) domid: 1
[20110717T03:25:25.229Z|debug|srv-xh5|861 inet-RPC|VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf: processing 
DevShutdownDone(vbd, 51712) domid: 1 D:4c11e5169e18|event] VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf (1499_5393) resident_on 
other host OpaqueRef:4f82279c-1222-368c-4e8f-8667e88485d9 (srv-xh5): 
taking no action
[20110717T03:25:25.229Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|locking_helpers] Released lock on VM 
OpaqueRef:dd860476-057f-2b22-6120-7668828720cf with token 6
[20110717T03:25:25.231Z|debug|srv-xh5|872||thread_queue] 
long_running_op: completed processing 1 items: queue = [  ](0)
[20110717T03:25:25.234Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Checking for vdis_reset_and_caching...
[20110717T03:25:25.234Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Op allowed!
[20110717T03:25:25.235Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Checking for vdis_reset_and_caching...
[20110717T03:25:25.235Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Op allowed!
[20110717T03:25:25.237Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Checking for vdis_reset_and_caching...
[20110717T03:25:25.237Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|xapi] Op allowed!
[20110717T03:25:25.243Z|debug|srv-xh5|861 inet-RPC|VM.pool_migrate 
R:524e127c00dc|taskhelper] the status of R:524e127c00dc is: success; 
cannot set it to `success
[20110717T03:25:25.252Z|debug|srv-xh5|861 
inet-RPC|dispatch:unknown-message-f5de3dd8-d90b-b00e-bb70-9fca4f551a89 
D:f1ebe51d335b|dispatcher] Unknown rpc 
"unknown-message-f5de3dd8-d90b-b00e-bb70-9fca4f551a89"
[20110717T03:25:25.255Z|debug|srv-xh5|941 
inet-RPC|dispatch:unknown-message-86550759-61bd-e61b-6c44-dd4f61433fda 
D:ad521ab1c607|dispatcher] Unknown rpc 
"unknown-message-86550759-61bd-e61b-6c44-dd4f61433fda"
[20110717T03:25:25.260Z| info|srv-xh5|941 inet-RPC|session.logout 
D:e23d456856c8|xapi] Session.destroy 
trackid=c82b070d193b45e7baf3630b3cd6d2ff
[20110717T03:26:10.878Z|debug|srv-xh5|769 
inet-RPC|dispatch:unknown-message-d19d13ac-931d-f95b-590f-b3e0d546e603 
D:db9820d7a192|dispatcher] Unknown rpc 
"unknown-message-d19d13ac-931d-f95b-590f-b3e0d546e603"


_______________________________________________
xen-api mailing list
xen-api@xxxxxxxxxxxxxxxxxxx
http://lists.xensource.com/mailman/listinfo/xen-api