初學SpringBoot之二
原文教程鏈接在此http://blog.csdn.net/lxhjh/article/details/51752419。
使用了org.slf4j.Logger和org.slf4j.LoggerFactory
貼三句代碼:
protected static Logger logger=LoggerFactory.getLogger(HelloController.class);
logger.debug("訪問hello");
logger.debug("訪問helloName,Name={}",name);
-----------------------------------------------------------------------------------
記錄問題:
按教程正常操作後,日誌文件一直沒有找到。
解決過程:
1.閱讀console輸出。
1)發現Spring這裏先加載了resource目錄下的logback.xml配置文件,然後才是後續的SpringBoot一系列啟動執行過程,這裏可能涉及Spring的加載機制,暫且放下,留作以後發現。
2)發現這裏輸出的文字都是亂碼,後來在logback.xml中修改了對應的<charset>為utf-8,重啟後輸出正常。這裏猜測eclipse控制臺默認解碼為utf-8,暫且不做研究。這裏同樣發現了昨天的問題,就是SpringBoot啟動後,代碼的修改都不會生效,很是奇怪。
3)還有一個發現,console的輸出格式,剛好是 %d %p (%file:%line\)- %m%n 。
2.閱讀logback.xml。
配置了兩種appender,分別對應<root><logger>,level分別為info、debug。其中配置對應關系,尚需詳查。
3.刷新項目目錄。
解決。。。。。。坑啊有點,而且打開日誌文件,再次從前端訪問,日誌文件內容並無變化,重啟eclipse後打開日誌文件,發現有了。。。
這裏的刷新機制真心有點奇怪。。。
------------------------------------------
粗略記錄三個問題,以待查詢:
1.SpringBoot的加載機制,如加入resource下的文件後。
2.SpringBoot刷新機制,如啟動後修改代碼不生效。
3.日誌框架,如log4j,slf4j。
------------------------------------------------------------------------------------------
將console和log/base.log的內容記錄在此:
console:
10:55:03,210 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
10:55:03,210 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
10:55:03,210 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/Z:/ChromeDownloads/spring-boot-sample-helloworld/spring-boot-sample-helloworld/target/classes/logback.xml]
10:55:03,366 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
10:55:03,366 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
10:55:03,397 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
10:55:03,413 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
10:55:03,569 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
10:55:03,585 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [baselog]
10:55:03,631 |-INFO in [email protected] - No compression will be used
10:55:03,631 |-INFO in [email protected] - Will use the pattern log/base.log.%d.%i for the active file
10:55:03,631 |-INFO in [email protected] - The date pattern is ‘yyyy-MM-dd‘ from file name pattern ‘log/base.log.%d.%i‘.
10:55:03,631 |-INFO in [email protected] - Roll-over at midnight.
10:55:03,663 |-INFO in [email protected] - Setting initial period to Sun Jun 25 10:25:50 CST 2017
10:55:03,663 |-WARN in [email protected] - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
10:55:03,663 |-WARN in [email protected] - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
10:55:03,678 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
10:55:03,678 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[baselog] - Active log file name: log/base.log
10:55:03,678 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[baselog] - File property is set to [log/base.log]
10:55:03,694 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
10:55:03,694 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
10:55:03,694 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.example] to DEBUG
10:55:03,694 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [baselog] to Logger[com.example]
10:55:03,694 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
10:55:03,694 |-INFO in [email protected] - Registering current configuration as safe fallback point
. ____ _ __ _ _
/\\ / ___‘_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | ‘_ | ‘_| | ‘_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
‘ |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v1.5.4.RELEASE)
2017-06-25 10:55:05,441 INFO (StartupInfoLogger.java:48)- Starting SpringBootSampleHelloworldApplication on OQBNBM1JE2S28LI with PID 6404 (Z:\ChromeDownloads\spring-boot-sample-helloworld\spring-boot-sample-helloworld\target\classes started by Administrator in Z:\ChromeDownloads\spring-boot-sample-helloworld\spring-boot-sample-helloworld)
2017-06-25 10:55:05,456 DEBUG (StartupInfoLogger.java:51)- Running with Spring Boot v1.5.4.RELEASE, Spring v4.3.9.RELEASE
2017-06-25 10:55:05,456 INFO (SpringApplication.java:593)- No active profile set, falling back to default profiles: default
2017-06-25 10:55:05,628 INFO (AbstractApplicationContext.java:583)- Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbedde[email protected]: startup date [Sun Jun 25 10:55:05 CST 2017]; root of context hierarchy
2017-06-25 10:55:06,409 INFO (Version.java:30)- HV000001: Hibernate Validator 5.3.5.Final
2017-06-25 10:55:10,660 INFO (TomcatEmbeddedServletContainer.java:89)- Tomcat initialized with port(s): 8080 (http)
2017-06-25 10:55:10,697 INFO (DirectJDKLog.java:179)- Starting service [Tomcat]
2017-06-25 10:55:10,697 INFO (DirectJDKLog.java:179)- Starting Servlet Engine: Apache Tomcat/8.5.15
2017-06-25 10:55:11,166 INFO (DirectJDKLog.java:179)- Initializing Spring embedded WebApplicationContext
2017-06-25 10:55:11,166 INFO (EmbeddedWebApplicationContext.java:276)- Root WebApplicationContext: initialization completed in 5538 ms
2017-06-25 10:55:11,838 INFO (ServletRegistrationBean.java:190)- Mapping servlet: ‘dispatcherServlet‘ to [/]
2017-06-25 10:55:11,856 INFO (AbstractFilterRegistrationBean.java:258)- Mapping filter: ‘characterEncodingFilter‘ to: [/*]
2017-06-25 10:55:11,856 INFO (AbstractFilterRegistrationBean.java:258)- Mapping filter: ‘hiddenHttpMethodFilter‘ to: [/*]
2017-06-25 10:55:11,856 INFO (AbstractFilterRegistrationBean.java:258)- Mapping filter: ‘httpPutFormContentFilter‘ to: [/*]
2017-06-25 10:55:11,856 INFO (AbstractFilterRegistrationBean.java:258)- Mapping filter: ‘requestContextFilter‘ to: [/*]
2017-06-25 10:55:12,825 INFO (RequestMappingHandlerAdapter.java:534)- Looking for @ControllerAdvice: org.springframework.boot.context.embedded.AnnotationConfigEmbedde[email protected]: startup date [Sun Jun 25 10:55:05 CST 2017]; root of context hierarchy
2017-06-25 10:55:13,066 INFO (AbstractHandlerMethodMapping.java:543)- Mapped "{[/hello/]}" onto public java.lang.String com.example.HelloController.helloName2()
2017-06-25 10:55:13,066 INFO (AbstractHandlerMethodMapping.java:543)- Mapped "{[/hello/{name}]}" onto public java.lang.String com.example.HelloController.helloName(java.lang.String)
2017-06-25 10:55:13,066 INFO (AbstractHandlerMethodMapping.java:543)- Mapped "{[/]}" onto public java.lang.String com.example.HelloController.helloWorld()
2017-06-25 10:55:13,066 INFO (AbstractHandlerMethodMapping.java:543)- Mapped "{[/shello/]}" onto public java.lang.String com.example.locationTest.HellooController.helloName2()
2017-06-25 10:55:13,082 INFO (AbstractHandlerMethodMapping.java:543)- Mapped "{[/shello/{name}]}" onto public java.lang.String com.example.locationTest.HellooController.helloName(java.lang.String)
2017-06-25 10:55:13,082 INFO (AbstractHandlerMethodMapping.java:543)- Mapped "{[/s]}" onto public java.lang.String com.example.locationTest.HellooController.helloWorld()
2017-06-25 10:55:13,082 INFO (AbstractHandlerMethodMapping.java:543)- 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)
2017-06-25 10:55:13,098 INFO (AbstractHandlerMethodMapping.java:543)- Mapped "{[/error],produces=[text/html]}" onto public org.springframework.web.servlet.ModelAndView org.springframework.boot.autoconfigure.web.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)
2017-06-25 10:55:13,176 INFO (AbstractUrlHandlerMapping.java:362)- Mapped URL path [/webjars/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2017-06-25 10:55:13,176 INFO (AbstractUrlHandlerMapping.java:362)- Mapped URL path [/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2017-06-25 10:55:13,285 INFO (AbstractUrlHandlerMapping.java:362)- Mapped URL path [/**/favicon.ico] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2017-06-25 10:55:13,645 INFO (MBeanExporter.java:431)- Registering beans for JMX exposure on startup
2017-06-25 10:55:13,691 INFO (DirectJDKLog.java:179)- Initializing ProtocolHandler ["http-nio-8080"]
2017-06-25 10:55:13,723 INFO (DirectJDKLog.java:179)- Starting ProtocolHandler ["http-nio-8080"]
2017-06-25 10:55:13,754 INFO (DirectJDKLog.java:179)- Using a shared selector for servlet write/read
2017-06-25 10:55:13,832 INFO (TomcatEmbeddedServletContainer.java:201)- Tomcat started on port(s): 8080 (http)
2017-06-25 10:55:13,848 INFO (StartupInfoLogger.java:57)- Started SpringBootSampleHelloworldApplication in 9.679 seconds (JVM running for 11.227)
2017-06-25 10:55:14,406 INFO (DirectJDKLog.java:179)- Initializing Spring FrameworkServlet ‘dispatcherServlet‘
2017-06-25 10:55:14,406 INFO (FrameworkServlet.java:489)- FrameworkServlet ‘dispatcherServlet‘: initialization started
2017-06-25 10:55:14,453 INFO (FrameworkServlet.java:508)- FrameworkServlet ‘dispatcherServlet‘: initialization completed in 47 ms
2017-06-25 10:55:14,609 DEBUG (HelloController.java:22)- 訪問helloName,Name=aaaaaallllllllllll
log/base.log:
2017-06-25 09:16:20,168 INFO (StartupInfoLogger.java:48)- Starting SpringBootSampleHelloworldApplication on OQBNBM1JE2S28LI with PID 3108 (Z:\ChromeDownloads\spring-boot-sample-helloworld\spring-boot-sample-helloworld\target\classes started by Administrator in Z:\ChromeDownloads\spring-boot-sample-helloworld\spring-boot-sample-helloworld)
2017-06-25 09:16:20,168 DEBUG (StartupInfoLogger.java:51)- Running with Spring Boot v1.5.4.RELEASE, Spring v4.3.9.RELEASE
2017-06-25 09:16:20,168 INFO (SpringApplication.java:593)- No active profile set, falling back to default profiles: default
2017-06-25 09:16:28,812 INFO (StartupInfoLogger.java:57)- Started SpringBootSampleHelloworldApplication in 9.891 seconds (JVM running for 11.537)
2017-06-25 09:18:43,363 DEBUG (HelloController.java:16)- 訪問hello
2017-06-25 09:50:38,944 DEBUG (HelloController.java:16)- 訪問hello
2017-06-25 09:50:57,783 DEBUG (HelloController.java:22)- 訪問helloName,Name=ok
2017-06-25 09:52:05,423 DEBUG (HelloController.java:22)- 訪問helloName,Name=ok
2017-06-25 09:53:18,761 INFO (StartupInfoLogger.java:48)- Starting SpringBootSampleHelloworldApplication on OQBNBM1JE2S28LI with PID 3572 (Z:\ChromeDownloads\spring-boot-sample-helloworld\spring-boot-sample-helloworld\target\classes started by Administrator in Z:\ChromeDownloads\spring-boot-sample-helloworld\spring-boot-sample-helloworld)
2017-06-25 09:53:18,778 DEBUG (StartupInfoLogger.java:51)- Running with Spring Boot v1.5.4.RELEASE, Spring v4.3.9.RELEASE
2017-06-25 09:53:18,780 INFO (SpringApplication.java:593)- No active profile set, falling back to default profiles: default
2017-06-25 09:53:26,948 INFO (StartupInfoLogger.java:57)- Started SpringBootSampleHelloworldApplication in 10.671 seconds (JVM running for 14.205)
2017-06-25 09:54:43,480 DEBUG (HelloController.java:22)- 訪問helloName,Name=ok
2017-06-25 10:09:09,681 DEBUG (HelloController.java:22)- 訪問helloName,Name=aaaaaa
2017-06-25 10:25:48,719 DEBUG (HelloController.java:22)- 訪問helloName,Name=aaaaaallllllllllll
2017-06-25 10:55:05,441 INFO (StartupInfoLogger.java:48)- Starting SpringBootSampleHelloworldApplication on OQBNBM1JE2S28LI with PID 6404 (Z:\ChromeDownloads\spring-boot-sample-helloworld\spring-boot-sample-helloworld\target\classes started by Administrator in Z:\ChromeDownloads\spring-boot-sample-helloworld\spring-boot-sample-helloworld)
2017-06-25 10:55:05,456 DEBUG (StartupInfoLogger.java:51)- Running with Spring Boot v1.5.4.RELEASE, Spring v4.3.9.RELEASE
2017-06-25 10:55:05,456 INFO (SpringApplication.java:593)- No active profile set, falling back to default profiles: default
2017-06-25 10:55:13,848 INFO (StartupInfoLogger.java:57)- Started SpringBootSampleHelloworldApplication in 9.679 seconds (JVM running for 11.227)
2017-06-25 10:55:14,609 DEBUG (HelloController.java:22)- 訪問helloName,Name=aaaaaallllllllllll
初學SpringBoot之二