xoce INTERNAL_ERROR while trying to create VM

[burbilog]

@olivierlambert I ran xe sr-list and xe-vm-list on all hosts, compiled a list of uuids, sorted them and all of them are unique. How to search for duplicate keys then?

[burbilog]

@olivierlambert installed xo-cli, connected and ran xo-cli --list-objects , then grepped all uuids, stirpped everything else and tried to find dupes -- none. all uuids are unique there.

[burbilog]

@burbilog ah, no, there are some repeated, i had to sort it first. but there is a lot of uuids that are repeated.

[olivierlambert]

Let me also ask some XAPI specialists around

[burbilog]

@olivierlambert Ugh.

I erased xoce (rm -rf /opt/xen-orchestra && apt purge redis-server), then reinstalled both xoce and single server afresh. Then I connected brand new, shiny xoce to brand new, shiny server. Only. I did not connect other servers.

And I've got the same problem. Added NFS SR, tried to install VM, pink square, error:

vm.create
{
  "clone": true,
  "existingDisks": {},
  "installation": {
    "method": "cdrom",
    "repository": "6b15b403-a94a-4f59-b4bc-4da75bffe4a7"
  },
  "name_label": "x",
  "template": "b8896401-be53-cbc1-58f3-ac0bd696ec55-4b6425be-728a-4a2c-8333-0aef209a348b",
  "VDIs": [
    {
      "bootable": true,
      "device": "0",
      "size": 10737418240,
      "type": "system",
      "SR": "aeaa681d-bf4a-5070-f553-ffe6debb0b54",
      "name_description": "Created by XO",
      "name_label": "CentOS 8_erofa"
    }
  ],
  "VIFs": [
    {
      "network": "b4fd13cc-7b32-0794-d617-2ecd39139dc1",
      "allowedIpv4Addresses": [],
      "allowedIpv6Addresses": []
    }
  ],
  "CPUs": 1,
  "cpusMax": 1,
  "cpuWeight": null,
  "cpuCap": null,
  "name_description": "x",
  "memory": 4294967296,
  "bootAfterCreate": true,
  "copyHostBiosStrings": false,
  "secureBoot": false,
  "share": false,
  "coreOs": false,
  "tags": [],
  "hvmBootFirmware": "bios"
}
{
  "code": "INTERNAL_ERROR",
  "params": [
    "(Failure \"Expected string, got 'N'\")"
  ],
  "call": {
    "method": "VM.get_power_state",
    "params": [
      null
    ]
  },
  "message": "INTERNAL_ERROR((Failure \"Expected string, got 'N'\"))",
  "name": "XapiError",
  "stack": "XapiError: INTERNAL_ERROR((Failure \"Expected string, got 'N'\"))
    at Function.wrap (/opt/xen-orchestra/packages/xen-api/src/_XapiError.js:16:12)
    at /opt/xen-orchestra/packages/xen-api/src/transports/json-rpc.js:37:27
    at AsyncResource.runInAsyncScope (node:async_hooks:202:9)
    at cb (/opt/xen-orchestra/node_modules/bluebird/js/release/util.js:355:42)
    at tryCatcher (/opt/xen-orchestra/node_modules/bluebird/js/release/util.js:16:23)
    at Promise._settlePromiseFromHandler (/opt/xen-orchestra/node_modules/bluebird/js/release/promise.js:547:31)
    at Promise._settlePromise (/opt/xen-orchestra/node_modules/bluebird/js/release/promise.js:604:18)
    at Promise._settlePromise0 (/opt/xen-orchestra/node_modules/bluebird/js/release/promise.js:649:10)
    at Promise._settlePromises (/opt/xen-orchestra/node_modules/bluebird/js/release/promise.js:729:18)
    at _drainQueueStep (/opt/xen-orchestra/node_modules/bluebird/js/release/async.js:93:12)
    at _drainQueue (/opt/xen-orchestra/node_modules/bluebird/js/release/async.js:86:9)
    at Async._drainQueues (/opt/xen-orchestra/node_modules/bluebird/js/release/async.js:102:5)
    at Immediate.Async.drainQueues [as _onImmediate] (/opt/xen-orchestra/node_modules/bluebird/js/release/async.js:15:14)
    at processImmediate (node:internal/timers:466:21)
    at process.callbackTrampoline (node:internal/async_hooks:130:17)"
}

