Forum
Welcome, Guest
Username: Password: Remember me

TOPIC:

Can't start VM on second server 10 years 8 months ago #54

  • christ neeskens
  • christ neeskens's Avatar Topic Author
  • Offline
  • Posts: 18
If I try to start my VM on the second server I get The VDI is not available in xencenter.

But if I click the same VM and than start it on the first server it boots up without a problem.

If I start it on server 1 and than migrate it from server 1 to server 2 I get an error on both servers. Internal error: Xenops_interface.Does_not_exist(_)


A part of the message log from server 2 during startup of the VM:
Aug 20 11:13:37 xenserver2 xapi: [ info|xenserver2|129074 UNIX /var/xapi/xapi|session.login_with_password D:c87df1fb8b28|xapi] Session.create trackid=104f3c6369e2ba39d190b33e981178e7 pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:13:37 xenserver2 xapi: [ info|xenserver2|129056 storage_unix|sm_exec D:5bf00f7ba2a8|xapi] Session.destroy trackid=eed06ca3887a0d6cb7418c0f2b4b55ed
Aug 20 11:13:37 xenserver2 xapi: [ info|xenserver2|129075 storage_unix||storage_impl] VDI.activate dbg:attach_and_activate dp:vbd/10/hda sr:2e56fc62-c9d7-28f8-c1aa-da6734138f16 vdi:913716fb-2273-4629-ae63-ab36fa4f760f
Aug 20 11:13:37 xenserver2 xapi: [ info|xenserver2|129075 storage_unix|sm_exec D:a686615e5b50|xapi] Session.create trackid=56fd21fc224d8da28c79d1f29c78a256 pool=false uname= is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:13:37 xenserver2 xapi: [ info|xenserver2|129076 UNIX /var/xapi/xapi|session.login_with_password D:234f04aa3354|xapi] Session.create trackid=cbbaabe5a04ade0d236159b1ca6652e7 pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:13:37 xenserver2 xapi: [ info|xenserver2|129077 UNIX /var/xapi/xapi|session.login_with_password D:dfa15acee8e7|xapi] Session.create trackid=d9586648d4919e7ecb708ac452f7f429 pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:13:37 xenserver2 xapi: [ info|xenserver2|129081 UNIX /var/xapi/xapi|session.login_with_password D:178bd5c5294c|xapi] Session.create trackid=258da6c069ee056e979d5a46843565b0 pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:13:38 xenserver2 ha-lizard: 6125 get_pool_ip_list: returned 192.168.207.200
Aug 20 11:13:38 xenserver2 xapi: [ info|xenserver2|129121 UNIX /var/xapi/xapi|session.login_with_password D:3919239b3417|xapi] Session.create trackid=b8f3b0178be01c3bd9fc77c0e551f8c1 pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:13:39 xenserver2 ha-lizard: 6125 get_pool_ip_list: returned 192.168.207.200 192.168.207.201
Aug 20 11:13:39 xenserver2 kernel: [90707.779155] device-mapper: table: 252:0: linear: dm-linear: Device lookup failed
Aug 20 11:13:39 xenserver2 kernel: [90707.779170] device-mapper: ioctl: error adding target to table
Aug 20 11:13:39 xenserver2 xapi: [ info|xenserver2|129075 storage_unix|sm_exec D:a686615e5b50|xapi] Session.destroy trackid=56fd21fc224d8da28c79d1f29c78a256
Aug 20 11:13:39 xenserver2 xapi: [error|xenserver2|129075 storage_unix||storage_impl] Storage_impl: dp:vbd/10/hda sr:2e56fc62-c9d7-28f8-c1aa-da6734138f16 vdi:913716fb-2273-4629-ae63-ab36fa4f760f op:activate error:Storage_interface.Backend_error(_) backtrace:Called from file "storage_impl.ml", line 299, characters 7-50
Aug 20 11:13:39 xenserver2 xenopsd: [ info|xenserver2|7|Async.VM.start_on R:9437b3d06e05|xenops] Caught Xenops_interface.Storage_backend_error(_) executing ["VM_start", "1b87662b-7d8f-b27e-75d4-35c1f1aef8f6"]: triggering cleanup actions
Aug 20 11:13:39 xenserver2 xenstored:  A36524       getdomain 10
Aug 20 11:13:39 xenserver2 xapi: [ info|xenserver2|129130 storage_unix||storage_impl] DP.destroy dbg:dp_destroy dp:vbd/10/hdc allow_leak:false
Aug 20 11:13:39 xenserver2 xapi: [ info|xenserver2|129131 storage_unix||storage_impl] DP.destroy dbg:dp_destroy dp:vbd/10/hda allow_leak:false

