Bug 65251

Summary: Child name [/app1] is not unique after upgrading 9.0.44
Product: Tomcat 9 Reporter: abhishekm
Component: ManagerAssignee: Tomcat Developers Mailing List <dev>
Status: RESOLVED FIXED    
Severity: critical    
Priority: P2    
Version: 9.0.44   
Target Milestone: -----   
Hardware: Other   
OS: Linux   
Attachments: server.xml

Description abhishekm 2021-04-19 21:43:21 UTC
Created attachment 37817 [details]
server.xml

Hello,

We have been using following command to deploy an app, say app1, for multiple "example.com" hosts on the same Tomcat instance hosted on a machine.

wget --connect-timeout=60 --http-user=$TC_MGR_USERNAME --http-password=$TC_MGR_PASSWORD --no-check-certificate --header='Host: $hostname' 'https://$ip_address/mgr/text/deploy?war=file:$WAR&path=/app1&update=true' -O -

After upgrading to Tomcat 9.0.44, we are seeing the following error consistently, preventing app1 to start normally. We have been using the same command since Tomcat 8.x versions without any issue and nothing has changed at our end.

15-Apr-2021 14:46:58.852 INFO [ajp-nio-127.0.0.1-8009-exec-27] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/usr/sites/x.example.com/tomcatweb/app1.war]
15-Apr-2021 14:46:58.860 INFO [Catalina-utility-1] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/usr/sites/x.example.com/tomcatweb/app1.war]
15-Apr-2021 14:46:58.861 SEVERE [Catalina-utility-1] org.apache.catalina.startup.HostConfig.deployWAR Error deploying web application archive [/usr/sites/x.example.com/tomcatweb/app1.war]
        java.lang.IllegalArgumentException: Child name [/app1] is not unique
                at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:703)
                at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:690)
                at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:706)
                at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:1023)
                at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1903)
                at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
                at java.util.concurrent.FutureTask.run(FutureTask.java:266)
                at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
                at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:112)
                at org.apache.catalina.startup.HostConfig.deployWARs(HostConfig.java:824)
                at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:474)
                at org.apache.catalina.startup.HostConfig.check(HostConfig.java:1660)
                at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:315)
                at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123)
                at org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1151)
                at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1353)
                at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1357)
                at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1335)
                at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
                at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
                at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
                at java.lang.Thread.run(Thread.java:748)
15-Apr-2021 14:46:58.861 INFO [Catalina-utility-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/usr/sites/x.example.com/tomcatweb/app1.war] has finished in [1] ms


I have attached server.xml for your reference which has multiple hosts, each host has multiple apps. Our Java deployer utility calls 'https://$ip_address/mgr/text/deploy?war=file:$WAR&path=/$app&update=true' command on different hosts for same app, app1, at the same time using multiple threads. 

The change log for Tomcat 9.0.44 https://tomcat.apache.org/tomcat-9.0-doc/changelog.html mentions "Remove the restriction that prevented the Manager web application deploying different web applications in parallel. (markt)". Even though we do not use parallel deployment(no version passed in command line), we suspect the changes here https://github.com/apache/tomcat/pull/403 might have caused the issue above.

Environment details:
CentOS Linux release 7.9.2009 (Core)
openjdk version "1.8.0_282"
OpenJDK Runtime Environment (build 1.8.0_282-b08)
OpenJDK 64-Bit Server VM (build 25.282-b08, mixed mode)

Any help would be appreciated.

Thank you!
Comment 1 Mark Thomas 2021-04-20 09:04:48 UTC
Thanks for the report.

It appears that both the deploy thread and the background processing thread are trying to deploy the updated WAR file. There is code that is meant to prevent that. I've found a bug in that code that allows me to recreate the stacktrace you reported. I am working on a fix.

To be sure I have found the same error you are seeing, can you clarify what you mean by "preventing app1 to start normally"?

In my testing when the two threads attempt to start the updated application, one of those threads succeeds and one fails. The app does start. To put it another way, the bug just causes an ugly stack trace in the logs, it doesn't prevent the deployment from completing nor does it break the application. Are you seeing the same?

A potential workaround would be to disable automatic deployment (autoDeploy="false" on the Host). If you are doing all your deployments via the Manager then you might want to do this anyway for the security benefits (an arbitrary file upload vulnerability can't be leveraged into RCE).
Comment 2 Mark Thomas 2021-04-20 11:15:19 UTC
Fixed in:
- 10.0.x for 10.0.6 onwards
- 9.0.x for 9.0.46 onwards
- 8.5.x for 8.5.66 onwards

Feel free to re-open if the issue you found isn't the one I've just fixed.
Comment 3 abhishekm 2021-04-20 13:52:12 UTC
(In reply to Mark Thomas from comment #1)
> Thanks for the report.
> 
> It appears that both the deploy thread and the background processing thread
> are trying to deploy the updated WAR file. There is code that is meant to
> prevent that. I've found a bug in that code that allows me to recreate the
> stacktrace you reported. I am working on a fix.
> 
> To be sure I have found the same error you are seeing, can you clarify what
> you mean by "preventing app1 to start normally"?
> 
> In my testing when the two threads attempt to start the updated application,
> one of those threads succeeds and one fails. The app does start. To put it
> another way, the bug just causes an ugly stack trace in the logs, it doesn't
> prevent the deployment from completing nor does it break the application.
> Are you seeing the same?
> 
> A potential workaround would be to disable automatic deployment
> (autoDeploy="false" on the Host). If you are doing all your deployments via
> the Manager then you might want to do this anyway for the security benefits
> (an arbitrary file upload vulnerability can't be leveraged into RCE).

When we saw "Child name [/app1] is not unique" and visited `app1` web page, we saw following error. It seems one of the war attempts was successful but the application did not start normally. Our context.xml defines database resources.

javax.naming.NameNotFoundException: Name [comp/env] is not bound in this Context. Unable to find [comp].
	org.apache.naming.NamingContext.lookup(NamingContext.java:833)
	org.apache.naming.NamingContext.lookup(NamingContext.java:174)
	org.apache.naming.SelectorContext.lookup(SelectorContext.java:163)
	javax.naming.InitialContext.lookup(InitialContext.java:417)