API,VMWARE,VEEAM

4.19.1

Assign Instance to backup offering problem

It makes it look like the transaction is done but it really isn't.

2024-07-24 22:58:00,465 DEBUG [c.c.a.ApiServlet] (qtp660017404-390:ctx-e6fc64df ctx-390166cf) (logid:968834c0) ===END===  192.168.161.8 -- GET  jobId=4dabe3fc-14a1-4c2a-8992-326e1be7ca6a&command=queryAsyncJobResult&response=json
2024-07-24 22:58:00,557 DEBUG [o.a.c.h.HAManagerImpl] (BackgroundTaskPollManager-5:ctx-60ee3a93) (logid:46865693) HA health check task is running...
2024-07-24 22:58:00,666 DEBUG [o.a.c.b.v.VeeamClient] (API-Job-Executor-1:ctx-255103b8 job-517 ctx-2be1b76c) (logid:4dabe3fc) Response received in GET request is: [HttpResponseProxy{HTTP/1.1 200 OK [Cache-Control: private, Content-Length: 8363, Content-Type: application/xml; charset=utf-8, Server: Microsoft-HTTPAPI/2.0, X-Frame-Options: SAMEORIGIN, X-XSS-Protection: 1; mode=block, Strict-Transport-Security: max-age=31536000, X-Content-Type-Options: nosniff, Date: Wed, 24 Jul 2024 19:58:33 GMT] ResponseEntityProxy{[Content-Type: application/xml; charset=utf-8,Content-Length: 8363,Chunked: false]}}] for URL: [https://vbem01.flexapp360.team:9398/api/jobs/dea66e23-a8e6-4247-a7d5-1b01969aa3c7?format=Entity].
2024-07-24 22:58:00,752 DEBUG [o.a.c.b.v.VeeamClient] (API-Job-Executor-1:ctx-255103b8 job-517 ctx-2be1b76c) (logid:4dabe3fc) Trying to clone veeam job: urn:veeam:Job:dea66e23-a8e6-4247-a7d5-1b01969aa3c7 with backup uuid: i-2-20-VM-CSBKP-22662e18-8ae1-4031-a82c-bf848a4b29bd
2024-07-24 22:58:00,756 DEBUG [o.a.c.b.v.VeeamClient] (API-Job-Executor-1:ctx-255103b8 job-517 ctx-2be1b76c) (logid:4dabe3fc) Trying to list backup repository for backup job [name: DailyBackup] in server [id: 7427e57f-b587-4d4f-a678-7dc0db6d4ab9].
2024-07-24 22:58:00,757 WARN  [o.a.c.b.v.VeeamClient] (API-Job-Executor-1:ctx-255103b8 job-517 ctx-2be1b76c) (logid:4dabe3fc) Exception caught while trying to clone Veeam job:
com.cloud.utils.exception.CloudRuntimeException: Error while executing PowerShell commands due to: There was a problem while connecting to vbem01.flexapp360.team:22
        at org.apache.cloudstack.backup.veeam.VeeamClient.executePowerShellCommands(VeeamClient.java:646)
        at org.apache.cloudstack.backup.veeam.VeeamClient.getRepositoryNameFromJob(VeeamClient.java:434)
        at org.apache.cloudstack.backup.veeam.VeeamClient.listBackupRepository(VeeamClient.java:412)
        at org.apache.cloudstack.backup.veeam.VeeamClient.cloneVeeamJob(VeeamClient.java:530)
        at org.apache.cloudstack.backup.VeeamBackupProvider.assignVMToBackupOffering(VeeamBackupProvider.java:177)
        at org.apache.cloudstack.backup.BackupManagerImpl$1.doInTransaction(BackupManagerImpl.java:314)
        at org.apache.cloudstack.backup.BackupManagerImpl$1.doInTransaction(BackupManagerImpl.java:306)
        at com.cloud.utils.db.Transaction$3.doInTransaction(Transaction.java:74)
        at com.cloud.utils.db.Transaction.execute(Transaction.java:62)
        at com.cloud.utils.db.Transaction.execute(Transaction.java:71)
        at org.apache.cloudstack.backup.BackupManagerImpl.transactionAssignVMToBackupOffering(BackupManagerImpl.java:306)
        at org.apache.cloudstack.backup.BackupManagerImpl.assignVMToBackupOffering(BackupManagerImpl.java:302)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
        at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:52)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
        at com.sun.proxy.$Proxy330.assignVMToBackupOffering(Unknown Source)
        at org.apache.cloudstack.api.command.user.backup.AssignVirtualMachineToBackupOfferingCmd.execute(AssignVirtualMachineToBackupOfferingCmd.java:88)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:172)
        at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:112)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:654)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:602)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