A part of the message log from server 2 during migration of VM from server 1 to server 2:
Aug 20 11:23:39 xenserver2 ha-lizard: 26705 get_vms_on_host: Returned 22116857-5ec8-e4fc-260c-ea1f6c276446 1b87662b-7d8f-b27e-75d4-35c1f1aef8f6
Aug 20 11:23:39 xenserver2 xapi: [ info|xenserver2|130030 UNIX /var/xapi/xapi|session.login_with_password D:55b789f24fad|xapi] Session.create trackid=a469cbbf1b096decf7279507f67af3c7 pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:23:39 xenserver2 ha-lizard: 26705 get_vms_on_host: No VMs found on host: 1ccd7861-8f3f-4fc2-936e-135221863c05
Aug 20 11:23:39 xenserver2 xapi: [ info|xenserver2|130032 UNIX /var/xapi/xapi|session.login_with_password D:3f2567dbd97c|xapi] Session.create trackid=9a2aee6a52331f580a9f8fe0381a0c24 pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:23:39 xenserver2 xapi: [ info|xenserver2|130033 UNIX /var/xapi/xapi|session.login_with_password D:7db418e7ef93|xapi] Session.create trackid=66ec6bc85cd6ddd030ee69e9dcac67ae pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:23:39 xenserver2 kernel: [91308.409209] device-mapper: table: 252:0: linear: dm-linear: Device lookup failed
Aug 20 11:23:39 xenserver2 kernel: [91308.409225] device-mapper: ioctl: error adding target to table
Aug 20 11:23:39 xenserver2 xapi: [ info|xenserver2|130036 UNIX /var/xapi/xapi|session.login_with_password D:beba1a3c90a4|xapi] Session.create trackid=34af9f801e695ddfd2e9585682b5f3b0 pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:23:40 xenserver2 xapi: [ info|xenserver2|130039 UNIX /var/xapi/xapi|session.login_with_password D:20f9dbc5f998|xapi] Session.create trackid=4e98a751d4b1fae15c2704a8a0c46ac2 pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:23:40 xenserver2 xapi: [ info|xenserver2|129990 storage_unix|sm_exec D:4cc65909d3bf|xapi] Session.destroy trackid=9376e160de690135304bacb0e7b966a7
Aug 20 11:23:40 xenserver2 xapi: [error|xenserver2|129990 storage_unix||storage_impl] Storage_impl: dp:vbd/11/hda sr:2e56fc62-c9d7-28f8-c1aa-da6734138f16 vdi:913716fb-2273-4629-ae63-ab36fa4f760f op:activate error:Storage_interface.Backend_error(_) backtrace:Called from file "storage_impl.ml", line 299, characters 7-50
Aug 20 11:23:40 xenserver2 xapi: [ info|xenserver2|130040 storage_unix||storage_impl] DP.destroy dbg:dp_destroy dp:vbd/11/hdc allow_leak:false
Aug 20 11:23:40 xenserver2 xapi: [ info|xenserver2|130041 storage_unix||storage_impl] DP.destroy dbg:dp_destroy dp:vbd/11/hda allow_leak:false
Aug 20 11:23:40 xenserver2 xapi: [ info|xenserver2|130041 storage_unix|sm_exec D:254aaafa60ce|xapi] Session.create trackid=cd32e0b52d037817d95033ec56f8ab1a pool=false uname= is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:23:40 xenserver2 ha-lizard: 26705 check_ha_enabled: Checking if ha-lizard is enabled for pool: f9718891-f906-e450-e0ed-62bcdf810018
Aug 20 11:23:40 xenserver2 ha-lizard: 26705 check_ha_enabled: ha-lizard is enabled
Aug 20 11:23:40 xenserver2 xapi: [ info|xenserver2|130042 UNIX /var/xapi/xapi|session.login_with_password D:728540cc26c3|xapi] Session.create trackid=80731e655f045b9895d334c7924e1b7d pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:23:40 xenserver2 xapi: [ info|xenserver2|130043 UNIX /var/xapi/xapi|session.login_with_password D:87499312feea|xapi] Session.create trackid=2909212e40b111120c79d8caa30e632d pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:23:40 xenserver2 ha-lizard: 26705 get_pool_host_list: enabled flag set - returning only hosts with enabled=true
Aug 20 11:23:40 xenserver2 xapi: [ info|xenserver2|130046 UNIX /var/xapi/xapi|session.login_with_password D:ea69233f8d36|xapi] Session.create trackid=2be31b8d2371f4ece49a5e8abb40371c pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:23:40 xenserver2 ha-lizard: 26705 get_pool_host_list: returned 3d678d20-7ed5-46db-a820-6fb683e6a277 1ccd7861-8f3f-4fc2-936e-135221863c05
Aug 20 11:23:40 xenserver2 xapi: [ info|xenserver2|130048 UNIX /var/xapi/xapi|session.login_with_password D:c8a0153c34c7|xapi] Session.create trackid=ada5c4748ff86bfd32fb2c7d0a9dd576 pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:23:40 xenserver2 ha-lizard: 26705 get_pool_ip_list: returned 192.168.207.200
Aug 20 11:23:40 xenserver2 xapi: [ info|xenserver2|130052 UNIX /var/xapi/xapi|session.login_with_password D:c6801d901fd4|xapi] Session.create trackid=6e4891f56821a6d66781cc3f81c4ecbb pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 20 11:23:40 xenserver2 ha-lizard: 26705 get_pool_ip_list: returned 192.168.207.200 192.168.207.201
Aug 20 11:23:40 xenserver2 xapi: [ info|xenserver2|130041 storage_unix|sm_exec D:254aaafa60ce|xapi] Session.destroy trackid=cd32e0b52d037817d95033ec56f8ab1a
Aug 20 11:23:40 xenserver2 xenstored:  A36810       getdomain 11
Aug 20 11:23:40 xenserver2 last message repeated 2 times
Aug 20 11:23:40 xenserver2 xenstored:  A36810       getdomain 0