May 13 16:49:42 xen xapi: [error||1712 HTTPS 10.1.0.188->:::80|VM.add_to_platform D:4a241a51b855|sql] Duplicate key in set or map: table VM; field platform; ref OpaqueRef:0766c0ce-6a4d-4c81-b8ab-9956ed2702f1; key secureboot
May 13 16:49:42 xen xapi: [error||1714 HTTPS 10.1.0.188->:::80|VM.add_to_HVM_boot_params D:0d9aca8b9b24|sql] Duplicate key in set or map: table VM; field HVM__boot_params; ref OpaqueRef:0766c0ce-6a4d-4c81-b8ab-9956ed2702f1; key firmware
May 13 16:49:42 xen xapi: [error||1712 :::80||backtrace] VM.add_to_platform D:4a241a51b855 failed with exception Db_exn.Duplicate_key("VM", "platform", "OpaqueRef:0766c0ce-6a4d-4c81-b8ab-9956ed2702f1", "secureboot")
May 13 16:49:42 xen xapi: [error||1712 :::80||backtrace] Raised Db_exn.Duplicate_key("VM", "platform", "OpaqueRef:0766c0ce-6a4d-4c81-b8ab-9956ed2702f1", "secureboot")
May 13 16:49:42 xen xapi: [error||1712 :::80||backtrace] 1/8 xapi Raised at file ocaml/database/db_cache_impl.ml, line 310
May 13 16:49:42 xen xapi: [error||1712 :::80||backtrace] 2/8 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 24
May 13 16:49:42 xen xapi: [error||1712 :::80||backtrace] 3/8 xapi Called from file ocaml/xapi/rbac.ml, line 231
May 13 16:49:42 xen xapi: [debug||1711 :::80||api_effect] VM.set_name_description
May 13 16:49:42 xen xapi: [debug||1715 :::80||api_effect] VM.add_to_platform
May 13 16:49:42 xen xapi: [error||1714 :::80||backtrace] VM.add_to_HVM_boot_params D:0d9aca8b9b24 failed with exception Db_exn.Duplicate_key("VM", "HVM__boot_params", "OpaqueRef:0766c0ce-6a4d-4c81-b8ab-9956ed2702f1", "firmware")
May 13 16:49:42 xen xapi: [error||1712 :::80||backtrace] 4/8 xapi Called from file ocaml/xapi/server_helpers.ml, line 100
May 13 16:49:42 xen xapi: [error||1715 HTTPS 10.1.0.188->:::80|VM.add_to_platform D:e5850b8e2aca|sql] Duplicate key in set or map: table VM; field platform; ref OpaqueRef:0766c0ce-6a4d-4c81-b8ab-9956ed2702f1; key device-model
May 13 16:49:42 xen xapi: [error||1714 :::80||backtrace] Raised Db_exn.Duplicate_key("VM", "HVM__boot_params", "OpaqueRef:0766c0ce-6a4d-4c81-b8ab-9956ed2702f1", "firmware")
May 13 16:49:42 xen xapi: [error||1712 :::80||backtrace] 5/8 xapi Called from file ocaml/xapi/server_helpers.ml, line 121
May 13 16:49:42 xen xapi: [error||1714 :::80||backtrace] 1/8 xapi Raised at file ocaml/database/db_cache_impl.ml, line 310
May 13 16:49:42 xen xapi: [error||1715 :::80||backtrace] VM.add_to_platform D:e5850b8e2aca failed with exception Db_exn.Duplicate_key("VM", "platform", "OpaqueRef:0766c0ce-6a4d-4c81-b8ab-9956ed2702f1", "device-model")
May 13 16:49:42 xen xapi: [error||1712 :::80||backtrace] 6/8 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 24
May 13 16:49:42 xen xapi: [error||1714 :::80||backtrace] 2/8 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 24
May 13 16:49:42 xen xapi: [error||1715 :::80||backtrace] Raised Db_exn.Duplicate_key("VM", "platform", "OpaqueRef:0766c0ce-6a4d-4c81-b8ab-9956ed2702f1", "device-model")
May 13 16:49:42 xen xapi: [error||1714 :::80||backtrace] 3/8 xapi Called from file ocaml/xapi/rbac.ml, line 231
May 13 16:49:42 xen xapi: [error||1715 :::80||backtrace] 1/8 xapi Raised at file ocaml/database/db_cache_impl.ml, line 310
May 13 16:49:42 xen xapi: [error||1712 :::80||backtrace] 7/8 xapi Called from file map.ml, line 135
May 13 16:49:42 xen xapi: [error||1715 :::80||backtrace] 2/8 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 24
May 13 16:49:42 xen xapi: [error||1714 :::80||backtrace] 4/8 xapi Called from file ocaml/xapi/server_helpers.ml, line 100
May 13 16:49:42 xen xapi: [error||1712 :::80||backtrace] 8/8 xapi Called from file src/sexp_conv.ml, line 156
May 13 16:49:42 xen xapi: [error||1714 :::80||backtrace] 5/8 xapi Called from file ocaml/xapi/server_helpers.ml, line 121
May 13 16:49:42 xen xapi: [error||1715 :::80||backtrace] 3/8 xapi Called from file ocaml/xapi/rbac.ml, line 231
May 13 16:49:42 xen xapi: [error||1712 :::80||backtrace]
May 13 16:49:42 xen xapi: [error||1714 :::80||backtrace] 6/8 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 24
May 13 16:49:42 xen xapi: [error||1715 :::80||backtrace] 4/8 xapi Called from file ocaml/xapi/server_helpers.ml, line 100
May 13 16:49:42 xen xapi: [error||1714 :::80||backtrace] 7/8 xapi Called from file map.ml, line 135
May 13 16:49:42 xen xapi: [error||1715 :::80||backtrace] 5/8 xapi Called from file ocaml/xapi/server_helpers.ml, line 121
May 13 16:49:42 xen xapi: [error||1714 :::80||backtrace] 8/8 xapi Called from file src/sexp_conv.ml, line 156
May 13 16:49:42 xen xapi: [error||1715 :::80||backtrace] 6/8 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 24
May 13 16:49:42 xen xapi: [error||1714 :::80||backtrace]
May 13 16:49:42 xen xapi: [error||1715 :::80||backtrace] 7/8 xapi Called from file map.ml, line 135
May 13 16:49:42 xen xapi: [error||1715 :::80||backtrace] 8/8 xapi Called from file src/sexp_conv.ml, line 156
May 13 16:49:42 xen xapi: [error||1715 :::80||backtrace]

