Duplicate vmid's?

[cronistar]

Hi Friends,
We have a 21-node cluster with a few thousand VMs; most are powered off (they're used for students to practice networking, computer science, etc, not actual production workloads). We do a lot of scripting to provision machines out for the students and we've noticed we're getting duplicate vmid's.

We're using proxmoxer for the majority of our provisioning, right before copying the vm, we make a call to cluster/nextid to get the next unique vmid-- but the value we're getting back isn't always unique. It tends to be the vmid of a VM we just created.



We're not cloning VMs asynchronously, we wait for the previous clone operation to finish before getting the next vmid & starting to copy the next vm. Every node in the cluster is running 8.2.0 as well. We do occasionally get a file lock issue

cfs-lock 'file-user_cfg' error: got lock request timeout

but those don't seem to correlate to the duplicate vmids.

Does anyone have advice as to the logs I could look into to see what could be causing this? It feels like the cluster is out of sync, but we aren't seeing any other major problems.

 

[sw-omit]

Probably the first things I would personally check would be the pvecm status and the system log specifically the part about corosync if it maybe goes out of sync there.
Since it is a large cluster, do you have the primary link on a completely separate port / switch / subnet (not just vlan) that you use only for that and nothing else? (Not even accessing the management-interface) And have you checked that the latency between all of the nodes to all of the nodes is below 5 ms consistently?

Also, since I don't know how proxmoxer works, does it always does the requests to 1 specific node or to "a node in the cluster"? If the former, tried changing it to one of the other nodes? If the later, is it possible/have you tried forcing it to use only 1 or 2 nodes?

 

[cronistar]

Apologies for my late response! pvecm status reports that we're quorate with all of the hosts. We do not currently have things running on a separate physical network, our latency between the nodes, just tested via a ping, is sitting around 0.2ms. We have an additional physical network and plan to move corosync over to it this weekend- fingers crossed that all goes well. The documentation seems to be fairly straightforward and we've done a dry run with a testing cluster to make sure our process seems clean.

As for proxmoxer and our other API requests, we've had them scattered about, we've since moved them all to point to one single host, that hasn't seemed to make anything better or worse, but logs are more convenient to read and correlate now.

We do still see a few bizarre errors when we dump the system logs, I included a snippet here. Mainly from the pvedaemon, an ipcc_send_rec error-- would that indicate something corosync related?

Sep 19 18:34:43 pve18 pvestatd[2858995]: VM 3554 qmp command failed - VM 3554 qmp command 'query-proxmox-support' failed - unable to connect to VM 3554 qmp socket - timeout after 51 retries
Sep 19 18:34:45 pve18 systemd[1]: session-8928.scope: Deactivated successfully.
Sep 19 18:34:45 pve18 systemd[1]: session-8928.scope: Consumed 2.131s CPU time.
Sep 19 18:34:45 pve18 systemd-logind[833]: Session 8928 logged out. Waiting for processes to exit.
Sep 19 18:34:45 pve18 systemd-logind[833]: Removed session 8928.
Sep 19 18:34:47 pve18 pvedaemon[3159278]: stop VM 1001: UPID:pve18:003034EE:13AAB951:66ECB517:qmstop:1001:user.name@domain.local:
Sep 19 18:34:47 pve18 pvedaemon[3062163]: <user.name@domain.local> starting task UPID:pve18:003034EE:13AAB951:66ECB517:qmstop:1001:user.name@domain.local:
Sep 19 18:34:47 pve18 pvedaemon[3062163]: writing cluster log failed: ipcc_send_rec[7] failed: Invalid argument
Sep 19 18:34:48 pve18 pmxcfs[19423]: [status] notice: received log
Sep 19 18:34:48 pve18 kernel: tap1001i0: left allmulticast mode
Sep 19 18:34:48 pve18 kernel: pool593: port 2(tap1001i0) entered disabled state
Sep 19 18:34:49 pve18 pmxcfs[19423]: [status] notice: received log
Sep 19 18:34:49 pve18 pmxcfs[19423]: [status] notice: received log
Sep 19 18:34:49 pve18 pvestatd[2858995]: status update time (13.939 seconds)
Sep 19 18:34:49 pve18 kernel: tap1001i1: left allmulticast mode
Sep 19 18:34:49 pve18 kernel: pool596: port 2(tap1001i1) entered disabled state
Sep 19 18:34:49 pve18 kernel: tap1001i2: left allmulticast mode
Sep 19 18:34:49 pve18 kernel: pool597: port 2(tap1001i2) entered disabled state
Sep 19 18:34:50 pve18 qmeventd[857]: read: Connection reset by peer
Sep 19 18:34:50 pve18 pvedaemon[3062163]: <user.name@domain.local> end task UPID:pve18:003034EE:13AAB951:66ECB517:qmstop:1001:user.name@domain.local: OK
Sep 19 18:34:50 pve18 pvedaemon[3062163]: writing cluster log failed: ipcc_send_rec[7] failed: Invalid argument

 

[sw-omit]

I hope it does help, but I'm suspecting that it might. What I think might be happening is that the action of creating the VM, meaning transferring data, is creating (enough) delay for long enough for Proxmox to start complaining.
Have you tested the ping-response times also while creating a bunch of VM's back-to-back (maybe adding some download/upload traffic through other means as well and hopefully triggering either of the errors again)?
Having storage-traffic and corosync-traffic not be (primarily) on the same line is one of the strong setup-recommendations:

https://pve.proxmox.com/wiki/Cluster_Manager#_requirements

• We recommend a dedicated NIC for the cluster traffic, especially if you use shared storage.

Also one other note, when you are moving the corosync to a seperate network, be sure to still put the main line a secondairy / fallback, in case you need to do maintenance to this second line or some kind of failure somewhere.
https://pve.proxmox.com/wiki/Cluster_Manager#pvecm_redundancy