问题描述

App Service for Linux 资源创建完成后，通过FTP方式把 .jar包（logdemo.jar）包上传到 /site/wwwroot/ 文件夹后，在App Service的Configration 配置页面配置启动命令为：

java -jar /site/wwwroot/logdemo.jar

但是，在访问App Service时，却是 Application Error 错误（503 Service Temporarily Unavailable）

问题解决

第一步：查看日志

进入App Service的Kudu站点(https://<your app service name>.scm.chinacloudsites.cn/DebugConsole)，查看Log Stream，检查错误日志

第二步：分析错误信息

2022-02-19T08:55:59.035870757Z Add private certificates to keystore if exists...2022-02-19T08:55:59.035875157Z Configuring max heap = 1346 MB2022-02-19T08:55:59.076047416Z STARTUP_FILE=2022-02-19T08:55:59.076713522Z STARTUP_COMMAND=java -jar /site/wwwroot/logdemo.jar2022-02-19T08:55:59.076729422Z No STARTUP_FILE available.2022-02-19T08:55:59.085391200Z Running STARTUP_COMMAND: java -jar /site/wwwroot/logdemo.jar2022-02-19T08:55:59.087846422Z Error: Unable to access jarfile /site/wwwroot/logdemo.jar2022-02-19T08:55:59.095872294Z Finished running startup file \'java -jar /site/wwwroot/logdemo.jar\'. Exit code: \'1\'.2022-02-19T08:55:59.115095866Z Custom startup complete. Now, exiting with exit code \'1\'/home/LogFiles/2022_02_19_lw0sdlwk00005J_docker.log  (https://xxxxx.scm.chinacloudsites.cn/api/vfs/LogFiles/2022_02_19_lw0sdlwk00005J_docker.log)2022-02-19T08:55:49.578Z INFO  - Pull Image successful, Time taken: 0 Minutes and 0 Seconds2022-02-19T08:55:49.659Z INFO  - Starting container for site2022-02-19T08:55:49.660Z INFO  - docker run -d -p 8080:8080 --name lbjavainlinux_0_2fbcc321 -e PORT=8080 -e WEBSITE_SITE_NAME=lbjavainlinux -e WEBSITE_AUTH_ENABLED=False -e WEBSITE_ROLE_INSTANCE_ID=0 -e WEBSITE_HOSTNAME=lbjavainlinux.chinacloudsites.cn -e WEBSITE_INSTANCE_ID=f902a04a85d38b0fa81789a73bd7f0fd35ab4400956424760d2a2f982ef05b43 mcr.microsoft.com/azure-app-service/java:8-jre8_210526002747 java -jar /site/wwwroot/logdemo.jar2022-02-19T08:55:49.660Z INFO  - Logging is not enabled for this container.Please use https://aka.ms/linux-diagnostics to enable logging to see container logs here.2022-02-19T08:55:58.101Z INFO  - Initiating warmup request to container lbjavainlinux_0_2fbcc321 for site lbjavainlinux2022-02-19T08:55:59.460Z ERROR - Container lbjavainlinux_0_2fbcc321 for site lbjavainlinux has exited, failing site start2022-02-19T08:55:59.467Z ERROR - Container lbjavainlinux_0_2fbcc321 didn\'t respond to HTTP pings on port: 8080, failing site start. See container logs for debugging.2022-02-19T08:55:59.497Z INFO  - Stopping site lbjavainlinux because it failed during startup.

日志显示，不能访问jar文件/site/wwwroot/logdemo.jar, 所以站点无法启动。但是通过Kudu Bash查看App Service的文件，发现logdemo.jar文件时存在的：

所以问题根源就是 App Service的Java应用启动命令中，jar包路径配置错误。正确的启动命令为：

java -jar /home/site/wwwroot/logdemo.jar

PS: 因为通过FTP工具显示的文件根路径就是/，并没有/home/显示，所以在Linux环境中，极易忽略home而导致以上错误。

第三步：问题解决，查看日志启动成功

/home/LogFiles/2022_02_19_lw0sdlwk00005J_docker.log  (https://lbjavainlinux.scm.chinacloudsites.cn/api/vfs/LogFiles/2022_02_19_lw0sdlwk00005J_docker.log)2022-02-19T09:11:02.556Z INFO  - 8-jre8_210526002747 Pulling from azure-app-service/java2022-02-19T09:11:02.557Z INFO  -  Digest: sha256:b26811cc1b99fc7cfa7485d2313da3abbf0f96f742961908ee7da07ef489ddc62022-02-19T09:11:02.557Z INFO  -  Status: Image is up to date for mcr.microsoft.com/azure-app-service/java:8-jre8_2105260027472022-02-19T09:11:02.565Z INFO  - Pull Image successful, Time taken: 0 Minutes and 0 Seconds2022-02-19T09:11:02.617Z INFO  - Starting container for site2022-02-19T09:11:02.617Z INFO  - docker run -d -p 8080:8080 --name lbjavainlinux_0_ffad47c9 -e PORT=8080 -e WEBSITE_SITE_NAME=lbjavainlinux -e WEBSITE_AUTH_ENABLED=False -e WEBSITE_ROLE_INSTANCE_ID=0 -e WEBSITE_HOSTNAME=lbjavainlinux.chinacloudsites.cn -e WEBSITE_INSTANCE_ID=f902a04a85d38b0fa81789a73bd7f0fd35ab4400956424760d2a2f982ef05b43 mcr.microsoft.com/azure-app-service/java:8-jre8_210526002747 java -jar /home/site/wwwroot/logdemo.jar2022-02-19T09:11:02.637Z INFO  - Logging is not enabled for this container.Please use https://aka.ms/linux-diagnostics to enable logging to see container logs here.2022-02-19T09:11:08.645Z INFO  - Initiating warmup request to container lbjavainlinux_0_ffad47c9 for site lbjavainlinux/home/LogFiles/webssh/.log  (https://lbjavainlinux.scm.chinacloudsites.cn/api/vfs/LogFiles/webssh/.log)Ending Log Tail of existing logs ---Starting Live Log Stream ---2022-02-19T09:11:08.645Z INFO  - Initiating warmup request to container lbjavainlinux_0_ffad47c9 for site lbjavainlinux2022-02-19 09:11:22.559  INFO 125 --- [main] com.example.App                          : Starting App v1.0-SNAPSHOT on f60af282340b with PID 125 (/home/site/wwwroot/logdemo.jar started by root in /)2022-02-19 09:11:23.022  INFO 125 --- [main] ationConfigEmbeddedWebApplicationContext : Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@447d90dd: startup date [Sat Feb 19 09:11:23 GMT 2022]; root of context hierarchy2022-02-19 09:11:29.200  INFO 125 --- [main] o.s.b.f.s.DefaultListableBeanFactory     : Overriding bean definition for bean \'beanNameViewResolver\': replacing [Root bean: class [null]; scope=; abstract=false; lazyInit=false; autowireMode=3; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=org.springframework.boot.autoconfigure.web.ErrorMvcAutoConfiguration$WhitelabelErrorViewConfiguration; factoryMethodName=beanNameViewResolver; initMethodName=null; destroyMethodName=(inferred); defined in class path resource [org/springframework/boot/autoconfigure/web/ErrorMvcAutoConfiguration$WhitelabelErrorViewConfiguration.class]] with [Root bean: class [null]; scope=; abstract=false; lazyInit=false; autowireMode=3; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=org.springframework.boot.autoconfigure.web.WebMvcAutoConfiguration$WebMvcAutoConfigurationAdapter; factoryMethodName=beanNameViewResolver; initMethodName=null; destroyMethodName=(inferred); defined in class path resource [org/springframework/boot/autoconfigure/web/WebMvcAutoConfiguration$WebMvcAutoConfigurationAdapter.class]]2022-02-19 09:11:32.370  INFO 125 --- [main] trationDelegate$BeanPostProcessorChecker : Bean \'org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration\' of type [class org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration$$EnhancerBySpringCGLIB$$b749a166] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2022-02-19 09:11:32.721  INFO 125 --- [main] trationDelegate$BeanPostProcessorChecker : Bean \'transactionAttributeSource\' of type [class org.springframework.transaction.annotation.AnnotationTransactionAttributeSource] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2022-02-19 09:11:32.842  INFO 125 --- [main] trationDelegate$BeanPostProcessorChecker : Bean \'transactionInterceptor\' of type [class org.springframework.transaction.interceptor.TransactionInterceptor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2022-02-19 09:11:32.903  INFO 125 --- [main] trationDelegate$BeanPostProcessorChecker : Bean \'org.springframework.transaction.config.internalTransactionAdvisor\' of type [class org.springframework.transaction.interceptor.BeanFactoryTransactionAttributeSourceAdvisor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2022-02-19 09:11:37.004  INFO 125 --- [main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat initialized with port(s): 8080 (http)2022-02-19T09:11:40.611Z INFO  - Waiting for response to warmup request for container lbjavainlinux_0_ffad47c9. Elapsed time = 31.9663615 sec2022-02-19 09:11:40.594  INFO 125 --- [main] o.apache.catalina.core.StandardService   : Starting service Tomcat2022-02-19 09:11:40.633  INFO 125 --- [main] org.apache.catalina.core.StandardEngine  : Starting Servlet Engine: Apache Tomcat/8.0.282022-02-19 09:11:41.800  INFO 125 --- [localhost-startStop-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext2022-02-19 09:11:41.819  INFO 125 --- [localhost-startStop-1] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 18816 ms2022-02-19 09:11:48.263  INFO 125 --- [localhost-startStop-1] o.s.b.c.e.ServletRegistrationBean        : Mapping servlet: \'dispatcherServlet\' to [/]2022-02-19 09:11:48.295  INFO 125 --- [localhost-startStop-1] o.s.b.c.embedded.FilterRegistrationBean  : Mapping filter: \'characterEncodingFilter\' to: [/*]2022-02-19 09:11:48.304  INFO 125 --- [localhost-startStop-1] o.s.b.c.embedded.FilterRegistrationBean  : Mapping filter: \'hiddenHttpMethodFilter\' to: [/*]2022-02-19 09:11:51.478  INFO 125 --- [main] s.w.s.m.m.a.RequestMappingHandlerAdapter : Looking for @ControllerAdvice: org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@447d90dd: startup date [Sat Feb 19 09:11:23 GMT 2022]; root of context hierarchy2022-02-19 09:11:52.406  INFO 125 --- [main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped \"{[/]}\" onto java.lang.String com.example.HelloController.hello()2022-02-19 09:11:52.412  INFO 125 --- [main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped \"{[/newhello]}\" onto java.lang.String com.example.HelloController.hello2()2022-02-19 09:11:52.422  INFO 125 --- [main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped \"{[/error],produces=[text/html]}\" onto public org.springframework.web.servlet.ModelAndView org.springframework.boot.autoconfigure.web.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest)2022-02-19 09:11:52.435  INFO 125 --- [main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped \"{[/error]}\" onto public org.springframework.http.ResponseEntity<java.util.Map<java.lang.String, java.lang.Object>> org.springframework.boot.autoconfigure.web.BasicErrorController.error(javax.servlet.http.HttpServletRequest)2022-02-19 09:11:52.666  INFO 125 --- [main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/webjars/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]2022-02-19 09:11:52.684  INFO 125 --- [main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]2022-02-19 09:11:53.066  INFO 125 --- [main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/**/favicon.ico] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]2022-02-19T09:11:55.939Z INFO  - Waiting for response to warmup request for container lbjavainlinux_0_ffad47c9. Elapsed time = 47.2941072 sec2022-02-19 09:11:55.146  INFO 125 --- [main] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup2022-02-19 09:11:55.950  INFO 125 --- [main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat started on port(s): 8080 (http)2022-02-19 09:11:56.000  INFO 125 --- [main] com.example.App                          : Started App in 35.854 seconds (JVM running for 40.855)2022-02-19 09:11:56.002  INFO 125 --- [main] com.example.App                          : test java logs  : info2022-02-19 09:11:56.010 ERROR 125 --- [main] com.example.App                          : test java logs  : error2022-02-19 09:11:56.012  WARN 125 --- [main] com.example.App                          : test java logs  : warn2022-02-19 09:11:56.409  INFO 125 --- [http-nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring FrameworkServlet \'dispatcherServlet\'2022-02-19 09:11:56.413  INFO 125 --- [http-nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : FrameworkServlet \'dispatcherServlet\': initialization started2022-02-19 09:11:56.545  INFO 125 --- [http-nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : FrameworkServlet \'dispatcherServlet\': initialization completed in 131 ms2022-02-19T09:11:57.181Z INFO  - Container lbjavainlinux_0_ffad47c9 for site lbjavainlinux initialized successfully and is ready to serve requests.

Java应用启动完成！