Perhaps, it's a problem with some latest changes to xoce after all?

[olivierlambert]

Could you try with XOA? This is more and more intriguing, never heard or had this before.

[burbilog]

@olivierlambert Installed xoa appliance, connected it to that server and it seems to work, xoa creates new VM just fine. So, it's certainly a problem of xoce.

[olivierlambert]

But that's an error coming from XAPI

Anyone else having issues on latest master commit?

[Harrison]

@olivierlambert It appears that this is in fact an issue with XOCE. I was able to reproduce the same error. I am having no issue with the XOA appliance or XCP-ng Center.

vm.create
{
  "clone": true,
  "existingDisks": {},
  "installation": {
    "method": "cdrom",
    "repository": "54f2aa37-7552-4e36-bb4f-2ae0cf5999c1"
  },
  "name_label": "Windows 10 (64-bit)",
  "template": "68055f83-4afe-2701-51d5-d6ca8fc90a6d-7774689b-4ca1-4dea-8545-dddd6b64c17f",
  "VDIs": [
    {
      "bootable": false,
      "device": "0",
      "size": 34359738368,
      "type": "system",
      "SR": "ef976096-efb6-5a74-bc37-e6d279b08e7d",
      "name_description": "Created by XO",
      "name_label": "Windows 10 (64-bit)_etade"
    }
  ],
  "VIFs": [
    {
      "network": "6061fbef-74bb-945c-ba88-d6868b419817",
      "allowedIpv4Addresses": [],
      "allowedIpv6Addresses": []
    }
  ],
  "CPUs": 2,
  "cpusMax": 2,
  "cpuWeight": null,
  "cpuCap": null,
  "name_description": "",
  "memory": 4294967296,
  "bootAfterCreate": false,
  "copyHostBiosStrings": false,
  "secureBoot": false,
  "share": false,
  "coreOs": false,
  "tags": [],
  "hvmBootFirmware": "uefi"
}
{
  "code": "INTERNAL_ERROR",
  "params": [
    "(Failure \"Expected string, got 'N'\")"
  ],
  "call": {
    "method": "VM.get_power_state",
    "params": [
      null
    ]
  },
  "message": "INTERNAL_ERROR((Failure \"Expected string, got 'N'\"))",
  "name": "XapiError",
  "stack": "XapiError: INTERNAL_ERROR((Failure \"Expected string, got 'N'\"))
    at Function.wrap (/opt/xo/xo-builds/xen-orchestra-202205131525/packages/xen-api/src/_XapiError.js:16:12)
    at /opt/xo/xo-builds/xen-orchestra-202205131525/packages/xen-api/src/transports/json-rpc.js:37:27
    at AsyncResource.runInAsyncScope (node:async_hooks:202:9)
    at cb (/opt/xo/xo-builds/xen-orchestra-202205131525/node_modules/bluebird/js/release/util.js:355:42)
    at tryCatcher (/opt/xo/xo-builds/xen-orchestra-202205131525/node_modules/bluebird/js/release/util.js:16:23)
    at Promise._settlePromiseFromHandler (/opt/xo/xo-builds/xen-orchestra-202205131525/node_modules/bluebird/js/release/promise.js:547:31)
    at Promise._settlePromise (/opt/xo/xo-builds/xen-orchestra-202205131525/node_modules/bluebird/js/release/promise.js:604:18)
    at Promise._settlePromise0 (/opt/xo/xo-builds/xen-orchestra-202205131525/node_modules/bluebird/js/release/promise.js:649:10)
    at Promise._settlePromises (/opt/xo/xo-builds/xen-orchestra-202205131525/node_modules/bluebird/js/release/promise.js:729:18)
    at _drainQueueStep (/opt/xo/xo-builds/xen-orchestra-202205131525/node_modules/bluebird/js/release/async.js:93:12)
    at _drainQueue (/opt/xo/xo-builds/xen-orchestra-202205131525/node_modules/bluebird/js/release/async.js:86:9)
    at Async._drainQueues (/opt/xo/xo-builds/xen-orchestra-202205131525/node_modules/bluebird/js/release/async.js:102:5)
    at Immediate.Async.drainQueues [as _onImmediate] (/opt/xo/xo-builds/xen-orchestra-202205131525/node_modules/bluebird/js/release/async.js:15:14)
    at processImmediate (node:internal/timers:466:21)
    at process.callbackTrampoline (node:internal/async_hooks:130:17)"
}

[olivierlambert]

Thanks a lot for the extra confirmation @Harrison

Would you mind trying to bisect since commit 2518395c03b166d28d3432f8feb33578d7b0f717? (which should be good).

See https://www.metaltoad.com/blog/beginners-guide-git-bisect-process-elimination for more details, on manually try to find the culprit if you prefer

[gskger]

@olivierlambert I get the same error on a XO from third party script (same script as OP, commit a1bcd, xo-server 5.93.1, xo-web 5.96.0). Can share the error log and more infos to reproduce the error if that helps.

[olivierlambert]

What will be helpful is trying to find what we broke on master, since we know commit 2518395c03b166d28d3432f8feb33578d7b0f717 should be good

[julien-f]

Thank you all, this is now fixed.

https://github.com/vatesfr/xen-orchestra/commit/07bd9cadd4732554c57e441cd9d860b63f73fe02

0 julien-f committed to vatesfr/xen-orchestra

fix(xo-server/vm.create): typo during VIF creation

Introduced by ecae554a7

Fixes https://xcp-ng.org/forum/post/49143

[olivierlambert]

VIM