Removed a large part

Aug 20 11:23:40 xenserver2 xenstored:  A36812       rm        /vss/1b87662b-7d8f-b27e-75d4-35c1f1aef8f6
Aug 20 11:23:40 xenserver2 xenstored:  A17          w event   /vss/1b87662b-7d8f-b27e-75d4-35c1f1aef8f6 vss
Aug 20 11:23:40 xenserver2 xenstored:  A10          unwatch   /local/domain/11/vm-data /local/domain/11/vm-data
Aug 20 11:23:40 xenserver2 xenstored:  A10          unwatch   /vm/1b87662b-7d8f-b27e-75d4-35c1f1aef8f6/rtc/timeoffset /vm/1b87662b-7d8f-b27e-75d4-35c1f1aef8f6/rtc/timeoffset
Aug 20 11:23:40 xenserver2 xenopsd: [ info|xenserver2|8|events|xenops] Caught Xenops_interface.Does_not_exist(_) executing ["VM_check_state", "1b87662b-7d8f-b27e-75d4-35c1f1aef8f6"]: triggering cleanup actions
Aug 20 11:23:41 xenserver2 ha-lizard: 8554 ha-lizard Watchdog: ha-lizard running - OK
Aug 20 11:23:42 xenserver2 xapi: [ info|xenserver2|129820 INET 0.0.0.0:80|dispatch:network.detach_for_vm D:a98f2019dd80|taskhelper] task network.detach_for_vm R:84d8c2bca49a forwarded (trackid=92a1fa89d0d2252dcfb4d98772380ec2)
Aug 20 11:23:43 xenserver2 iscsi-ha: 26394 Spawning new instance of iscsi-ha
Aug 20 11:23:43 xenserver2 iscsi-ha: 27188 Checking if this host is a Pool Master or Slave
Aug 20 11:23:43 xenserver2 iscsi-ha: 27188 This host's pool status = slave:192.168.207.200

No idea why this is now happening.
Before the last discussed crash this was working.
Ok, starting a VM on a random server didn't work (was on the try to solve list). But I could always migrate it to where I wanted it to be and it would run. And start from the last server it was migrated to.

If any more log files, config files or trace or what ever are needed just let me know!

Please Log in or Create an account to join the conversation.

Can't start VM on second server 10 years 8 months ago #55

Can you check to ensure there is no CD/DVD mounted in the cd drive of the VM.

Please Log in or Create an account to join the conversation.

Can't start VM on second server 10 years 8 months ago #56

  • christ neeskens
  • christ neeskens's Avatar Topic Author
  • Offline
  • Posts: 18
It was already unmounted.

