Hi @taschaal,
did you ever solve this issue? I'm seeing the same error with no details and have no clue what the issue is. I don't see any connection issues, but it's also not clear to me who is talking wo whom (OV, OV4VC, vCenter, ESXi)
@Lalegre I don't have this log on my vCenter.
/var/log/vmware/vmware-updatemgr/vum-server/vmware-vum-server-log4cpp.log
Other logs show error like this:
vmware-vum-server.log
2023-08-03T07:51:24.670Z info vmware-vum-server[20943] [Originator@6876 sub=ServiceProvider] [EmbeddedPyServiceProvider 1609] HSM Task Info JSON String: {"action": "UPDATE_PRE_CHECK", "description": "Precheck update for host-2429156", "estimatedTimeRemaining": 0,
"hosts": ["host-2429156"], "id": "9f81ce00-1d79-4c08-a54e-c718d14cf621", "messages": ["Failed precheck for host-2429156"], "operationStatusCode": 500, "progress": 100, "startTime": "2023-08-03 07:50:52.609331", "status": "FAILED"}
hsm-service.log
HsmService:2023-08-03 07:50:26,089[Dummy-43]hsmService:416 [INFO] Retrieved information of task d5ee9e48-06b6-498c-9c52-d2ec2851f421: {"action":"GET_HOST_INVENTORY","description":"Firmware inventory details of host host-2429156","estimatedTimeRemaining":0,"hosts":["host-2429156"],"id":"d5ee9e48-06b6-498c-9c52-d2ec2851f421","messages":["Error occured during inventory of host-2429156"],"operationStatusCode":500,"progress":100,"startTime":"2023-08-03 07:50:13.089515","status":"FAILED"}
HsmService:2023-08-03 07:50:26,089[Dummy-43]hsmService:758 [INFO] Hsm service result: {'output': '{"action": "GET_HOST_INVENTORY", "description": "Firmware inventory details of host host-2429156", "estimatedTimeRemaining": 0, "hosts": ["host-2429156"], "id": "d5ee9e48-06b6-498c-9c52-d2ec2851f421", "messages": ["Error occured during inventory of host-2429156"], "operationStatusCode": 500, "progress": 100, "startTime": "2023-08-03 07:50:13.089515", "status": "FAILED"}', 'error': None}
HsmService:2023-08-03 07:50:27,114[MainThread]hsmService:737 [INFO] HSM Service is initialized
HsmService:2023-08-03 07:50:51,874[Dummy-9]hsmService:793 [INFO] Running command from C++: hosts update
HsmService:2023-08-03 07:50:51,874[Dummy-9]hsmService:746 [INFO] Running command hosts update
HsmService:2023-08-03 07:50:51,875[Dummy-9]hsmService:245 [INFO] Got operation arguments: _OptArgsHolder(host_id='host-2429156', package=None, release=None, task_id=None, version=None)
HsmService:2023-08-03 07:50:51,875[Dummy-9]hsmService:255 [INFO] Initiating executor
HsmService:2023-08-03 07:50:51,875[Dummy-9]hsmService:478 [INFO] Got network location: SDES0259.xxxxxx:3512
HsmService:2023-08-03 07:50:51,876[Dummy-9]hsmService:503 [INFO] Extracted hostname: sdes0259.xxxxxx, port: 3512
HsmService:2023-08-03 07:50:51,883[Dummy-9]hsmService:270 [INFO] Successfully initiated executor
HsmService:2023-08-03 07:50:52,611[Dummy-9]hsmService:396 [INFO] Task: 9f81ce00-1d79-4c08-a54e-c718d14cf621 was scheduled to UPDATE_PRE_CHECK host host-2429156 firmware
HsmService:2023-08-03 07:50:52,611[Dummy-9]hsmService:758 [INFO] Hsm service result: {'output': '{"task": "9f81ce00-1d79-4c08-a54e-c718d14cf621"}', 'error': None}
HsmService:2023-08-03 07:50:52,619[Dummy-9]hsmService:793 [INFO] Running command from C++: tasks get
HsmService:2023-08-03 07:50:52,620[Dummy-9]hsmService:746 [INFO] Running command tasks get
HsmService:2023-08-03 07:50:52,620[Dummy-9]hsmService:245 [INFO] Got operation arguments: _OptArgsHolder(host_id=None, package=None, release=None, task_id='9f81ce00-1d79-4c08-a54e-c718d14cf621', version=None)
HsmService:2023-08-03 07:50:52,620[Dummy-9]hsmService:255 [INFO] Initiating executor
HsmService:2023-08-03 07:50:52,621[Dummy-9]hsmService:478 [INFO] Got network location: SDES0259.xxxxxx:3512
HsmService:2023-08-03 07:50:52,621[Dummy-9]hsmService:503 [INFO] Extracted hostname: sdes0259.xxxxxx, port: 3512
HsmService:2023-08-03 07:50:52,630[Dummy-9]hsmService:270 [INFO] Successfully initiated executor
HsmService:2023-08-03 07:50:53,619[Dummy-9]hsmService:416 [INFO] Retrieved information of task 9f81ce00-1d79-4c08-a54e-c718d14cf621: {"action":"UPDATE_PRE_CHECK","description":"Precheck update for host-2429156","estimatedTimeRemaining":180,"hosts":["host-2429156"],"id":"9f81ce00-1d79-4c08-a54e-c718d14cf621","messages":["Starting Precheck update for host-2429156"],"progress":10,"startTime":"2023-08-03 07:50:52.609331","status":"RUNNING"}
HsmService:2023-08-03 07:50:53,619[Dummy-9]hsmService:758 [INFO] Hsm service result: {'output': '{"action": "UPDATE_PRE_CHECK", "description": "Precheck update for host-2429156", "estimatedTimeRemaining": 180, "hosts": ["host-2429156"], "id": "9f81ce00-1d79-4c08-a54e-c718d14cf621", "messages": ["Starting Precheck update for host-2429156"], "progress": 10, "startTime": "2023-08-03 07:50:52.609331", "status": "RUNNING"}', 'error': None}
HsmService:2023-08-03 07:51:23,628[Dummy-9]hsmService:793 [INFO] Running command from C++: tasks get
HsmService:2023-08-03 07:51:23,628[Dummy-9]hsmService:746 [INFO] Running command tasks get
HsmService:2023-08-03 07:51:23,629[Dummy-9]hsmService:245 [INFO] Got operation arguments: _OptArgsHolder(host_id=None, package=None, release=None, task_id='9f81ce00-1d79-4c08-a54e-c718d14cf621', version=None)
HsmService:2023-08-03 07:51:23,629[Dummy-9]hsmService:255 [INFO] Initiating executor
HsmService:2023-08-03 07:51:23,629[Dummy-9]hsmService:478 [INFO] Got network location: SDES0259.xxxxxx:3512
HsmService:2023-08-03 07:51:23,630[Dummy-9]hsmService:503 [INFO] Extracted hostname: sdes0259.xxxxxx, port: 3512
HsmService:2023-08-03 07:51:23,636[Dummy-9]hsmService:270 [INFO] Successfully initiated executor
HsmService:2023-08-03 07:51:24,669[Dummy-9]hsmService:416 [INFO] Retrieved information of task 9f81ce00-1d79-4c08-a54e-c718d14cf621: {"action":"UPDATE_PRE_CHECK","description":"Precheck update for host-2429156","estimatedTimeRemaining":0,"hosts":["host-2429156"],"id":"9f81ce00-1d79-4c08-a54e-c718d14cf621","messages":["Failed precheck for host-2429156"],"operationStatusCode":500,"progress":100,"startTime":"2023-08-03 07:50:52.609331","status":"FAILED"}
HsmService:2023-08-03 07:51:24,670[Dummy-9]hsmService:758 [INFO] Hsm service result: {'output': '{"action": "UPDATE_PRE_CHECK", "description": "Precheck update for host-2429156", "estimatedTimeRemaining": 0, "hosts": ["host-2429156"], "id": "9f81ce00-1d79-4c08-a54e-c718d14cf621", "messages": ["Failed precheck for host-2429156"], "operationStatusCode": 500, "progress": 100, "startTime": "2023-08-03 07:50:52.609331", "status": "FAILED"}', 'error': None}
The image itself and the status in vLCM looks good, status of firmware version too.
Interesting is that vLCM pre-check shows errors for iSUT, but amsd and iSUT (AutoDeploy) are running and the "repair" button triggers the start to fix it, but I only see in logs that service are restarted again. Status never changes to green.
2023-08-02T14:17:52.448Z sshd[5838021]: Connection from 10.11.5.76 port 53766
2023-08-02T14:17:52.591Z sshd[5838021]: Accepted keyboard-interactive/pam for root from 10.11.5.76 port 53766 ssh2
2023-08-02T14:17:52.609Z sshd[5838021]: pam_unix(sshd:session): session opened for user root by (uid=0)
2023-08-02T14:17:52.649Z sshd[5838021]: User 'root' running command '/etc/init.d/amsd restart'
2023-08-02T14:18:10.134Z sshd[5838021]: User 'root' running command 'sut -set mode=AutoDeploy'