2024-07-24 22:58:00,759 ERROR [o.a.c.b.VeeamBackupProvider] (API-Job-Executor-1:ctx-255103b8 job-517 ctx-2be1b76c) (logid:4dabe3fc) Failed to clone pre-defined Veeam job (backup offering) for backup offering ID: urn:veeam:Job:dea66e23-a8e6-4247-a7d5-1b01969aa3c7 but will check the list of jobs again if it was eventually succeeded.
2024-07-24 22:58:00,759 DEBUG [o.a.c.b.v.VeeamClient] (API-Job-Executor-1:ctx-255103b8 job-517 ctx-2be1b76c) (logid:4dabe3fc) Trying to list backup policies that are Veeam jobs
2024-07-24 22:58:01,190 DEBUG [o.a.c.b.v.VeeamClient] (API-Job-Executor-1:ctx-255103b8 job-517 ctx-2be1b76c) (logid:4dabe3fc) Response received in GET request is: [HttpResponseProxy{HTTP/1.1 200 OK [Cache-Control: private, Content-Length: 912, Content-Type: application/xml; charset=utf-8, Server: Microsoft-HTTPAPI/2.0, X-Frame-Options: SAMEORIGIN, X-XSS-Protection: 1; mode=block, Strict-Transport-Security: max-age=31536000, X-Content-Type-Options: nosniff, Date: Wed, 24 Jul 2024 19:58:35 GMT] ResponseEntityProxy{[Content-Type: application/xml; charset=utf-8,Content-Length: 912,Chunked: false]}}] for URL: [https://vbem01.flexapp360.team:9398/api/jobs].
2024-07-24 22:58:01,204 ERROR [o.a.c.b.BackupManagerImpl] (API-Job-Executor-1:ctx-255103b8 job-517 ctx-2be1b76c) (logid:4dabe3fc) Failed to assign VM [{"backupOfferingId":1,"backupVolumes":"[{\"uuid\":\"9c1a0797-f55f-4f93-8712-085d48eca756\",\"type\":\"ROOT\",\"size\":107374182400,\"path\":\"0fb3c71b3444447f92dae3312ef3e6e7\"}]","instanceName":"i-2-20-VM","uuid":"22662e18-8ae1-4031-a82c-bf848a4b29bd"}] to the Backup Offering [{"externalId":"urn:veeam:Job:dea66e23-a8e6-4247-a7d5-1b01969aa3c7","name":"Daily Backup","provider":"veeam","uuid":"291a0968-c509-438a-94f9-1f60e2c1532e"}], using provider [name: veeam, class: VeeamBackupProvider], due to: [Failed to assign the VM to the backup offering, please try removing the assignment and try again.].
2024-07-24 22:58:01,205 DEBUG [o.a.c.b.BackupManagerImpl] (API-Job-Executor-1:ctx-255103b8 job-517 ctx-2be1b76c) (logid:4dabe3fc) Failed to assign VM [{"backupOfferingId":1,"backupVolumes":"[{\"uuid\":\"9c1a0797-f55f-4f93-8712-085d48eca756\",\"type\":\"ROOT\",\"size\":107374182400,\"path\":\"0fb3c71b3444447f92dae3312ef3e6e7\"}]","instanceName":"i-2-20-VM","uuid":"22662e18-8ae1-4031-a82c-bf848a4b29bd"}] to the Backup Offering [{"externalId":"urn:veeam:Job:dea66e23-a8e6-4247-a7d5-1b01969aa3c7","name":"Daily Backup","provider":"veeam","uuid":"291a0968-c509-438a-94f9-1f60e2c1532e"}], using provider [name: veeam, class: VeeamBackupProvider], due to: [Failed to assign the VM to the backup offering, please try removing the assignment and try again.].
com.cloud.utils.exception.CloudRuntimeException: Failed to assign the VM to the backup offering, please try removing the assignment and try again.
        at org.apache.cloudstack.backup.BackupManagerImpl$1.doInTransaction(BackupManagerImpl.java:315)
        at org.apache.cloudstack.backup.BackupManagerImpl$1.doInTransaction(BackupManagerImpl.java:306)
        at com.cloud.utils.db.Transaction$3.doInTransaction(Transaction.java:74)
        at com.cloud.utils.db.Transaction.execute(Transaction.java:62)
        at com.cloud.utils.db.Transaction.execute(Transaction.java:71)
        at org.apache.cloudstack.backup.BackupManagerImpl.transactionAssignVMToBackupOffering(BackupManagerImpl.java:306)
        at org.apache.cloudstack.backup.BackupManagerImpl.assignVMToBackupOffering(BackupManagerImpl.java:302)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
        at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:52)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
        at com.sun.proxy.$Proxy330.assignVMToBackupOffering(Unknown Source)
        at org.apache.cloudstack.api.command.user.backup.AssignVirtualMachineToBackupOfferingCmd.execute(AssignVirtualMachineToBackupOfferingCmd.java:88)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:172)
        at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:112)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:654)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:602)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
