Intermittent failures when deploying to WebLogic 12.1.2

[atijms]

Using the currently latest published WebLogic remote container in combination with a local WebLogic 12.1.2 (the developer unzip version), I get intermittent deployment failures.

Several deployments go right, then suddenly one fails and they often keep failing until I restart WebLogic. When deploying to GlassFish 3 embedded, GlassFish 4 managed and JBoss EAP 6.1 managed the exact same project does have any deployment issues.

Excerpt of the log when deployments start failing:

INFO: Starting weblogic.Deployer to deploy the test artifact.
Aug 10, 2013 3:13:16 PM org.jboss.arquillian.container.wls.WebLogicDeployerClient forkWebLogicDeployer
WARNING: weblogic.Deployer terminated abnormally with exit code 1
Aug 10, 2013 3:13:16 PM org.jboss.arquillian.container.wls.WebLogicDeployerClient forkWebLogicDeployer
INFO: The output of the weblogic.Deployer process was:
 weblogic.Deployer invoked with options:  -adminurl t3://localhost:7001 -username admin -deploy -name register-session-simple -source /var/folders/lb/tt__r4nd2ldgfvhwkfqrzyh00000gn/T/arquillian2515620436439273675register-session-simple.war/register-session-simple.war -targets myserver -upload -debug
[WebLogicDeploymentManagerImpl.<init>():119] : Constructing DeploymentManager for J2EE version V1_4 deployments
[WebLogicDeploymentManagerImpl.getNewConnection():162] : Connecting to admin server at localhost:7001, as user admin
[ServerConnectionImpl.getEnvironment():295] : setting environment
[ServerConnectionImpl.getEnvironment():298] : getting context using t3://localhost:7001
[ServerConnectionImpl.getMBeanServer():246] : Connecting to MBeanServer at service:jmx:t3://localhost:7001/jndi/weblogic.management.mbeanservers.domainruntime
[ServerConnectionImpl.getMBeanServer():246] : Connecting to MBeanServer at service:jmx:t3://localhost:7001/jndi/weblogic.management.mbeanservers.runtime
[DomainManager.resetDomain():36] : Getting new domain
[DomainManager.resetDomain():39] : Using pending domain: false
[MBeanCache.addNotificationListener():96] : Adding notification listener for weblogic.deploy.api.spi.deploy.mbeans.TargetCache@85138d9
[MBeanCache.addNotificationListener():103] : Added notification listener for weblogic.deploy.api.spi.deploy.mbeans.TargetCache@85138d9
[MBeanCache.addNotificationListener():96] : Adding notification listener for weblogic.deploy.api.spi.deploy.mbeans.ModuleCache@a5e2f1d
[MBeanCache.addNotificationListener():103] : Added notification listener for weblogic.deploy.api.spi.deploy.mbeans.ModuleCache@a5e2f1d
[ServerConnectionImpl.initialize():178] : Connected to WLS domain: mydomain
[ServerConnectionImpl.setRemote():489] : Running in remote mode
[ServerConnectionImpl.init():168] : Initializing ServerConnection : weblogic.deploy.api.spi.deploy.internal.ServerConnectionImpl@6762a5f3
[BasicOperation.dumpTmids():740] : Incoming tmids:
[BasicOperation.dumpTmids():742] :   {Target=myserver, WebLogicTargetType=server, Name=register-session-simple}, targeted=true
[BasicOperation.deriveAppName():143] : appname established as: register-session-simple
<Aug 10, 2013 3:13:16 PM CEST> <Info> <J2EE Deployment SPI> <BEA-260121> <Initiating deploy operation for application, register-session-simple [archive: /var/folders/lb/tt__r4nd2ldgfvhwkfqrzyh00000gn/T/arquillian2515620436439273675register-session-simple.war/register-session-simple.war], to myserver .> 
[BasicOperation.dumpTmids():740] : Incoming tmids:
[BasicOperation.dumpTmids():742] :   {Target=myserver, WebLogicTargetType=server, Name=register-session-simple}, targeted=true
[BasicOperation.loadGeneralOptions():655] : Delete Files:false
Timeout :3600000
Targets: 
myserver
ModuleTargets={}
SubModuleTargets={}
}
Files: 
null
Deployment Plan: null
App root: /var/folders/lb/tt__r4nd2ldgfvhwkfqrzyh00000gn/T/arquilliantest/./config/deployments/register-session-simple
App config: /var/folders/lb/tt__r4nd2ldgfvhwkfqrzyh00000gn/T/arquilliantest/./config/deployments/register-session-simple/plan
Deployment Options: {isRetireGracefully=true,isGracefulProductionToAdmin=false,isGracefulIgnoreSessions=false,rmiGracePeriod=-1,retireTimeoutSecs=-1,undeployAllVersions=false,archiveVersion=null,planVersion=null,isLibrary=false,libSpecVersion=null,libImplVersion=null,stageMode=null,clusterTimeout=3600000,altDD=null,altWlsDD=null,name=register-session-simple,securityModel=null,securityValidationEnabled=false,versionIdentifier=null,isTestMode=false,forceUndeployTimeout=0,defaultSubmoduleTargets=true,timeout=0,deploymentPrincipalName=null,useExpiredLock=falsespecifiedTargetsOnly=false}

