Hi, as promised, here are the log excerpts from the incident, in case they help the @Team-Storage folks (or anyone hitting the same thing). All times are CET (host time). VM dd25471a-fbd3-2b0c-df4c-b8182546f6a8, SR 1a97f391-…, migration task R:4fa24c2fefb3 (beta → gamma).
1. The failed attach (SMlog on gamma)
The SR lock is acquired at 23:00:04 and the exception comes 6s later:
Nov 10 23:00:04 gamma SM: [11963] lock: acquired /var/lock/sm/1a97f391-c733-8520-62c3-2f3847235a36/sr
Nov 10 23:00:10 gamma SM: [11963] Raising exception [47, The SR is not available [opterr=Error: ERRO:NoneType]]
Nov 10 23:00:10 gamma SM: [11963] ***** generic exception: vdi_attach: EXCEPTION <class 'xs_errors.SROSError'>, The SR is not available [opterr=Error: ERRO:NoneType]
File "/opt/xensource/sm/SRCommand.py", line 157, in _run_locked
target = sr.vdi(self.vdi_uuid)
File "/opt/xensource/sm/LinstorSR", line 549, in wrap
return load(self, *args, **kwargs)
File "/opt/xensource/sm/LinstorSR", line 479, in load
raise xs_errors.XenError('SRUnavailable', opterr=str(e))
One second later the same SR answers normally, which is why I think the failure was transient:
Nov 10 23:00:11 gamma SM: [12120] Failed to join node(s): {'gamma', 'alpha'}
Nov 10 23:00:11 gamma SM: [12120] Synchronize metadata...
Nov 10 23:00:11 gamma SM: [12120] VDI c90eeb92-... loaded! (path=/dev/drbd/by-res/xcp-persistent-ha-statefile/0, hidden=0)
2. LINSTOR side (controller on beta)
Three error reports between 22:59 and 23:00, all identical:
ERROR REPORT 6AF3924C-00000-000001 (also -000002 and -000003)
Version: 1.33.1 Node: beta
Class name: com.linbit.linstor.netcom.PeerClosingConnectionException
Generated at: Method 'connectionClosing', Source file 'TcpConnectorPeer.java', Line #627
*__checkpoint ⇢ Fetch thin capacity info
3. How it surfaces in xapi
gamma xapi: [error|VDI.attach2] sm_exec failed with exception Storage_error ([S(Backend_error);[S(SR_BACKEND_FAILURE_47);[S();S(The SR is not available [opterr=Error: ERRO:NoneType]);S()]]])
gamma xapi: [error|Async.VM.pool_migrate R:4fa24c2fefb3|Storage_smapiv1_wrapper] dp:vbd/1/xvda sr:1a97f391-... vdi:60342e65-... op:attach(RW) error:Storage_error (...SR_BACKEND_FAILURE_47...)
4. The cleanup on the source also fails (beta)
23:00:10 beta xenopsd-xc: [error|71|Async.VM.pool_migrate R:4fa24c2fefb3|xenops_server] VM.migrate: Failed during Synchronisation point 4. msg: Xenops_interface.Xenopsd_error([S(Storage_backend_error);[S(SR_BACKEND_FAILURE_47);...]])
23:00:10 beta xenopsd-xc: [error|71|...|task_server] Task 101 failed; Xenopsd_error([S(Does_not_exist);[S(VM);S(dd25471a-.../config)]])
23:00:10 beta xenopsd-xc: [error|71|...|xenops_server] Triggering cleanup actions failed: Xenopsd_error([S(Does_not_exist);[S(VM);S(dd25471a-.../config)]])
So after the migration error, the cleanup fails too because the VM config is no longer in xenopsd on the source. That matches what I saw afterwards: XAPI says running on beta, but xenopsd doesn't know the VM.
5. What is left on the destination (gamma)
The temporary extra/ entry is created at 22:58:09 and renamed to the final uuid at 23:00:03, i.e. before the attach fails at 23:00:10. Nothing removes it afterwards:
22:58:09 gamma xenopsd-xc: [debug|Async.VM.pool_migrate R:4fa24c2fefb3|xenops_utils] TypedTable: Writing extra/dd25471a-fbd3-2b0c-df4c-000000000001
23:00:03 gamma xenopsd-xc: [debug|13|Async.VM.pool_migrate R:4fa24c2fefb3|xenops_utils] TypedTable: Renaming extra/dd25471a-fbd3-2b0c-df4c-000000000001 -> extra/dd25471a-fbd3-2b0c-df4c-b8182546f6a8
6. What the following RPU runs report in XO
2nd run (00:03, VM still in that state):
END failure Evacuate INTERNAL_ERROR(Object with type VM and id dd25471a-fbd3-2b0c-df4c-b8182546f6a8/config does not exist in xenopsd)
END failure Rolling pool update INTERNAL_ERROR(Object with type VM and id dd25471a-.../config does not exist in xenopsd)
3rd run (00:11–00:14, after I had recovered the VM on beta only):
END failure Evacuate INTERNAL_ERROR(xenopsd internal error: VM.migrate: Failed during Synchronisation point 4. msg: Xenops_interface.Xenopsd_error([S(Already_exists);[S(extra);S(extra/dd25471a-fbd3-2b0c-df4c-b8182546f6a8)]]))
And on gamma for that run:
00:13:42 gamma xenopsd-xc: [debug|94|Async.VM.pool_migrate R:005a41ca1c30|xenops_utils] Key extra/dd25471a-fbd3-2b0c-df4c-b8182546f6a8 already exists
00:13:42 gamma xenopsd-xc: [error|94|...|backtrace] Raised Xenopsd_error([S(Already_exists);[S(extra);S(extra/dd25471a-fbd3-2b0c-df4c-b8182546f6a8)]])
00:13:42 gamma xenopsd-xc: [debug|94|...|xenops_server] Caught Xenopsd_error([S(Already_exists);...]): cleaning up VM state
Also at 00:14:03, opening the VM console from XO fails on beta with the same Does_not_exist … /config error.
What the logs show
A single transient LINSTOR controller error (ERRO:NoneType) appears to trigger the failure vdi_attach with no retry.
That failure at sync point 4 leaves state on both hosts: on the source the cleanup fails with Does_not_exist …/config, and on the destination the extra/<uuid> entry stays.
Subsequent RPU runs then trips on that leftover (first Does_not_exist, then Already_exists), so it can't recover by itself and requires manual recovery on both hosts.
I still have the full xensource.log, SMlog and ErrorReport files for that window if someone needs more.
Thanks!