What I did now was remove the server from the pool.
Reinstall xenserver
Add it to the pool
NOT install drbd and ha-lizard/iscs-ha
How it can start the VM.

I'm now busy setting up ha-lizard and iscs-ha on that machine to see if it is running now, or still has the same problem.

Please Log in or Create an account to join the conversation.

Can't start VM on second server 10 years 8 months ago #57

We have seen this before with xenserver. Usually detaching and reattaching the iscsi SR fixes it.. it may not be the optimal solution though for a live system.

Please Log in or Create an account to join the conversation.

Can't start VM on second server 10 years 8 months ago #58

  • christ neeskens
  • christ neeskens's Avatar Topic Author
  • Offline
  • Posts: 18
It is now working like it should.

If it occurs again i'll try to reacttach the SR to see if that solves it.
That's probably a lot faster than reinstalling the server.


Now I only have an issue with slow write performance.
Read is going fast enough (from xenserver performance VM between 750 and 900MB/s). But write is incredibly slow (from xenserver performance VM average around 7MB/s).

perfvm:/home# dd if=/dev/zero of=/home/bigfile bs=1024k count=1000 conv=fdatasync
1000+0 records in
1000+0 records out
1048576000 bytes (1.0 GB) copied, 64.5507 s, 16.2 MB/s
perfvm:/home# rm /home/bigfile
perfvm:/home# dd if=/dev/zero of=/home/bigfile bs=1024k count=1000
1000+0 records in
1000+0 records out
1048576000 bytes (1.0 GB) copied, 82.967 s, 12.6 MB/s


But the host it self is:
[root@xenserver2 home]# dd if=/dev/zero of=/home/bigfile bs=1024k count=1000 conv=fdatasync
1000+0 records in
1000+0 records out
1048576000 bytes (1.0 GB) copied, 21.7084 seconds, 48.3 MB/s
[root@xenserver2 home]# rm /home/bigfile
[root@xenserver2 home]# dd if=/dev/zero of=/home/bigfile bs=1024k count=1000
1000+0 records in
1000+0 records out
1048576000 bytes (1.0 GB) copied, 17.6399 seconds, 59.4 MB/s

Please Log in or Create an account to join the conversation.

Can't start VM on second server 10 years 8 months ago #59

We are achieving much better performance in our test environment (which is 100% based on the how-to we published). Below are the results we attain with 10K SAS drives in HW RAID 1+0

Also, write cache can considerably slow performance. If you have battery backed cache in your controllers you can try disabling write cache - but this can be dangerous..

results below:
#### From a VM on the Slave - Adequate performance achieved ####
[root@localhost home]# dd if=/dev/zero of=/home/bigfile bs=1024k count=1000 conv=fdatasync
1000+0 records in
1000+0 records out
1048576000 bytes (1.0 GB) copied, 20.8139 s, 50.4 MB/s
[root@localhost home]# rm /home/bigfile
rm: remove regular file `/home/bigfile'? y

[root@localhost home]# dd if=/dev/zero of=/home/bigfile bs=1024k count=1000
1000+0 records in
1000+0 records out
1048576000 bytes (1.0 GB) copied, 16.7628 s, 62.6 MB/s

#### From a VM on the Master - Improved performance expected ####
[root@localhost ~]# cd /home/
[root@localhost home]# dd if=/dev/zero of=/home/bigfile bs=1024k count=1000 conv=fdatasync
1000+0 records in
1000+0 records out
1048576000 bytes (1.0 GB) copied, 11.6842 s, 89.7 MB/s

[root@localhost home]# dd if=/dev/zero of=/home/bigfile bs=1024k count=1000
1000+0 records in
1000+0 records out
1048576000 bytes (1.0 GB) copied, 7.62403 s, 138 MB/s



#### From Domu to direct attatched storage - no SAN - improved performance expected ####
[root@XS1 home]# dd if=/dev/zero of=/home/bigfile bs=1024k count=1000 conv=fdatasync
1000+0 records in
1000+0 records out
1048576000 bytes (1.0 GB) copied, 9.1033 seconds, 115 MB/s
[root@XS1 home]# rm /home/bigfile
rm: remove regular file `/home/bigfile'? y
[root@XS1 home]# dd if=/dev/zero of=/home/bigfile bs=1024k count=1000
1000+0 records in
1000+0 records out
1048576000 bytes (1.0 GB) copied, 8.83339 seconds, 119 MB/s

Please Log in or Create an account to join the conversation.