[ServerConnectionImpl.upload():862] : Uploaded app to <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Draft//EN">
[BasicOperation.execute():472] : Initiating deploy operation for app, register-session-simple, on targets:
[BasicOperation.execute():474] :    myserver
weblogic.management.ManagementException: [Deployer:149003]Unable to access application source information in "<!DOCTYPE HTML PUBLIC "-/W3C/DTD HTML 4.0 Draft/EN">/app/register-session-simple.war" for application "register-session-simple". The specific error is: No application files exist.
          at weblogic.deploy.internal.adminserver.operations.OperationHelper.validateSource(OperationHelper.java:357)
          at weblogic.deploy.internal.adminserver.operations.OperationHelper.getArchiveVersionIdFromSource(OperationHelper.java:167)
          at weblogic.deploy.internal.adminserver.operations.OperationHelper.getAndValidateVersionIdWithSrc(OperationHelper.java:205)
          at weblogic.deploy.internal.adminserver.operations.ActivateOperation.updateConfiguration(ActivateOperation.java:49)
          at weblogic.deploy.internal.adminserver.operations.DeployOperation.updateConfiguration(DeployOperation.java:35)
          at weblogic.deploy.internal.adminserver.operations.AbstractOperation.updateConfigurationAndInitializeDeployment(AbstractOperation.java:401)
          at weblogic.deploy.internal.adminserver.operations.AbstractOperation.execute(AbstractOperation.java:242)
          at weblogic.management.deploy.internal.DeployerRuntimeImpl$2.run(DeployerRuntimeImpl.java:846)
          at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
          at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:120)
          at weblogic.management.deploy.internal.DeployerRuntimeImpl.performDeployerActions(DeployerRuntimeImpl.java:840)
          at weblogic.management.deploy.internal.DeployerRuntimeImpl.deploy(DeployerRuntimeImpl.java:418)
          at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
          at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
          at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
          at java.lang.reflect.Method.invoke(Method.java:601)
          at weblogic.management.jmx.modelmbean.WLSModelMBean.invoke(WLSModelMBean.java:437)
          at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819)
          at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:791)
          at weblogic.management.mbeanservers.domainruntime.internal.FederatedMBeanServerInterceptor.invoke(FederatedMBeanServerInterceptor.java:375)
          at weblogic.management.jmx.mbeanserver.WLSMBeanServerInterceptorBase$16.run(WLSMBeanServerInterceptorBase.java:449)
          at java.security.AccessController.doPrivileged(Native Method)
          at weblogic.management.jmx.mbeanserver.WLSMBeanServerInterceptorBase.invoke(WLSMBeanServerInterceptorBase.java:447)
          at weblogic.management.mbeanservers.internal.JMXContextInterceptor.invoke(JMXContextInterceptor.java:263)
          at weblogic.management.jmx.mbeanserver.WLSMBeanServerInterceptorBase$16.run(WLSMBeanServerInterceptorBase.java:449)
          at java.security.AccessController.doPrivileged(Native Method)
          at weblogic.management.jmx.mbeanserver.WLSMBeanServerInterceptorBase.invoke(WLSMBeanServerInterceptorBase.java:447)
          at weblogic.management.mbeanservers.internal.SecurityMBeanMgmtOpsInterceptor.invoke(SecurityMBeanMgmtOpsInterceptor.java:65)
          at weblogic.management.jmx.mbeanserver.WLSMBeanServerInterceptorBase$16.run(WLSMBeanServerInterceptorBase.java:449)
          at java.security.AccessController.doPrivileged(Native Method)
          at weblogic.management.jmx.mbeanserver.WLSMBeanServerInterceptorBase.invoke(WLSMBeanServerInterceptorBase.java:447)
          at weblogic.management.mbeanservers.internal.SecurityInterceptor.invoke(SecurityInterceptor.java:444)
          at weblogic.management.jmx.mbeanserver.WLSMBeanServer.invoke(WLSMBeanServer.java:323)
          at weblogic.management.mbeanservers.internal.JMXConnectorSubjectForwarder$11$1.run(JMXConnectorSubjectForwarder.java:664)
          at java.security.AccessController.doPrivileged(Native Method)
          at weblogic.management.mbeanservers.internal.JMXConnectorSubjectForwarder$11.run(JMXConnectorSubjectForwarder.java:662)
          at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:363)
          at weblogic.management.mbeanservers.internal.JMXConnectorSubjectForwarder.invoke(JMXConnectorSubjectForwarder.java:655)
          at javax.management.remote.rmi.RMIConnectionImpl.doOperation(RMIConnectionImpl.java:1447)
          at javax.management.remote.rmi.RMIConnectionImpl.access$200(RMIConnectionImpl.java:89)
          at javax.management.remote.rmi.RMIConnectionImpl$PrivilegedOperation.run(RMIConnectionImpl.java:1292)
          at java.security.AccessController.doPrivileged(Native Method)
          at javax.management.remote.rmi.RMIConnectionImpl.doPrivilegedOperation(RMIConnectionImpl.java:1387)
          at javax.management.remote.rmi.RMIConnectionImpl.invoke(RMIConnectionImpl.java:812)
          at javax.management.remote.rmi.RMIConnectionImpl_WLSkel.invoke(Unknown Source)
          at weblogic.rmi.internal.BasicServerRef.invoke(BasicServerRef.java:693)
          at weblogic.rmi.internal.BasicServerRef$1.run(BasicServerRef.java:519)
          at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:363)
          at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:146)
          at weblogic.rmi.internal.BasicServerRef.handleRequest(BasicServerRef.java:515)
          at weblogic.rmi.internal.wls.WLSExecuteRequest.run(WLSExecuteRequest.java:118)
          at weblogic.work.ExecuteThread.execute(ExecuteThread.java:295)
          at weblogic.work.ExecuteThread.run(ExecuteThread.java:254)
