While we tried to executed the powershell tasks in windows machine we always getting the task execution failure error.I have attached the current logs for your reference.
2023-01-25_09:18:44.72970 '[2023-01-25 09:18:44,729] [http-nio-127.0.0.1-8080-exec-3] e[34mINFO e[0;39m e[36mc.m.p.TaskSetsControllere[0;39m - save result: {success=true, msg=null, errors={}, errorCode=null, data=com.morpheus.JobTemplate : 1, inProgress=false}
2023-01-25_09:18:44.72972 ''[2023-01-25 09:18:44,732] [http-nio-127.0.0.1-8080-exec-3] e[34mINFO e[0;39m e[36mc.m.JobServicee[0;39m - Running for target: com.morpheus.JobTarget : 1
2023-01-25_09:18:44.73262 ''[2023-01-25 09:18:44,845] [http-nio-127.0.0.1-8080-exec-3] e[34mINFO e[0;39m e[36mc.m.AuditLogServicee[0;39m - CEF:0|MorpheusData|Morpheus|5.4.12|provisioning:taskSets#execute|taskSet Created|src=10.21.33.172 suid=1 suser=svradm request=http://dev1morpheus01.devcloud.co.id/library/workflows/1/execute requestMethod=POST cn1=1 cn1Label=Object ID cs1Label=Object Type cs1=taskSet cn2=1 cn2Label=Account ID
2023-01-25_09:18:44.84549 ''[2023-01-25 09:18:44,976] [appJobNormal-20] e[34mINFO e[0;39m e[36mc.m.ApplianceJobServicee[0;39m - Executing Job on Target:
2023-01-25_09:18:44.97638 ''[2023-01-25 09:18:45,253] [RxCachedThreadScheduler-4] e[34mINFO e[0;39m e[36mc.m.t.WinrmTaskServicee[0;39m - Executing WinRM Task AntiVirus Package Installation on Server VM-Windows-2019-001
2023-01-25_09:18:45.25389 ''[2023-01-25 09:18:45,254] [RxCachedThreadScheduler-4] e[34mINFO e[0;39m e[36mc.m.MorpheusComputeServicee[0;39m - Sending Winrm Command To Host 10.27.12.7
2023-01-25_09:18:45.25460 ''[2023-01-25 09:18:45,620] [RxCachedThreadScheduler-4] e[34mINFO e[0;39m e[36mo.a.c.w.s.f.ReflectionServiceFactoryBeane[0;39m - Creating Service {http://schemas.dmtf.org/wbem/wsman/1/wsman.xsd}WinRmService from WSDL: jar:file:/opt/morpheus/lib/tomcat/webapps/ROOT/WEB-INF/lib/winrm4j-client-0.12.3.jar!/wsdl/WinRmService.wsdl
2023-01-25_09:18:45.62101 ''[2023-01-25 09:19:16,911] [RxCachedThreadScheduler-4] e[31mWARN e[0;39m e[36mo.a.c.p.PhaseInterceptorChaine[0;39m - Interceptor for {http://schemas.dmtf.org/wbem/wsman/1/wsman.xsd}WinRmService#{http://schemas.dmtf.org/wbem/wsman/1/wsman.xsd}Create has thrown exception, unwinding now
2023-01-25_09:19:16.91175 'org.apache.cxf.interceptor.Fault: Could not send Message.
2023-01-25_09:19:16.91176 at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:67)
2023-01-25_09:19:16.91177 at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308)
2023-01-25_09:19:16.91177 at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:530)
2023-01-25_09:19:16.91177 at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:441)
2023-01-25_09:19:16.91177 at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:356)
2023-01-25_09:19:16.91177 at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:314)
2023-01-25_09:19:16.91177 at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96)
2023-01-25_09:19:16.91178 at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:140)
2023-01-25_09:19:16.91178 at com.sun.proxy.$Proxy268.create(Unknown Source)
2023-01-25_09:19:16.91179 at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2023-01-25_09:19:16.91179 at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
Looks like you are using WinRM and not the Morpheus Agent on the systems? PowerShell is way more performant via the Morpheus agent.
Also, that snippet is too limiting on what is occurring with that script, but here are a few theories:
WinRM could be disconnecting, the payload could be too big (there is a max size WinRM supports), etc.
Validate the RPC credentials work for WinRM via port 5985 (test this port connectivity from Morpheus and ensure winrm quick config is enabled on your system).
Try with/without “Elevated Shell” checkbox on the PowerShell task type
Check this thread. Looks like someone had the same error and solved it with their username format
Hi @cbunge, thank you for your suggestion. I am working with Ibrahim together for this issue.
just reply back to your suggestion,:
WinRM could be disconnecting, the payload could be too big (there is a max size WinRM supports), etc. → it is just one line PowerShell testing purpose. It is working fine in our lab env but failed in customer env.
Validate the RPC credentials work for WinRM via port 5985 (test this port connectivity from Morpheus and ensure winrm quick config is enabled on your system). → we have tested 5985 port, it is connected.
Try with/without “Elevated Shell” checkbox on the PowerShell task type → we tried both but still doesn’t solve the issue
I will put the whole error log file in couples of post since it is quite big.
Appreciate for any of your suggestion here.
1:59:17.32784 '[2023-01-25 11:59:17,327] [RxCachedThreadScheduler-8] e[1;31mERRORe[0;39m e[36mc.m.p.VmwareProvisionServicee[0;39m - Process Exec Failure: [success:false]
2023-01-25_11:59:17.32785 ''[2023-01-25 11:59:17,373] [RxCachedThreadScheduler-8] e[1;31mERRORe[0;39m e[36mc.m.c.VmwareComputeUtilitye[0;39m - executeProcess error: com.vmware.vim25.SystemError: A general system error occurred: vix error codes = (1, 0).
2023-01-25_11:59:17.37384
2023-01-25_11:59:17.37384 'com.vmware.vim25.SystemError: A general system error occurred: vix error codes = (1, 0).
2023-01-25_11:59:17.37384
2023-01-25_11:59:17.37384 at jdk.internal.reflect.GeneratedConstructorAccessor1517.newInstance(Unknown Source)
2023-01-25_11:59:17.37385 at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
2023-01-25_11:59:17.37385 at java.base/java.lang.reflect.Constructor.newInstance(Unknown Source)
2023-01-25_11:59:17.37385 at java.base/java.lang.Class.newInstance(Unknown Source)
2023-01-25_11:59:17.37386 at com.vmware.vim25.ws.XmlGenDom.fromXml(XmlGenDom.java:253)
2023-01-25_11:59:17.37386 at com.vmware.vim25.ws.XmlGenDom.parseSoapFault(XmlGenDom.java:151)
2023-01-25_11:59:17.37387 at com.vmware.vim25.ws.XmlGenDom.fromXML(XmlGenDom.java:109)
2023-01-25_11:59:17.37387 at com.vmware.vim25.ws.SoapClient.unMarshall(SoapClient.java:253)
2023-01-25_11:59:17.37387 at com.vmware.vim25.ws.WSClient.invoke(WSClient.java:96)
2023-01-25_11:59:17.37387 at com.vmware.vim25.ws.VimStub.startProgramInGuest(VimStub.java:4695)
2023-01-25_11:59:17.37387 at com.vmware.vim25.mo.GuestProcessManager.startProgramInGuest(GuestProcessManager.java:65)
2023-01-25_11:59:17.37388 at com.vmware.vim25.mo.GuestProcessManager$startProgramInGuest.call(Unknown Source)
2023-01-25_11:59:17.37388 at com.morpheus.compute.VmwareComputeUtility.executeProcess(VmwareComputeUtility.groovy:5427)
2023-01-25_11:59:17.37389 at com.morpheus.compute.VmwareComputeUtility$executeProcess$67.call(Unknown Source)
2023-01-25_11:59:17.37389 at com.morpheus.provision.VmwareProvisionService.executeContainerCommand(VmwareProvisionService.groovy:3220)
2023-01-25_11:59:17.37389 at com.morpheus.provision.VmwareProvisionService$executeContainerCommand$26.callCurrent(Unknown Source)
2023-01-25_11:59:17.37390 at com.morpheus.provision.AbstractBoxProvisionService.execContainer(AbstractBoxProvisionService.groovy:1680)
2023-01-25_11:59:17.37390 at com.morpheus.provision.AbstractBoxProvisionService.execContainer(AbstractBoxProvisionService.groovy)
2023-01-25_11:59:17.37390 at com.morpheus.provision.AbstractBoxProvisionService$execContainer$15.call(Unknown Source)
2023-01-25_11:59:17.37390 at com.morpheus.task.WinrmTaskService.executeContainerTask(WinrmTaskService.groovy:55)
2023-01-25_11:59:17.37390 at com.morpheus.task.ExecutableTaskInterface$executeContainerTask$0.call(Unknown Source)
2023-01-25_11:59:17.37391 at com.morpheus.task.TaskService.executeContainerTask(TaskService.groovy:343)
2023-01-25_11:59:17.37391 at com.morpheus.task.TaskService$executeContainerTask$10.call(Unknown Source)
2023-01-25_11:59:17.37392 at com.morpheus.provision.AbstractProvisionService.executeContainerTask(AbstractProvisionService.groovy:1785)
2023-01-25_11:59:17.37392 at com.morpheus.provision.AbstractProvisionService$executeContainerTask$28.call(Unknown Source)
2023-01-25_11:59:17.37392 at com.morpheus.ContainerService.executeContainerTask(ContainerService.groovy:1737)
2023-01-25_11:59:17.37392 at com.morpheus.ContainerService$executeContainerTask$58.call(Unknown Source)
2023-01-25_11:59:17.37392 at com.morpheus.InstanceService$_executeInstanceTask_closure205$_closure500$_closure501.doCall(InstanceService.groovy:4874)
2023-01-25_11:59:17.37393 at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2023-01-25_11:59:17.37393 at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:17.37393 at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:17.37393 at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2023-01-25_11:59:17.37393 at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107)
2023-01-25_11:59:17.37394 at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323)
2023-01-25_11:59:17.37394 at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:263)
2023-01-25_11:59:17.37395 at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035)
2023-01-25_11:59:17.37395 at groovy.lang.Closure.call(Closure.java:412)
2023-01-25_11:59:17.37395 at groovy.lang.Closure.call(Closure.java:428)
2023-01-25_11:59:17.37395 at org.grails.orm.hibernate.GrailsHibernateTemplate.doExecute(GrailsHibernateTemplate.java:297)
2023-01-25_11:59:17.37395 at org.grails.orm.hibernate.GrailsHibernateTemplate.execute(GrailsHibernateTemplate.java:241)
2023-01-25_11:59:17.37395 at org.grails.orm.hibernate.GrailsHibernateTemplate.executeWithNewSession(GrailsHibernateTemplate.java:153)
2023-01-25_11:59:17.37396 at org.grails.orm.hibernate.AbstractHibernateDatastore.withNewSession(AbstractHibernateDatastore.java:360)
2023-01-25_11:59:17.37396 at org.grails.orm.hibernate.AbstractHibernateGormStaticApi.withNewSession(AbstractHibernateGormStaticApi.groovy:78)
2023-01-25_11:59:17.37396 at org.grails.datastore.gorm.GormEntity$Trait$Helper.withNewSession(GormEntity.groovy:1027)
2023-01-25_11:59:17.37396 at org.grails.datastore.gorm.GormEntity$Trait$Helper$withNewSession.call(Unknown Source)
2023-01-25_11:59:17.37397 at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:47)
2023-01-25_11:59:17.37397 at org.grails.datastore.gorm.GormEntity$Trait$Helper$withNewSession.call(Unknown Source)
2023-01-25_11:59:17.37397 at com.morpheus.Container.withNewSession(Container.groovy)
2023-01-25_11:59:17.37398 at com.morpheus.Container$withNewSession$26.call(Unknown Source)
2023-01-25_11:59:17.37398 at com.morpheus.InstanceService$_executeInstanceTask_closure205$_closure500.doCall(InstanceService.groovy:4863)
2023-01-25_11:59:17.37398 at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2023-01-25_11:59:17.37398 at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:17.37399 at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:17.37399 at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2023-01-25_11:59:17.37399 at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107)
2023-01-25_11:59:17.37399 at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323)
2023-01-25_11:59:17.37399 at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:263)
2023-01-25_11:59:17.37400 at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035)
2023-01-25_11:59:17.37400 at groovy.lang.Closure.call(Closure.java:412)
2023-01-25_11:59:17.37401 at org.codehaus.groovy.runtime.ConvertedClosure.invokeCustom(ConvertedClosure.java:50)
2023-01-25_11:59:17.37401 at org.codehaus.groovy.runtime.ConversionHandler.invoke(ConversionHandler.java:110)
2023-01-25_11:59:17.37401 at com.sun.proxy.$Proxy216.apply(Unknown Source)
2023-01-25_11:59:17.37402 at io.reactivex.internal.operators.observable.ObservableMap$MapObserver.onNext(ObservableMap.java:57)
2023-01-25_11:59:17.37402 at io.reactivex.subjects.ReplaySubject$UnboundedReplayBuffer.replay(ReplaySubject.java:770)
2023-01-25_11:59:17.37402 at io.reactivex.subjects.ReplaySubject.onNext(ReplaySubject.java:352)
2023-01-25_11:59:17.37402 at org.grails.async.factory.rxjava2.RxPromise$1.onNext(RxPromise.groovy:73)
2023-01-25_11:59:17.37402 at io.reactivex.internal.observers.DeferredScalarDisposable.complete(DeferredScalarDisposable.java:82)
2023-01-25_11:59:17.37403 at io.reactivex.internal.operators.single.SingleToObservable$SingleToObservableObserver.onSuccess(SingleToObservable.java:72)
2023-01-25_11:59:17.37403 at io.reactivex.internal.operators.single.SingleSubscribeOn$SubscribeOnObserver.onSuccess(SingleSubscribeOn.java:68)
2023-01-25_11:59:17.37404 at io.reactivex.internal.operators.single.SingleCreate$Emitter.onSuccess(SingleCreate.java:67)
2023-01-25_11:59:17.37404 at org.grails.async.factory.rxjava2.RxPromise$_closure1.doCall(RxPromise.groovy:42)
2023-01-25_11:59:17.37404 at jdk.internal.reflect.GeneratedMethodAccessor606.invoke(Unknown Source)
2023-01-25_11:59:17.37404 at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:17.37405 at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2023-01-25_11:59:17.37405 at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107)
2023-01-25_11:59:17.37405 at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323)
2023-01-25_11:59:17.37405 at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:263)
2023-01-25_11:59:17.37405 at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035)
2023-01-25_11:59:17.37406 at groovy.lang.Closure.call(Closure.java:412)
2023-01-25_11:59:17.37406 at org.codehaus.groovy.runtime.ConvertedClosure.invokeCustom(ConvertedClosure.java:50)
2023-01-25_11:59:17.37406 at org.codehaus.groovy.runtime.ConversionHandler.invoke(ConversionHandler.java:110)
2023-01-25_11:59:17.37406 at com.sun.proxy.$Proxy213.subscribe(Unknown Source)
2023-01-25_11:59:17.37406 at io.reactivex.internal.operators.single.SingleCreate.subscribeActual(SingleCreate.java:39)
2023-01-25_11:59:17.37407 at io.reactivex.Single.subscribe(Single.java:3666)
2023-01-25_11:59:17.37408 at io.reactivex.internal.operators.single.SingleSubscribeOn$SubscribeOnObserver.run(SingleSubscribeOn.java:89)
2023-01-25_11:59:17.37408 at io.reactivex.Scheduler$DisposeTask.run(Scheduler.java:608)
2023-01-25_11:59:17.37408 at io.reactivex.internal.schedulers.ScheduledRunnable.run(ScheduledRunnable.java:66)
2023-01-25_11:59:17.37409 at io.reactivex.internal.schedulers.ScheduledRunnable.call(ScheduledRunnable.java:57)
2023-01-25_11:59:17.37409 at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
2023-01-25_11:59:17.37410 at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
2023-01-25_11:59:17.37410 at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
2023-01-25_11:59:17.37410 at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
2023-01-25_11:59:17.37410 at java.base/java.lang.Thread.run(Unknown Source)
1:59:17.37410 '[2023-01-25 11:59:17,373] [RxCachedThreadScheduler-8] e[1;31mERRORe[0;39m e[36mc.m.p.VmwareProvisionServicee[0;39m - Process Exec Failure: [success:false]
2023-01-25_11:59:17.37411 ''[2023-01-25 11:59:17,389] [RxCachedThreadScheduler-8] e[34mINFO e[0;39m e[36mo.a.c.w.s.f.ReflectionServiceFactoryBeane[0;39m - Creating Service {http://schemas.dmtf.org/wbem/wsman/1/wsman.xsd}WinRmService from WSDL: jar:file:/opt/morpheus/lib/tomcat/webapps/ROOT/WEB-INF/lib/winrm4j-client-0.12.3.jar!/wsdl/WinRmService.wsdl
2023-01-25_11:59:17.38934 ''[2023-01-25 11:59:17,490] [RxCachedThreadScheduler-8] e[34mINFO e[0;39m e[36mo.a.c.t.h.HTTPConduite[0;39m - Authorization loop detected on Conduit "{http://schemas.dmtf.org/wbem/wsman/1/wsman.xsd}WinRmPort.http-conduit" on URL "http://10.27.4.6:5985/wsman" with realm "null"
2023-01-25_11:59:17.49041 ''[2023-01-25 11:59:17,490] [RxCachedThreadScheduler-8] e[31mWARN e[0;39m e[36mo.a.c.p.PhaseInterceptorChaine[0;39m - Interceptor for {http://schemas.dmtf.org/wbem/wsman/1/wsman.xsd}WinRmService#{http://schemas.dmtf.org/wbem/wsman/1/wsman.xsd}Create has thrown exception, unwinding now
2023-01-25_11:59:17.49095 'org.apache.cxf.interceptor.Fault: Could not send Message.
2023-01-25_11:59:17.49096 at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:67)
2023-01-25_11:59:17.49096 at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308)
2023-01-25_11:59:17.49096 at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:530)
2023-01-25_11:59:17.49097 at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:441)
2023-01-25_11:59:17.49097 at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:356)
2023-01-25_11:59:17.49098 at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:314)
2023-01-25_11:59:17.49099 at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96)
2023-01-25_11:59:17.49099 at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:140)
2023-01-25_11:59:17.49100 at com.sun.proxy.$Proxy268.create(Unknown Source)
2023-01-25_11:59:17.49102 at jdk.internal.reflect.GeneratedMethodAccessor19065.invoke(Unknown Source)
2023-01-25_11:59:17.49102 at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:17.49103 at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2023-01-25_11:59:17.49103 at io.cloudsoft.winrm4j.client.RetryingProxyHandler.invokeWithRetry(RetryingProxyHandler.java:44)
2023-01-25_11:59:17.49104 at io.cloudsoft.winrm4j.client.RetryingProxyHandler.invoke(RetryingProxyHandler.java:31)
2023-01-25_11:59:17.49104 at com.sun.proxy.$Proxy269.create(Unknown Source)
2023-01-25_11:59:17.49104 at io.cloudsoft.winrm4j.client.WinRmClient.createShell(WinRmClient.java:540)
2023-01-25_11:59:17.49105 at io.cloudsoft.winrm4j.winrm.WinRmTool.executeCommand(WinRmTool.java:397)
2023-01-25_11:59:17.49105 at io.cloudsoft.winrm4j.winrm.WinRmTool.executePs(WinRmTool.java:422)
2023-01-25_11:59:17.49106 at io.cloudsoft.winrm4j.winrm.WinRmTool.executePs(WinRmTool.java:413)
2023-01-25_11:59:17.49106 at io.cloudsoft.winrm4j.winrm.WinRmTool$executePs.call(Unknown Source)
2023-01-25_11:59:17.49106 at com.morpheus.RpcService.executeWindowsCommand(RpcService.groovy:706)
2023-01-25_11:59:17.49107 at com.morpheus.RpcService.executeWindowsCommand(RpcService.groovy)
2023-01-25_11:59:17.49109 at com.morpheus.RpcService$executeWindowsCommand$5.call(Unknown Source)
2023-01-25_11:59:17.49112 at com.morpheus.provision.AbstractBoxProvisionService.executeContainerCommand(AbstractBoxProvisionService.groovy:2868)
2023-01-25_11:59:17.49112 at com.morpheus.provision.VmwareProvisionService.super$3$executeContainerCommand(VmwareProvisionService.groovy)
2023-01-25_11:59:17.49112 at jdk.internal.reflect.GeneratedMethodAccessor15905.invoke(Unknown Source)
2023-01-25_11:59:17.49113 at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:17.49113 at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2023-01-25_11:59:17.49113 at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107)
2023-01-25_11:59:17.49114 at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323)
2023-01-25_11:59:17.49114 at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1268)
2023-01-25_11:59:17.49114 at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodOnSuperN(ScriptBytecodeAdapter.java:144)
2023-01-25_11:59:17.49115 at com.morpheus.provision.VmwareProvisionService.executeContainerCommand(VmwareProvisionService.groovy:3241)
2023-01-25_11:59:17.49115 at com.morpheus.provision.VmwareProvisionService$executeContainerCommand$26.callCurrent(Unknown Source)
2023-01-25_11:59:17.49117 at com.morpheus.provision.AbstractBoxProvisionService.execContainer(AbstractBoxProvisionService.groovy:1680)
2023-01-25_11:59:17.49118 at com.morpheus.provision.AbstractBoxProvisionService.execContainer(AbstractBoxProvisionService.groovy)
2023-01-25_11:59:17.49118 at com.morpheus.provision.AbstractBoxProvisionService$execContainer$15.call(Unknown Source)
2023-01-25_11:59:17.49118 at com.morpheus.task.WinrmTaskService.executeContainerTask(WinrmTaskService.groovy:55)
2023-01-25_11:59:17.49120 at com.morpheus.task.ExecutableTaskInterface$executeContainerTask$0.call(Unknown Source)
2023-01-25_11:59:17.49120 at com.morpheus.task.TaskService.executeContainerTask(TaskService.groovy:343)
2023-01-25_11:59:17.49121 at com.morpheus.task.TaskService$executeContainerTask$10.call(Unknown Source)
2023-01-25_11:59:17.49121 at com.morpheus.provision.AbstractProvisionService.executeContainerTask(AbstractProvisionService.groovy:1785)
2023-01-25_11:59:17.49122 at com.morpheus.provision.AbstractProvisionService$executeContainerTask$28.call(Unknown Source)
2023-01-25_11:59:17.49122 at com.morpheus.ContainerService.executeContainerTask(ContainerService.groovy:1737)
2023-01-25_11:59:17.49122 at com.morpheus.ContainerService$executeContainerTask$58.call(Unknown Source)
2023-01-25_11:59:17.49123 at com.morpheus.InstanceService$_executeInstanceTask_closure205$_closure500$_closure501.doCall(InstanceService.groovy:4874)
2023-01-25_11:59:17.49125 at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2023-01-25_11:59:17.49125 at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:17.49126 at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:17.49126 at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2023-01-25_11:59:17.49126 at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107)
2023-01-25_11:59:17.49127 at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323)
2023-01-25_11:59:17.49127 at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:263)
2023-01-25_11:59:17.49128 at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035)
2023-01-25_11:59:17.49128 at groovy.lang.Closure.call(Closure.java:412)
2023-01-25_11:59:17.49129 at groovy.lang.Closure.call(Closure.java:428)
2023-01-25_11:59:17.49129 at org.grails.orm.hibernate.GrailsHibernateTemplate.doExecute(GrailsHibernateTemplate.java:297)
2023-01-25_11:59:17.49130 at org.grails.orm.hibernate.GrailsHibernateTemplate.execute(GrailsHibernateTemplate.java:241)
2023-01-25_11:59:17.49134 at org.grails.orm.hibernate.GrailsHibernateTemplate.executeWithNewSession(GrailsHibernateTemplate.java:153)
2023-01-25_11:59:17.49135 at org.grails.orm.hibernate.AbstractHibernateDatastore.withNewSession(AbstractHibernateDatastore.java:360)
2023-01-25_11:59:17.49136 at org.grails.orm.hibernate.AbstractHibernateGormStaticApi.withNewSession(AbstractHibernateGormStaticApi.groovy:78)
2023-01-25_11:59:17.49136 at org.grails.datastore.gorm.GormEntity$Trait$Helper.withNewSession(GormEntity.groovy:1027)
2023-01-25_11:59:17.49137 at org.grails.datastore.gorm.GormEntity$Trait$Helper$withNewSession.call(Unknown Source)
2023-01-25_11:59:17.49137 at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:47)
2023-01-25_11:59:17.49137 at org.grails.datastore.gorm.GormEntity$Trait$Helper$withNewSession.call(Unknown Source)
2023-01-25_11:59:17.49138 at com.morpheus.Container.withNewSession(Container.groovy)
2023-01-25_11:59:17.49138 at com.morpheus.Container$withNewSession$26.call(Unknown Source)
2023-01-25_11:59:17.49138 at com.morpheus.InstanceService$_executeInstanceTask_closure205$_closure500.doCall(InstanceService.groovy:4863)
2023-01-25_11:59:17.49139 at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2023-01-25_11:59:17.49141 at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:17.49142 at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:17.49142 at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2023-01-25_11:59:17.49142 at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107)
2023-01-25_11:59:17.49143 at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323)
2023-01-25_11:59:17.49143 at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:263)
2023-01-25_11:59:17.49143 at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035)
2023-01-25_11:59:17.49144 at groovy.lang.Closure.call(Closure.java:412)
2023-01-25_11:59:17.49144 at org.codehaus.groovy.runtime.ConvertedClosure.invokeCustom(ConvertedClosure.java:50)
2023-01-25_11:59:17.49145 at org.codehaus.groovy.runtime.ConversionHandler.invoke(ConversionHandler.java:110)
2023-01-25_11:59:17.49145 at com.sun.proxy.$Proxy216.apply(Unknown Source)
2023-01-25_11:59:17.49145 at io.reactivex.internal.operators.observable.ObservableMap$MapObserver.onNext(ObservableMap.java:57)
2023-01-25_11:59:17.49146 at io.reactivex.subjects.ReplaySubject$UnboundedReplayBuffer.replay(ReplaySubject.java:770)
2023-01-25_11:59:17.49146 at io.reactivex.subjects.ReplaySubject.onNext(ReplaySubject.java:352)
2023-01-25_11:59:17.49148 at org.grails.async.factory.rxjava2.RxPromise$1.onNext(RxPromise.groovy:73)
2023-01-25_11:59:17.49149 at io.reactivex.internal.observers.DeferredScalarDisposable.complete(DeferredScalarDisposable.java:82)
2023-01-25_11:59:17.49149 at io.reactivex.internal.operators.single.SingleToObservable$SingleToObservableObserver.onSuccess(SingleToObservable.java:72)
2023-01-25_11:59:17.49150 at io.reactivex.internal.operators.single.SingleSubscribeOn$SubscribeOnObserver.onSuccess(SingleSubscribeOn.java:68)
2023-01-25_11:59:17.49150 at io.reactivex.internal.operators.single.SingleCreate$Emitter.onSuccess(SingleCreate.java:67)
2023-01-25_11:59:17.49150 at org.grails.async.factory.rxjava2.RxPromise$_closure1.doCall(RxPromise.groovy:42)
2023-01-25_11:59:17.49151 at jdk.internal.reflect.GeneratedMethodAccessor606.invoke(Unknown Source)
2023-01-25_11:59:17.49151 at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:17.49152 at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2023-01-25_11:59:17.49153 at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107)
2023-01-25_11:59:17.49153 at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323)
2023-01-25_11:59:17.49155 at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:263)
2023-01-25_11:59:17.49156 at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035)
2023-01-25_11:59:17.49157 at groovy.lang.Closure.call(Closure.java:412)
2023-01-25_11:59:17.49157 at org.codehaus.groovy.runtime.ConvertedClosure.invokeCustom(ConvertedClosure.java:50)
2023-01-25_11:59:17.49157 at org.codehaus.groovy.runtime.ConversionHandler.invoke(ConversionHandler.java:110)
2023-01-25_11:59:17.49158 at com.sun.proxy.$Proxy213.subscribe(Unknown Source)
2023-01-25_11:59:17.49158 at io.reactivex.internal.operators.single.SingleCreate.subscribeActual(SingleCreate.java:39)
2023-01-25_11:59:17.49159 at io.reactivex.Single.subscribe(Single.java:3666)
2023-01-25_11:59:17.49159 at io.reactivex.internal.operators.single.SingleSubscribeOn$SubscribeOnObserver.run(SingleSubscribeOn.java:89)
2023-01-25_11:59:17.49160 at io.reactivex.Scheduler$DisposeTask.run(Scheduler.java:608)
2023-01-25_11:59:17.49160 at io.reactivex.internal.schedulers.ScheduledRunnable.run(ScheduledRunnable.java:66)
2023-01-25_11:59:17.49160 at io.reactivex.internal.schedulers.ScheduledRunnable.call(ScheduledRunnable.java:57)
2023-01-25_11:59:17.49161 at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
2023-01-25_11:59:17.49161 at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
2023-01-25_11:59:17.49163 at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
2023-01-25_11:59:17.49164 at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
2023-01-25_11:59:17.49164 at java.base/java.lang.Thread.run(Unknown Source)
2023-01-25_11:59:17.49164 Caused by: java.io.IOException: Authorization loop detected on Conduit "{http://schemas.dmtf.org/wbem/wsman/1/wsman.xsd}WinRmPort.http-conduit" on URL "http://10.27.4.6:5985/wsman" with realm "null"
2023-01-25_11:59:17.49165 at org.apache.cxf.transport.http.HTTPConduit.detectAuthorizationLoop(HTTPConduit.java:1949)
2023-01-25_11:59:17.49165 at org.apache.cxf.transport.http.HTTPConduit.access$600(HTTPConduit.java:150)
2023-01-25_11:59:17.49166 at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.authorizationRetransmit(HTTPConduit.java:1526)
2023-01-25_11:59:17.49167 at org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$AsyncWrappedOutputStream.authorizationRetransmit(AsyncHTTPConduit.java:827)
2023-01-25_11:59:17.49167 at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.processRetransmit(HTTPConduit.java:1461)
2023-01-25_11:59:17.49169 at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleRetransmits(HTTPConduit.java:1435)
2023-01-25_11:59:17.49170 at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1565)
2023-01-25_11:59:17.49170 at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1371)
2023-01-25_11:59:17.49170 at org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$AsyncWrappedOutputStream.close(AsyncHTTPConduit.java:429)
2023-01-25_11:59:17.49171 at io.cloudsoft.winrm4j.client.encryption.SignAndEncryptOutInterceptor$EncryptAndSignOutputStream.processAndShip(SignAndEncryptOutInterceptor.java:148)
2023-01-25_11:59:17.49171 at io.cloudsoft.winrm4j.client.encryption.SignAndEncryptOutInterceptor$EncryptAndSignOutputStream.close(SignAndEncryptOutInterceptor.java:84)
2023-01-25_11:59:17.49173 at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56)
2023-01-25_11:59:17.49173 at org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:671)
2023-01-25_11:59:17.49174 at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:63)
2023-01-25_11:59:17.49174 ... 110 common frames omitted
1:59:37.78353 '[2023-01-25 11:59:37,779] [RxCachedThreadScheduler-8] e[1;31mERRORe[0;39m e[36mc.m.RpcServicee[0;39m - Error Executing WinRM Command via JRuby Task: (WinRMAuthorizationError) WinRM::WinRMAuthorizationError
2023-01-25_11:59:37.78359 'org.jruby.exceptions.StandardError: (WinRMAuthorizationError) WinRM::WinRMAuthorizationError
2023-01-25_11:59:37.78359 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.http.response_handler.raise_if_auth_error(uri:classloader:/gems/winrm-2.3.4/lib/winrm/http/response_handler.rb:59)
2023-01-25_11:59:37.78359 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.http.response_handler.raise_if_error(uri:classloader:/gems/winrm-2.3.4/lib/winrm/http/response_handler.rb:51)
2023-01-25_11:59:37.78360 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.http.response_handler.parse_to_xml(uri:classloader:/gems/winrm-2.3.4/lib/winrm/http/response_handler.rb:34)
2023-01-25_11:59:37.78360 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.http.transport.send_request(uri:classloader:/gems/winrm-2.3.4/lib/winrm/http/transport.rb:186)
2023-01-25_11:59:37.78360 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.http.transport.send_request(uri:classloader:/gems/winrm-2.3.4/lib/winrm/http/transport.rb:181)
2023-01-25_11:59:37.78361 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.shells.power_shell.max_envelope_size_kb(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/power_shell.rb:153)
2023-01-25_11:59:37.78363 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.shells.power_shell.max_fragment_blob_size(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/power_shell.rb:78)
2023-01-25_11:59:37.78363 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.shells.power_shell.fragmenter(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/power_shell.rb:202)
2023-01-25_11:59:37.78363 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.shells.power_shell.open_shell_payload(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/power_shell.rb:166)
2023-01-25_11:59:37.78363 at org.jruby.RubyArray.map(org/jruby/RubyArray.java:2577)
2023-01-25_11:59:37.78364 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.shells.power_shell.open_shell_payload(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/power_shell.rb:163)
2023-01-25_11:59:37.78364 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.shells.power_shell.open_shell(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/power_shell.rb:123)
2023-01-25_11:59:37.78365 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.shells.base.open(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/base.rb:169)
2023-01-25_11:59:37.78365 at RUBY.retryable(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/retryable.rb:35)
2023-01-25_11:59:37.78365 at RUBY.open(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/base.rb:167)
2023-01-25_11:59:37.78365 at RUBY.with_command_shell(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/base.rb:128)
2023-01-25_11:59:37.78366 at RUBY.run(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/base.rb:79)
2023-01-25_11:59:37.78366 at RUBY.runCommand(jruby_winrm.rb:37)
2023-01-25_11:59:37.78366 at RUBY.shell(uri:classloader:/gems/winrm-2.3.4/lib/winrm/connection.rb:42)
2023-01-25_11:59:37.78366 at RUBY.runCommand(jruby_winrm.rb:36)
2023-01-25_11:59:37.78366 '[2023-01-25 11:59:37,780] [RxCachedThreadScheduler-8] e[1;31mERRORe[0;39m e[36mc.m.RpcServicee[0;39m - winrm4j also had an error attempting to connect: java.lang.IllegalStateException: Invalid credentials or incompatible authentication schemes
2023-01-25_11:59:37.78367 'java.lang.IllegalStateException: Invalid credentials or incompatible authentication schemes
2023-01-25_11:59:37.78367 at io.cloudsoft.winrm4j.client.RetryingProxyHandler.checkForRootErrorAuthorizationLoopAndPropagateAnnotated(RetryingProxyHandler.java:94)
2023-01-25_11:59:37.78368 at io.cloudsoft.winrm4j.client.RetryingProxyHandler.invokeWithRetry(RetryingProxyHandler.java:47)
2023-01-25_11:59:37.78368 at io.cloudsoft.winrm4j.client.RetryingProxyHandler.invoke(RetryingProxyHandler.java:31)
2023-01-25_11:59:37.78368 at com.sun.proxy.$Proxy269.create(Unknown Source)
2023-01-25_11:59:37.78369 at io.cloudsoft.winrm4j.client.WinRmClient.createShell(WinRmClient.java:540)
2023-01-25_11:59:37.78373 at io.cloudsoft.winrm4j.winrm.WinRmTool.executeCommand(WinRmTool.java:397)
2023-01-25_11:59:37.78373 at io.cloudsoft.winrm4j.winrm.WinRmTool.executePs(WinRmTool.java:422)
2023-01-25_11:59:37.78373 at io.cloudsoft.winrm4j.winrm.WinRmTool.executePs(WinRmTool.java:413)
2023-01-25_11:59:37.78374 at io.cloudsoft.winrm4j.winrm.WinRmTool$executePs.call(Unknown Source)
2023-01-25_11:59:37.78374 at com.morpheus.RpcService.executeWindowsCommand(RpcService.groovy:706)
2023-01-25_11:59:37.78374 at com.morpheus.RpcService.executeWindowsCommand(RpcService.groovy)
2023-01-25_11:59:37.78375 at com.morpheus.RpcService$executeWindowsCommand$5.call(Unknown Source)
2023-01-25_11:59:37.78376 at com.morpheus.provision.AbstractBoxProvisionService.executeContainerCommand(AbstractBoxProvisionService.groovy:2868)
2023-01-25_11:59:37.78376 at com.morpheus.provision.VmwareProvisionService.super$3$executeContainerCommand(VmwareProvisionService.groovy)
2023-01-25_11:59:37.78376 at jdk.internal.reflect.GeneratedMethodAccessor15905.invoke(Unknown Source)
2023-01-25_11:59:37.78376 at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:37.78377 at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2023-01-25_11:59:37.78377 at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107)
2023-01-25_11:59:37.78377 at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323)
2023-01-25_11:59:37.78377 at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1268)
2023-01-25_11:59:37.78378 at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodOnSuperN(ScriptBytecodeAdapter.java:144)
2023-01-25_11:59:37.78378 at com.morpheus.provision.VmwareProvisionService.executeContainerCommand(VmwareProvisionService.groovy:3241)
2023-01-25_11:59:37.78378 at com.morpheus.provision.VmwareProvisionService$executeContainerCommand$26.callCurrent(Unknown Source)
2023-01-25_11:59:37.78379 at com.morpheus.provision.AbstractBoxProvisionService.execContainer(AbstractBoxProvisionService.groovy:1680)
2023-01-25_11:59:37.78384 at com.morpheus.provision.AbstractBoxProvisionService.execContainer(AbstractBoxProvisionService.groovy)
2023-01-25_11:59:37.78384 at com.morpheus.provision.AbstractBoxProvisionService$execContainer$15.call(Unknown Source)
2023-01-25_11:59:37.78384 at com.morpheus.task.WinrmTaskService.executeContainerTask(WinrmTaskService.groovy:55)
2023-01-25_11:59:37.78385 at com.morpheus.task.ExecutableTaskInterface$executeContainerTask$0.call(Unknown Source)
2023-01-25_11:59:37.78385 at com.morpheus.task.TaskService.executeContainerTask(TaskService.groovy:343)
2023-01-25_11:59:37.78385 at com.morpheus.task.TaskService$executeContainerTask$10.call(Unknown Source)
2023-01-25_11:59:37.78385 at com.morpheus.provision.AbstractProvisionService.executeContainerTask(AbstractProvisionService.groovy:1785)
2023-01-25_11:59:37.78385 at com.morpheus.provision.AbstractProvisionService$executeContainerTask$28.call(Unknown Source)
2023-01-25_11:59:37.78385 at com.morpheus.ContainerService.executeContainerTask(ContainerService.groovy:1737)
2023-01-25_11:59:37.78386 at com.morpheus.ContainerService$executeContainerTask$58.call(Unknown Source)
2023-01-25_11:59:37.78387 at com.morpheus.InstanceService$_executeInstanceTask_closure205$_closure500$_closure501.doCall(InstanceService.groovy:4874)
2023-01-25_11:59:37.78387 at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2023-01-25_11:59:37.78387 at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:37.78387 at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:37.78387 at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2023-01-25_11:59:37.78388 at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107)
2023-01-25_11:59:37.78388 at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323)
2023-01-25_11:59:37.78388 at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:263)
2023-01-25_11:59:37.78388 at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035)
2023-01-25_11:59:37.78389 at groovy.lang.Closure.call(Closure.java:412)
2023-01-25_11:59:37.78389 at groovy.lang.Closure.call(Closure.java:428)
2023-01-25_11:59:37.78389 at org.grails.orm.hibernate.GrailsHibernateTemplate.doExecute(GrailsHibernateTemplate.java:297)
2023-01-25_11:59:37.78389 at org.grails.orm.hibernate.GrailsHibernateTemplate.execute(GrailsHibernateTemplate.java:241)
2023-01-25_11:59:37.78390 at org.grails.orm.hibernate.GrailsHibernateTemplate.executeWithNewSession(GrailsHibernateTemplate.java:153)
2023-01-25_11:59:37.78390 at org.grails.orm.hibernate.AbstractHibernateDatastore.withNewSession(AbstractHibernateDatastore.java:360)
2023-01-25_11:59:37.78390 at org.grails.orm.hibernate.AbstractHibernateGormStaticApi.withNewSession(AbstractHibernateGormStaticApi.groovy:78)
2023-01-25_11:59:37.78391 at org.grails.datastore.gorm.GormEntity$Trait$Helper.withNewSession(GormEntity.groovy:1027)
2023-01-25_11:59:37.78391 at org.grails.datastore.gorm.GormEntity$Trait$Helper$withNewSession.call(Unknown Source)
2023-01-25_11:59:37.78391 at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:47)
2023-01-25_11:59:37.78391 at org.grails.datastore.gorm.GormEntity$Trait$Helper$withNewSession.call(Unknown Source)
2023-01-25_11:59:37.78391 at com.morpheus.Container.withNewSession(Container.groovy)
2023-01-25_11:59:37.78391 at com.morpheus.Container$withNewSession$26.call(Unknown Source)
2023-01-25_11:59:37.78392 at com.morpheus.InstanceService$_executeInstanceTask_closure205$_closure500.doCall(InstanceService.groovy:4863)
2023-01-25_11:59:37.78392 at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2023-01-25_11:59:37.78393 at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:37.78393 at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:37.78393 at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2023-01-25_11:59:37.78393 at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107)
2023-01-25_11:59:37.78393 at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323)
2023-01-25_11:59:37.78393 at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:263)
2023-01-25_11:59:37.78394 at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035)
2023-01-25_11:59:37.78394 at groovy.lang.Closure.call(Closure.java:412)
2023-01-25_11:59:37.78394 at org.codehaus.groovy.runtime.ConvertedClosure.invokeCustom(ConvertedClosure.java:50)
2023-01-25_11:59:37.78394 at org.codehaus.groovy.runtime.ConversionHandler.invoke(ConversionHandler.java:110)
2023-01-25_11:59:37.78394 at com.sun.proxy.$Proxy216.apply(Unknown Source)
2023-01-25_11:59:37.78395 at io.reactivex.internal.operators.observable.ObservableMap$MapObserver.onNext(ObservableMap.java:57)
2023-01-25_11:59:37.78395 at io.reactivex.subjects.ReplaySubject$UnboundedReplayBuffer.replay(ReplaySubject.java:770)
2023-01-25_11:59:37.78395 at io.reactivex.subjects.ReplaySubject.onNext(ReplaySubject.java:352)
2023-01-25_11:59:37.78396 at org.grails.async.factory.rxjava2.RxPromise$1.onNext(RxPromise.groovy:73)
2023-01-25_11:59:37.78396 at io.reactivex.internal.observers.DeferredScalarDisposable.complete(DeferredScalarDisposable.java:82)
2023-01-25_11:59:37.78396 at io.reactivex.internal.operators.single.SingleToObservable$SingleToObservableObserver.onSuccess(SingleToObservable.java:72)
2023-01-25_11:59:37.78396 at io.reactivex.internal.operators.single.SingleSubscribeOn$SubscribeOnObserver.onSuccess(SingleSubscribeOn.java:68)
2023-01-25_11:59:37.78396 at io.reactivex.internal.operators.single.SingleCreate$Emitter.onSuccess(SingleCreate.java:67)
2023-01-25_11:59:37.78397 at org.grails.async.factory.rxjava2.RxPromise$_closure1.doCall(RxPromise.groovy:42)
2023-01-25_11:59:37.78397 at jdk.internal.reflect.GeneratedMethodAccessor606.invoke(Unknown Source)
2023-01-25_11:59:37.78397 at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:37.78397 at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2023-01-25_11:59:37.78397 at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107)
2023-01-25_11:59:37.78398 at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323)
2023-01-25_11:59:37.78398 at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:263)
2023-01-25_11:59:37.78399 at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035)
2023-01-25_11:59:37.78399 at groovy.lang.Closure.call(Closure.java:412)
2023-01-25_11:59:37.78399 at org.codehaus.groovy.runtime.ConvertedClosure.invokeCustom(ConvertedClosure.java:50)
2023-01-25_11:59:37.78399 at org.codehaus.groovy.runtime.ConversionHandler.invoke(ConversionHandler.java:110)
2023-01-25_11:59:37.78399 at com.sun.proxy.$Proxy213.subscribe(Unknown Source)
2023-01-25_11:59:37.78400 at io.reactivex.internal.operators.single.SingleCreate.subscribeActual(SingleCreate.java:39)
2023-01-25_11:59:37.78400 at io.reactivex.Single.subscribe(Single.java:3666)
2023-01-25_11:59:37.78400 at io.reactivex.internal.operators.single.SingleSubscribeOn$SubscribeOnObserver.run(SingleSubscribeOn.java:89)
2023-01-25_11:59:37.78400 at io.reactivex.Scheduler$DisposeTask.run(Scheduler.java:608)
2023-01-25_11:59:37.78400 at io.reactivex.internal.schedulers.ScheduledRunnable.run(ScheduledRunnable.java:66)
2023-01-25_11:59:37.78400 at io.reactivex.internal.schedulers.ScheduledRunnable.call(ScheduledRunnable.java:57)
2023-01-25_11:59:37.78401 at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
2023-01-25_11:59:37.78401 at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
2023-01-25_11:59:37.78402 at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
2023-01-25_11:59:37.78402 at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
2023-01-25_11:59:37.78402 at java.base/java.lang.Thread.run(Unknown Source)
2023-01-25_11:59:37.78402 Caused by: javax.xml.ws.WebServiceException: Could not send Message.
2023-01-25_11:59:37.78402 at org.apache.cxf.jaxws.JaxWsClientProxy.mapException(JaxWsClientProxy.java:183)
2023-01-25_11:59:37.78402 at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:145)
2023-01-25_11:59:37.78403 at com.sun.proxy.$Proxy268.create(Unknown Source)
2023-01-25_11:59:37.78403 at jdk.internal.reflect.GeneratedMethodAccessor19065.invoke(Unknown Source)
2023-01-25_11:59:37.78403 at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-01-25_11:59:37.78403 at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2023-01-25_11:59:37.78403 at io.cloudsoft.winrm4j.client.RetryingProxyHandler.invokeWithRetry(RetryingProxyHandler.java:44)
2023-01-25_11:59:37.78404 ... 98 common frames omitted
2023-01-25_11:59:37.78404 Caused by: java.io.IOException: Authorization loop detected on Conduit "{http://schemas.dmtf.org/wbem/wsman/1/wsman.xsd}WinRmPort.http-conduit" on URL "http://10.27.4.6:5985/wsman" with realm "null"
2023-01-25_11:59:37.78404 at org.apache.cxf.transport.http.HTTPConduit.detectAuthorizationLoop(HTTPConduit.java:1949)
2023-01-25_11:59:37.78405 at org.apache.cxf.transport.http.HTTPConduit.access$600(HTTPConduit.java:150)
2023-01-25_11:59:37.78405 at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.authorizationRetransmit(HTTPConduit.java:1526)
2023-01-25_11:59:37.78405 at org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$AsyncWrappedOutputStream.authorizationRetransmit(AsyncHTTPConduit.java:827)
2023-01-25_11:59:37.78405 at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.processRetransmit(HTTPConduit.java:1461)
2023-01-25_11:59:37.78406 at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleRetransmits(HTTPConduit.java:1435)
2023-01-25_11:59:37.78406 at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1565)
2023-01-25_11:59:37.78406 at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1371)
2023-01-25_11:59:37.78406 at org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$AsyncWrappedOutputStream.close(AsyncHTTPConduit.java:429)
2023-01-25_11:59:37.78407 at io.cloudsoft.winrm4j.client.encryption.SignAndEncryptOutInterceptor$EncryptAndSignOutputStream.processAndShip(SignAndEncryptOutInterceptor.java:148)
2023-01-25_11:59:37.78407 at io.cloudsoft.winrm4j.client.encryption.SignAndEncryptOutInterceptor$EncryptAndSignOutputStream.close(SignAndEncryptOutInterceptor.java:84)
2023-01-25_11:59:37.78407 at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56)
2023-01-25_11:59:37.78407 at org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:671)
2023-01-25_11:59:37.78408 at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:63)
2023-01-25_11:59:37.78408 at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308)
2023-01-25_11:59:37.78408 at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:530)
2023-01-25_11:59:37.78408 at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:441)
2023-01-25_11:59:37.78408 at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:356)
2023-01-25_11:59:37.78409 at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:314)
2023-01-25_11:59:37.78409 at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96)
2023-01-25_11:59:37.78410 at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:140)
2023-01-25_11:59:37.78410 ... 103 common frames omitted
2023-01-25_11:59:37.78410 '[2023-01-25 11:59:37,780] [RxCachedThreadScheduler-8] e[1;31mERRORe[0;39m e[36mc.m.RpcServicee[0;39m - winrmrb Error Detected: null
2023-01-25_11:59:37.78410 'org.jruby.exceptions.StandardError: (WinRMAuthorizationError) WinRM::WinRMAuthorizationError
2023-01-25_11:59:37.78410 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.http.response_handler.raise_if_auth_error(uri:classloader:/gems/winrm-2.3.4/lib/winrm/http/response_handler.rb:59)
2023-01-25_11:59:37.78410 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.http.response_handler.raise_if_error(uri:classloader:/gems/winrm-2.3.4/lib/winrm/http/response_handler.rb:51)
2023-01-25_11:59:37.78411 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.http.response_handler.parse_to_xml(uri:classloader:/gems/winrm-2.3.4/lib/winrm/http/response_handler.rb:34)
2023-01-25_11:59:37.78411 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.http.transport.send_request(uri:classloader:/gems/winrm-2.3.4/lib/winrm/http/transport.rb:186)
2023-01-25_11:59:37.78412 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.http.transport.send_request(uri:classloader:/gems/winrm-2.3.4/lib/winrm/http/transport.rb:181)
2023-01-25_11:59:37.78412 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.shells.power_shell.max_envelope_size_kb(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/power_shell.rb:153)
2023-01-25_11:59:37.78412 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.shells.power_shell.max_fragment_blob_size(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/power_shell.rb:78)
2023-01-25_11:59:37.78412 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.shells.power_shell.fragmenter(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/power_shell.rb:202)
2023-01-25_11:59:37.78413 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.shells.power_shell.open_shell_payload(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/power_shell.rb:166)
2023-01-25_11:59:37.78413 at org.jruby.RubyArray.map(org/jruby/RubyArray.java:2577)
2023-01-25_11:59:37.78414 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.shells.power_shell.open_shell_payload(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/power_shell.rb:163)
2023-01-25_11:59:37.78414 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.shells.power_shell.open_shell(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/power_shell.rb:123)
2023-01-25_11:59:37.78414 at uri_3a_classloader_3a_.gems.winrm_minus_2_dot_3_dot_4.lib.winrm.shells.base.open(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/base.rb:169)
2023-01-25_11:59:37.78414 at RUBY.retryable(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/retryable.rb:35)
2023-01-25_11:59:37.78414 at RUBY.open(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/base.rb:167)
2023-01-25_11:59:37.78415 at RUBY.with_command_shell(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/base.rb:128)
2023-01-25_11:59:37.78415 at RUBY.run(uri:classloader:/gems/winrm-2.3.4/lib/winrm/shells/base.rb:79)
2023-01-25_11:59:37.78415 at RUBY.runCommand(jruby_winrm.rb:37)
2023-01-25_11:59:37.78415 at RUBY.shell(uri:classloader:/gems/winrm-2.3.4/lib/winrm/connection.rb:42)
2023-01-25_11:59:37.78415 at RUBY.runCommand(jruby_winrm.rb:36)
2023-01-25_11:59:37.78416 '[2023-01-25 11:59:37,780] [RxCachedThreadScheduler-8] e[34mINFO e[0;39m e[36mc.m.t.WinrmTaskServicee[0;39m - results: [success:false, data:null, exitValue:null, error:null]
realm is null. I think like the link provided it’s a bad authentication occurring. Assuming you are using a domain user to connect? You probably need to be user@domain.com to get the login to pass. Also, local Administrator with domain joined systems I think gets blocked via winrm at times, but I don’t remember the exacts.
Again, the easiest and recommended way would be the agent, but if you continue to have problems with this please submit a ticket at support.morpheusdata.com
This is definitely a credential issue though based on those logs.
Thank you for your reply. I have checked the environment.
We are using the local user (which is setup in Morpheus User Settings) not domain account and the Windows VM provisioned is also not domain joined VM.
In such case, any other reason for this issue can be considered?
is the local user getting created (with the checkbox) at time of provision? Also, does the local user actually get WinRM permissions? The error is stating a bad user credential.