2024-07-24 22:58:01,241 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-1:ctx-255103b8 job-517 ctx-2be1b76c) (logid:4dabe3fc) Complete async job-517, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.SuccessResponse/null/{"success":"true"}
2024-07-24 22:58:01,243 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-1:ctx-255103b8 job-517 ctx-2be1b76c) (logid:4dabe3fc) Publish async job-517 complete on message bus
2024-07-24 22:58:01,243 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-1:ctx-255103b8 job-517 ctx-2be1b76c) (logid:4dabe3fc) Wake up jobs related to job-517
2024-07-24 22:58:01,244 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-1:ctx-255103b8 job-517 ctx-2be1b76c) (logid:4dabe3fc) Update db status for job-517
2024-07-24 22:58:01,246 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-1:ctx-255103b8 job-517 ctx-2be1b76c) (logid:4dabe3fc) Wake up jobs joined with job-517 and disjoin all subjobs created from job- 517
2024-07-24 22:58:01,255 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-1:ctx-255103b8 job-517) (logid:4dabe3fc) Done executing org.apache.cloudstack.api.command.user.backup.AssignVirtualMachineToBackupOfferingCmd for job-517
2024-07-24 22:58:01,256 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-1:ctx-255103b8 job-517) (logid:4dabe3fc) Remove job-517 from job monitoring
2024-07-24 22:58:01,419 DEBUG [c.c.a.ApiServlet] (qtp660017404-388:ctx-8d964df1) (logid:2ebbfcc9) ===START===  192.168.161.8 -- GET  command=readyForShutdown&response=json
2024-07-24 22:58:01,419 DEBUG [c.c.a.ApiServlet] (qtp660017404-388:ctx-8d964df1) (logid:2ebbfcc9) Two factor authentication is already verified for the user 2, so skipping
2024-07-24 22:58:01,435 DEBUG [c.c.a.ApiServer] (qtp660017404-388:ctx-8d964df1 ctx-ec3a5d74) (logid:2ebbfcc9) CIDRs from which account 'Account [{"accountName":"admin","id":2,"uuid":"a64e983a-45bd-11ef-968b-005056b7aa72"}]' is allowed to perform API calls: 0.0.0.0/0,::/0
2024-07-24 22:58:01,445 DEBUG [o.a.c.a.StaticRoleBasedAPIAccessChecker] (qtp660017404-388:ctx-8d964df1 ctx-ec3a5d74) (logid:2ebbfcc9) RoleService is enabled. We will use it instead of StaticRoleBasedAPIAccessChecker.