xoce INTERNAL_ERROR while trying to create VM

olivierlambert

@burbilog said in xoce INTERNAL_ERROR while trying to create VM:

INTERNAL_ERROR((Failure "Expected string, got 'N'")

You have to investigate on your XCP-ng host, there's obviously a problem in there.

See https://xcp-ng.org/docs/troubleshooting.html

I would suggest to restart the toolstack too.

burbilog

@olivierlambert This problem is common for all 3 servers, i did not touch other two hosts at all for a while. I see some strange error appear in xensource.log after VM creation attempt:

May 13 11:59:07 xen xapi: [error||13931 :::80||backtrace] VM.add_to_platform D:87deedffed4a failed with exception Db_exn.Duplicate_key("VM", "platform", "OpaqueRef:cae2f8cd-6d33-4ca8-81a1-0eb76df149bd", "device-model")
May 13 11:59:07 xen xapi: [error||13930 :::80||backtrace] 3/8 xapi Called from file ocaml/xapi/rbac.ml, line 231
May 13 11:59:07 xen xapi: [error||13931 :::80||backtrace] Raised Db_exn.Duplicate_key("VM", "platform", "OpaqueRef:cae2f8cd-6d33-4ca8-81a1-0eb76df149bd", "device-model")
May 13 11:59:07 xen xapi: [error||13930 :::80||backtrace] 4/8 xapi Called from file ocaml/xapi/server_helpers.ml, line 100
May 13 11:59:07 xen xapi: [error||13931 :::80||backtrace] 1/8 xapi Raised at file ocaml/database/db_cache_impl.ml, line 310
May 13 11:59:07 xen xapi: [error||13930 :::80||backtrace] 5/8 xapi Called from file ocaml/xapi/server_helpers.ml, line 121
May 13 11:59:07 xen xapi: [error||13929 :::80||backtrace] VM.add_to_platform D:6b3c2fce951b failed with exception Db_exn.Duplicate_key("VM", "platform", "OpaqueRef:cae2f8cd-6d33-4ca8-81a1-0eb76df149bd", "secureboot")
May 13 11:59:07 xen xapi: [error||13931 :::80||backtrace] 2/8 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 24
May 13 11:59:07 xen xapi: [error||13930 :::80||backtrace] 6/8 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 24
May 13 11:59:07 xen xapi: [error||13929 :::80||backtrace] Raised Db_exn.Duplicate_key("VM", "platform", "OpaqueRef:cae2f8cd-6d33-4ca8-81a1-0eb76df149bd", "secureboot")
May 13 11:59:07 xen xapi: [error||13930 :::80||backtrace] 7/8 xapi Called from file map.ml, line 135
May 13 11:59:07 xen xapi: [error||13931 :::80||backtrace] 3/8 xapi Called from file ocaml/xapi/rbac.ml, line 231
May 13 11:59:07 xen xapi: [error||13929 :::80||backtrace] 1/8 xapi Raised at file ocaml/database/db_cache_impl.ml, line 310
May 13 11:59:07 xen xapi: [error||13931 :::80||backtrace] 4/8 xapi Called from file ocaml/xapi/server_helpers.ml, line 100
May 13 11:59:07 xen xapi: [error||13930 :::80||backtrace] 8/8 xapi Called from file src/sexp_conv.ml, line 156
May 13 11:59:07 xen xapi: [error||13931 :::80||backtrace] 5/8 xapi Called from file ocaml/xapi/server_helpers.ml, line 121
May 13 11:59:07 xen xapi: [error||13929 :::80||backtrace] 2/8 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 24
May 13 11:59:07 xen xapi: [error||13930 :::80||backtrace]
May 13 11:59:07 xen xapi: [error||13931 :::80||backtrace] 6/8 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 24
May 13 11:59:07 xen xapi: [error||13929 :::80||backtrace] 3/8 xapi Called from file ocaml/xapi/rbac.ml, line 231
May 13 11:59:07 xen xapi: [error||13929 :::80||backtrace] 4/8 xapi Called from file ocaml/xapi/server_helpers.ml, line 100
May 13 11:59:07 xen xapi: [error||13931 :::80||backtrace] 7/8 xapi Called from file map.ml, line 135
May 13 11:59:07 xen xapi: [error||13929 :::80||backtrace] 5/8 xapi Called from file ocaml/xapi/server_helpers.ml, line 121
May 13 11:59:07 xen xapi: [error||13931 :::80||backtrace] 8/8 xapi Called from file src/sexp_conv.ml, line 156
May 13 11:59:07 xen xapi: [error||13929 :::80||backtrace] 6/8 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 24
May 13 11:59:07 xen xapi: [error||13931 :::80||backtrace]
May 13 11:59:07 xen xapi: [error||13929 :::80||backtrace] 7/8 xapi Called from file map.ml, line 135
May 13 11:59:07 xen xapi: [error||13929 :::80||backtrace] 8/8 xapi Called from file src/sexp_conv.ml, line 156
May 13 11:59:07 xen xapi: [error||13929 :::80||backtrace]

This problem is common for all servers.

olivierlambert

You have duplicates in XAPI DB, that's not normal

It's coming from a template I assume.

burbilog

@olivierlambert But templates are stock templates, no? It does not matter what template I choose, it fails anyway.

How to fix them?

olivierlambert

I have no context on what you did on those hosts previously, so it's hard to answer what to do to assist.

I don't know what could trigger that in the first place

burbilog

@olivierlambert I did not do anything on these hosts, except occasional yum update. Frankly, i did not touch this setup for a while and it worked a month or two ago ok.

I'm kinda surprised that all 3 servers do the same. One of them wasn't touched at all except yum update since it worked ok.

olivierlambert

It's normal you have the problem on the whole pool/all hosts, because the XAPI database is shared with all hosts.

I would search for duplicate keys for platform record on all your existing VMs.

burbilog

@olivierlambert So, how to look up these keys? I ran xe vm-list and xe sr-list on all hosts, it seems that all UUIDs are different.

I even reinstalled one of the hosts, set up 8.2.1 anew and the problem here persists.

olivierlambert

Again, reinstalling won't change anything since the info is within the main DB, which is copied on all pool members from the master

You need to find duplicates UUIDs in all your VMs objects.

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.