Slow deployement of Docker AppService

[blacelle]

Plugin name and version

<groupId>com.microsoft.azure</groupId>
                    <artifactId>azure-webapp-maven-plugin</artifactId>

Plugin configuration in your pom.xml

<!-- Azure Plugin will deploy given Docker container from AzureContainerRegistry (ACR) -->
                <plugin>
                    <groupId>com.microsoft.azure</groupId>
                    <artifactId>azure-webapp-maven-plugin</artifactId>
                    <configuration>
                        <authentication>
                            <serverId>azure-auth</serverId>
                        </authentication>

                        <!-- Disable telemetry as it reports "Failed to parse configuration file: 'unexpected element' ..." -->
                        <allowTelemetry>false</allowTelemetry>

                        <appServicePlanResourceGroup>${azure.env}-datasharing</appServicePlanResourceGroup>
                        <appServicePlanName>${azure.appServicePlanName}</appServicePlanName>

                        <resourceGroup>${azure.env}-XXX</resourceGroup>
                        <appName>${azure.appName}</appName>

                        <!-- https://github.com/Microsoft/azure-maven-plugins/tree/master/azure-webapp-maven-plugin#supported-regions -->
                        <region>francecentral</region>

                        <deploymentType>none</deploymentType>
                        <!-- subscriptionId for Datasharing -->
                        <subscriptionId>XXX</subscriptionId>

                        <!-- https://github.com/microsoft/azure-maven-plugins/issues/1183 -->
                        <schemaVersion>v1</schemaVersion>

                        <containerSettings>
                            <imageName>${docker.image.name}:${docker.tag}</imageName>
                            <registryUrl>https://${docker.repository.root}</registryUrl>
                            <serverId>${docker.repository.root}</serverId>
                        </containerSettings>
                        <appSettings>

                            <!-- Ensure environment variables are in upperCase -->
                            <!-- https://github.com/docker-library/openjdk/issues/135 -->
                            <!-- https://stackoverflow.com/questions/34178556/how-to-set-a-spring-boot-property-with-an-underscore-in-its-name-via-environment -->
                            <!-- https://docs.microsoft.com/en-us/azure/app-service/containers/app-service-linux-faq#custom-containers -->
                            <property>
                                <name>WEBSITES_PORT</name>
                                <value>${azure.port}</value>
                            </property>
                            <property>
                                <!-- https://stackoverflow.com/questions/38520638/how-to-set-spring-profile-from-system-variable -->
                                <!-- https://docs.spring.io/spring-boot/docs/current/reference/html/boot-features-profiles.html#boot-features-profiles -->
                                <name>SPRING_PROFILES_ACTIVE</name>
                                <value>${azure.spring.profiles.active}</value>
                            </property>
                            <property>
                                <!-- https://docs.microsoft.com/en-us/azure/app-service/containers/app-service-linux-faq -->
                                <name>WEBSITES_CONTAINER_START_TIME_LIMIT</name>
                                <!-- Default is 230 -->
                                <!-- Max is 1800, but 30 minutes might be too slow to wait for a retry -->
                                <!-- Sometimes, 180 is enough, sometimes not enough. A priori, it depends on colocated applications -->
                                <value>300</value>
                            </property>
                            <property>
                                <!-- We try to enforce CI as the webapp seems not restarted by default -->
                                <!-- Changing a property seems to trigger more CD mechanisms... -->
                                <name>BUILD_TIMESTAMP</name>
                                <value>${maven.build.timestamp}</value>
                            </property>

                            <property>
                                <name>MITRUST_ENV</name>
                                <value>${azure.env}</value>
                            </property>

                            <property>
                                <name>GIT_SHA1</name>
                                <value>${git.commit.id}</value>
                            </property>
                        </appSettings>
                        <!-- web.config refers to this with -Dlogback.configurationFile=XXX -->
                        <!-- <directory>${project.basedir}/src/main/resources/azure</directory> -->
                        <!-- <include>logback.xml</include> -->
                    </configuration>
                    <executions>
                        <!-- mvn azure-webapp:deploy -->
                        <execution>
                            <id>deployWebApp</id>
                            <phase>deploy</phase>
                            <goals>
                                <goal>deploy</goal>
                            </goals>
                        </execution>
                    </executions>
                </plugin>

Expected behavior

The deployment to be faster

Actual behavior

The deployement takes 3 minutes without logging, then 20 seconds with expressive logs. What's going on in these 3 minutes?

19:44:16,450 [INFO] --- azure-webapp-maven-plugin:1.12.0:deploy (deployWebApp) @ gateway ---
19:44:39,032 [WARNING] The POM for com.microsoft.azure.applicationinsights.v2015_05_01:azure-mgmt-insights:jar:1.0.0-beta is invalid, transitive dependencies (if any) will not be available, enable debug logging for more details
19:47:14,225 [INFO] 
19:47:14,225 [INFO] Data/Telemetry
19:47:14,226 [INFO] ---------
19:47:14,226 [INFO] This project collects usage data and sends it to Microsoft to help improve our products and services.
19:47:14,226 [INFO] Read Microsoft's privacy statement to learn more: https://privacy.microsoft.com/en-us/privacystatement.
19:47:14,226 [INFO] 
19:47:14,226 [INFO] You can change your telemetry configuration through 'allowTelemetry' property.
19:47:14,227 [INFO] For more information, please go to https://aka.ms/azure-maven-config.
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by com.microsoft.applicationinsights.core.dependencies.xstream.core.util.Fields (file:/home/circleci/.m2/repository/com/microsoft/azure/applicationinsights-core/2.6.1/applicationinsights-core-2.6.1.jar) to field java.util.TreeMap.comparator
WARNING: Please consider reporting this to the maintainers of com.microsoft.applicationinsights.core.dependencies.xstream.core.util.Fields
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
19:47:14,846 [WARNING] You are using an old way of authentication which will be deprecated in future versions, please change your configurations.
19:47:15,206 [INFO] Authenticate with ServerId: azure-auth
19:47:16,791 [INFO] [Correlation ID: 8675b6e6-0439-4476-a2ee-1570a5d025e1] Instance discovery was successful
19:47:17,386 [INFO] Subscription : Datasharing(fe92c0a9-f3ff-4a8d-8fbd-7d47cc72992c)
19:47:21,462 [INFO] Updating target Web App...
19:47:31,948 [INFO] Successfully updated Web App.
19:47:34,216 [INFO] Skip deployment.

[andxu]

Investigating on this strange problem, will post the result later