[ServerConnectionImpl.close():341] : Closing DM connection
[ServerConnectionImpl.close():361] : Unregistered all listeners
[ServerConnectionImpl.closeJMX():381] : Closed JMX connection
[ServerConnectionImpl.closeJMX():393] : Closed Runtime JMX connection
[ServerConnectionImpl.closeJMX():405] : Closed Edit JMX connection

[vineet.reynolds]

Well, this is a bit irritating to experience as a user. Going by the debug info it is similar to some weird behavior I remember noticing when I originally wrote the adapter. I never really drilled down the root cause, since there was nothing in the deployment that triggered it. It was all down to some timing (?) issue in the weblogic.Deployer process.

But, to be honest, I'm more concerned if the adapter reported back with a failed deployment - this is the rationale behind the WARNING level log message instead of a FATAL/ERROR level message. I designed the adapter to not fail immediately on a weblogic.Deployer failure; there were instances were the deployer indicated a failure via the process exit code, but the app had successfully deployed (that's why there is some timing issue at play here). The adapter only marks a deployment as failed when the JMX client it later uses to query the AdminServer about the deployment, does not find the deployment in a running state. So if you're seeing these errors from weblogic.Deployer, but no failing tests, you can ignore these, since the adapter did indeed notice that the deployment had not failed.

If you however see test failures due to failed deployments, I could help reduce the frequency of this by introducing a user-configurable flag to attempt another redeployment if the first one failed. I dont foresee any other way, since the best we could do this is to pass the weblogic.Deployer process with options that could prevent it, and I don't see any.

If possible, can this issue be raised in MOS (My Oracle Support). I'll also see if I can forward this to someone who could possibly comment on this.

[atijms]

Again sorry for the late reply as I have been totally occupied by a myriad of other things.

I unfortunately can't raise the issue with MOS, as I'm not really a WebLogic user. I'm just a developer creating a test suite for JASPIC (https://github.com/arjantijms/jaspic-capabilities-test) which should support as many Java EE implementations as possible.

But one of the WebLogic developers did mention a patch for the Arquillian WLS remote container. This was a while back and I unfortunately missed the message back then, but I'll ask about it again.