web项目log日志查看分析- 流程理解

1.DEBUG [2017-07-10 11:38:41,705][] org.springframework.web.servlet.DispatcherServlet:865 - DispatcherServlet with name \'dispatcherServlet\' processing POST request for [/profit/queryProfitAccountList]
注:spring mvc的的DispatcherServlet dispatcherservlet会日志打印传进来的每个请求的url和http方法,并日志debug输出打印
2.AbstractHandlerMethodMapping dispatcherservlet处理分发请求后,当然就要handlermapping查找controller的方法了,如下打印: 2.DEBUG [2017-07-10 11:38:41,705][] org.springframework.web.servlet.handler.AbstractHandlerMethodMapping:310 - Looking up handler method for path /profit/queryProfitAccountList
debug打印“Looking up handler method for path /profit/queryProfitAccountList 3.DEBUG [2017-07-10 11:38:41,705][] org.springframework.web.servlet.handler.AbstractHandlerMethodMapping:317 - Returning handler method [public java.util.Map<java.lang.String, java.lang.Object> com.pingan.property.icore.pap.aggregation.profit.controller.ProfitController.queryProfitAccounts(com.pingan.property.icore.pap.aggregation.profit.dto.QueryProfitAccountReqDTO)] AbstractHandlerMethodMapping handlermapping查找到url对应的controller和方法,并log打印出来controller类名和处理方法名,并打印出整个方法的形参和返回值


4.DEBUG [2017-07-10 11:38:41,706][] org.springframework.beans.factory.support.AbstractBeanFactory:251 - Returning cached instance of singleton bean \'profitController\' 找到controller了(即handler),那么就从spring ioc里拿出来这个单例的bean呗,就有了AbstractBeanFactory类去取bean。


5.接下来就要调用 AbstractMessageConverterMethodArgumentResolver进行入参的json格式转换了。 将json string转为DTO,
再返回输出的时候将DTO转换为json字符串 DEBUG [2017-07-10 11:38:41,719][] org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodArgumentResolver:197 - Read [class com.pingan.property.icore.pap.aggregation.profit.dto.QueryProfitAccountReqDTO] as "application/json;charset=UTF-8" with [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@19200eab] 6.马上要sql语句操纵的时候, org.mybatis.spring.SqlSessionUtils

SqlSessionUtils mybatis会打印创建sqlsession的log DEBUG [2017-07-10 11:38:41,719][] org.mybatis.spring.SqlSessionUtils:97 - Creating a new SqlSession

7.然后可以mybatis设置sqlsession是否同步 DEBUG [2017-07-10 11:38:41,719][] org.mybatis.spring.SqlSessionUtils:148 - SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@391b61a4] was not registered for synchronization because synchronization is not active 8.创建sqlsession后,mybatis就要从 org.springframework.jdbc.datasource.DataSourceUtils datasource里取出一个jdbc connection了 DEBUG [2017-07-10 11:38:41,720][] org.springframework.jdbc.datasource.DataSourceUtils:110 - Fetching JDBC Connection from DataSource

9.jdbc connection拿出来后,就要对connection进行事务处理判断了。
spring 默认也会打印出来关于这个connection的数据库连接串信息 DEBUG [2017-07-10 11:38:41,723][] org.mybatis.spring.transaction.SpringManagedTransaction:87 - JDBC Connection [74708194, URL=jdbc:oracle:thin:@t0eshop.dbstg.paic.com.cn:1597:t0eshop, UserName=PAPOPR, Oracle JDBC driver] will not be managed by Spring 10.spring jdbc connection拿到后,也进行了事务判断,接下来mybatis就要打印sql语句log了。
mybatis负责打印sql语句log的用到的类是org.apache.ibatis.logging.jdbc.BaseJdbcLogger。

DEBUG [2017-07-10 11:38:41,724][] org.apache.ibatis.logging.jdbc.BaseJdbcLogger:181 - ==> Preparing: SELECT uuid FROM uid_cert_mobile WHERE mobile_no=? AND is_valid = ? DEBUG [2017-07-10 11:38:41,724][] org.apache.ibatis.logging.jdbc.BaseJdbcLogger:181 - ==> Parameters: 13565050505(String), Y(String) DEBUG [2017-07-10 11:38:41,727][] org.apache.ibatis.logging.jdbc.BaseJdbcLogger:181 - <== Total: 1

11.sql局域执行完,mybatis打印log显示关闭这条connection org.mybatis.spring.SqlSessionUtils DEBUG [2017-07-10 11:38:41,728][] org.mybatis.spring.SqlSessionUtils:191 - Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@391b61a4] 12.实际mybatis关闭sqlsession是调用spring jdbc的return connection到datsource org.springframework.jdbc.datasource.DataSourceUtils DEBUG [2017-07-10 11:38:41,728][] org.springframework.jdbc.datasource.DataSourceUtils:327 - Returning JDBC Connection to DataSource 13.return完spring的jdbc connection给spring jdbc datasource后,就要统一返回dto转成成json字符串返回了啊。
又要用到spring mvc的 AbstractMessageConverterMethodProcessor。
注意:这里有个区别,一个是read一个是write。
read是在http request进来的时候将json字符串转换为dto并作为参数传给controller。
write是controller返回dto后,将dto转换为json字符串,为write DEBUG [2017-07-10 11:39:35,135][] org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodProcessor:234 - Written [{profitAccountList=[com.pingan.property.icore.pap.aggregation.profit.dto.ProfitAccountDTO@755c5763, com.pingan.property.icore.pap.aggregation.profit.dto.ProfitAccountDTO@a2bfab5, com.pingan.property.icore.pap.aggregation.profit.dto.ProfitAccountDTO@6bc29bbb]}] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@19200eab]
14.既然controller已处理完,且已转换为json,就要返回给dispatcherservlet 给modelandview了 DEBUG [2017-07-10 11:39:35,135][] org.springframework.web.servlet.DispatcherServlet:1044 - Null ModelAndView returned to DispatcherServlet with name \'dispatcherServlet\': assuming HandlerAdapter completed request handling
15.请求处理完后,spring mvc的FrameworkServlet会打印出请求处理完的log语句。
至此,一个request请求完毕 DEBUG [2017-07-10 11:39:35,135][] org.springframework.web.servlet.FrameworkServlet:1000 - Successfully completed request
完整的log打印如下: DEBUG [2017-07-10 11:39:30,791][] org.springframework.web.servlet.DispatcherServlet:865 - DispatcherServlet with name \'dispatcherServlet\' processing POST request for [/profit/queryProfitAccountList] DEBUG [2017-07-10 11:39:30,791][] org.springframework.web.servlet.handler.AbstractHandlerMethodMapping:310 - Looking up handler method for path /profit/queryProfitAccountList DEBUG [2017-07-10 11:39:30,791][] org.springframework.web.servlet.handler.AbstractHandlerMethodMapping:317 - Returning handler method [public java.util.Map<java.lang.String, java.lang.Object> com.pingan.property.icore.pap.aggregation.profit.controller.ProfitController.queryProfitAccounts(com.pingan.property.icore.pap.aggregation.profit.dto.QueryProfitAccountReqDTO)] DEBUG [2017-07-10 11:39:30,791][] org.springframework.beans.factory.support.AbstractBeanFactory:251 - Returning cached instance of singleton bean \'profitController\' INFO [2017-07-10 11:39:30,792][] com.pingan.property.icore.pap.access.interceptor.EntranceInterceptor:46 - *************** EntranceInterceptor preHandle() begin **************** INFO [2017-07-10 11:39:30,793][] com.pingan.property.icore.pap.access.um.controller.UMApiAuthService:36 - pap->properties读取到umpwd is3mxVy95H INFO [2017-07-10 11:39:30,793][] com.pingan.property.icore.pap.access.interceptor.EntranceInterceptor:115 - umAuthUser authorization header is: Basic Vl9QQTAxM19QQTE4X0VNQUxMOjdrSjV0ZkUy INFO [2017-07-10 11:39:30,793][] com.pingan.property.icore.pap.access.interceptor.EntranceInterceptor:118 - umAuthUser decoded namePwd is: V_PA013_PA18_EMALL:7kJ5tfE2 INFO [2017-07-10 11:39:30,794][] com.pingan.property.icore.pap.access.um.controller.GuavaCachedService:60 - key : V_PA013_PA18_EMALL:7kJ5tfE2,在缓存中不存在,需要调用外部接口获取值 INFO [2017-07-10 11:39:30,794][] com.pingan.property.icore.pap.access.um.controller.GuavaCachedService:65 - userName = V_PA013_PA18_EMALL, passwd = 7kJ5tfE2 INFO [2017-07-10 11:39:30,803][] com.pingan.property.icore.pap.access.interceptor.EntranceInterceptor:125 - pap->用户的cookie : 1 INFO [2017-07-10 11:39:30,803][] com.pingan.property.icore.pap.access.interceptor.EntranceInterceptor:63 - pap-> um switch->1 INFO [2017-07-10 11:39:30,803][] com.pingan.property.icore.pap.access.interceptor.EntranceInterceptor:65 - ************** EntranceInterceptor preHandle() end********************* DEBUG [2017-07-10 11:39:30,803][] org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodArgumentResolver:197 - Read [class com.pingan.property.icore.pap.aggregation.profit.dto.QueryProfitAccountReqDTO] as "application/json;charset=UTF-8" with [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@19200eab] INFO [2017-07-10 11:39:30,804][] com.pingan.property.icore.pap.aggregation.profit.controller.ProfitController:75 - 查询权益账户信息传入参数:req=QueryProfitAccountReqDTO [mobileNo=13565050505, profitType=null, uuid=null] DEBUG [2017-07-10 11:39:30,804][] org.mybatis.spring.SqlSessionUtils:97 - Creating a new SqlSession DEBUG [2017-07-10 11:39:30,804][] org.mybatis.spring.SqlSessionUtils:148 - SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@457c4787] was not registered for synchronization because synchronization is not active DEBUG [2017-07-10 11:39:30,805][] org.springframework.jdbc.datasource.DataSourceUtils:110 - Fetching JDBC Connection from DataSource DEBUG [2017-07-10 11:39:30,808][] org.mybatis.spring.transaction.SpringManagedTransaction:87 - JDBC Connection [1699135185, URL=jdbc:oracle:thin:@t0eshop.dbstg.paic.com.cn:1597:t0eshop, UserName=PAPOPR, Oracle JDBC driver] will not be managed by Spring DEBUG [2017-07-10 11:39:30,808][] org.apache.ibatis.logging.jdbc.BaseJdbcLogger:181 - ==> Preparing: SELECT uuid FROM uid_cert_mobile WHERE mobile_no=? AND is_valid = ? DEBUG [2017-07-10 11:39:30,809][] org.apache.ibatis.logging.jdbc.BaseJdbcLogger:181 - ==> Parameters: 13565050505(String), Y(String) DEBUG [2017-07-10 11:39:30,812][] org.apache.ibatis.logging.jdbc.BaseJdbcLogger:181 - <== Total: 1 DEBUG [2017-07-10 11:39:30,813][] org.mybatis.spring.SqlSessionUtils:191 - Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@457c4787] DEBUG [2017-07-10 11:39:30,813][] org.springframework.jdbc.datasource.DataSourceUtils:327 - Returning JDBC Connection to DataSource INFO [2017-07-10 11:39:30,813][] com.pingan.property.icore.pap.common.util.PAPLogger:77 - 查询权益账户信息传入参数:req=com.pingan.property.icore.pap.profit.dto.AccountDTO@3cf11332 INFO [2017-07-10 11:39:30,813][] com.pingan.property.icore.pap.common.util.PAPLogger:77 - 查询权益账户信息传入参数:req=com.pingan.property.icore.pap.profit.dto.AccountDTO@3cf11332 DEBUG [2017-07-10 11:39:30,813][] org.mybatis.spring.SqlSessionUtils:97 - Creating a new SqlSession DEBUG [2017-07-10 11:39:30,814][] org.mybatis.spring.SqlSessionUtils:148 - SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1a4ea0e6] was not registered for synchronization because synchronization is not active DEBUG [2017-07-10 11:39:30,814][] org.springframework.jdbc.datasource.DataSourceUtils:110 - Fetching JDBC Connection from DataSource DEBUG [2017-07-10 11:39:30,817][] org.mybatis.spring.transaction.SpringManagedTransaction:87 - JDBC Connection [1026133079, URL=jdbc:oracle:thin:@t0eshop.dbstg.paic.com.cn:1597:t0eshop, UserName=PAPOPR, Oracle JDBC driver] will not be managed by Spring DEBUG [2017-07-10 11:39:30,818][] org.apache.ibatis.logging.jdbc.BaseJdbcLogger:181 - ==> Preparing: select ID_PROFIT_ACCOUNT, UUID, PROFIT_TYPE, AVAILABLE_NUM, HISTORY_NUM, CREATED_DATE, CREATED_BY, UPDATED_DATE, UPDATED_BY, IS_VALID from PROFIT_ACCOUNT where UUID = ? and PROFIT_TYPE = ? and IS_VALID = \'Y\' DEBUG [2017-07-10 11:39:30,818][] org.apache.ibatis.logging.jdbc.BaseJdbcLogger:181 - ==> Parameters: 52007A8473E72EE6E054000B5DE0B7FC(String), 1(String) DEBUG [2017-07-10 11:39:30,822][] org.apache.ibatis.logging.jdbc.BaseJdbcLogger:181 - <== Total: 1 DEBUG [2017-07-10 11:39:30,822][] org.mybatis.spring.SqlSessionUtils:191 - Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1a4ea0e6] DEBUG [2017-07-10 11:39:30,822][] org.springframework.jdbc.datasource.DataSourceUtils:327 - Returning JDBC Connection to DataSource INFO [2017-07-10 11:39:30,822][] com.pingan.property.icore.pap.common.util.PAPLogger:77 - 查询权益账户信息传入参数:req=com.pingan.property.icore.pap.profit.dto.AccountDTO@3cf11332 DEBUG [2017-07-10 11:39:30,823][] org.mybatis.spring.SqlSessionUtils:97 - Creating a new SqlSession DEBUG [2017-07-10 11:39:30,823][] org.mybatis.spring.SqlSessionUtils:148 - SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@6dc91d15] was not registered for synchronization because synchronization is not active DEBUG [2017-07-10 11:39:30,823][] org.springframework.jdbc.datasource.DataSourceUtils:110 - Fetching JDBC Connection from DataSource DEBUG [2017-07-10 11:39:30,826][] org.mybatis.spring.transaction.SpringManagedTransaction:87 - JDBC Connection [1502997277, URL=jdbc:oracle:thin:@t0eshop.dbstg.paic.com.cn:1597:t0eshop, UserName=PAPOPR, Oracle JDBC driver] will not be managed by Spring DEBUG [2017-07-10 11:39:30,827][] org.apache.ibatis.logging.jdbc.BaseJdbcLogger:181 - ==> Preparing: select ID_PROFIT_ACCOUNT, UUID, PROFIT_TYPE, AVAILABLE_NUM, HISTORY_NUM, CREATED_DATE, CREATED_BY, UPDATED_DATE, UPDATED_BY, IS_VALID from PROFIT_ACCOUNT where UUID = ? and PROFIT_TYPE = ? and IS_VALID = \'Y\' DEBUG [2017-07-10 11:39:30,827][] org.apache.ibatis.logging.jdbc.BaseJdbcLogger:181 - ==> Parameters: 52007A8473E72EE6E054000B5DE0B7FC(String), 2(String) DEBUG [2017-07-10 11:39:30,831][] org.apache.ibatis.logging.jdbc.BaseJdbcLogger:181 - <== Total: 1 DEBUG [2017-07-10 11:39:30,831][] org.mybatis.spring.SqlSessionUtils:191 - Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@6dc91d15] DEBUG [2017-07-10 11:39:30,831][] org.springframework.jdbc.datasource.DataSourceUtils:327 - Returning JDBC Connection to DataSource INFO [2017-07-10 11:39:30,832][] com.pingan.property.icore.pap.common.util.PAPLogger:77 - 查询权益账户信息传入参数:req=com.pingan.property.icore.pap.profit.dto.AccountDTO@3cf11332 DEBUG [2017-07-10 11:39:30,832][] org.mybatis.spring.SqlSessionUtils:97 - Creating a new SqlSession DEBUG [2017-07-10 11:39:30,832][] org.mybatis.spring.SqlSessionUtils:148 - SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@36332959] was not registered for synchronization because synchronization is not active DEBUG [2017-07-10 11:39:30,832][] org.springframework.jdbc.datasource.DataSourceUtils:110 - Fetching JDBC Connection from DataSource DEBUG [2017-07-10 11:39:30,836][] org.mybatis.spring.transaction.SpringManagedTransaction:87 - JDBC Connection [1200181500, URL=jdbc:oracle:thin:@t0eshop.dbstg.paic.com.cn:1597:t0eshop, UserName=PAPOPR, Oracle JDBC driver] will not be managed by Spring DEBUG [2017-07-10 11:39:30,836][] org.apache.ibatis.logging.jdbc.BaseJdbcLogger:181 - ==> Preparing: select ID_PROFIT_GP_ACCOUNT, UUID, AVAILABLE_NUM, HISTORY_NUM, CREATED_DATE, CREATED_BY, UPDATED_DATE, UPDATED_BY, IS_VALID from PROFIT_GP_ACCOUNT where UUID = ? and IS_VALID = \'Y\' DEBUG [2017-07-10 11:39:30,836][] org.apache.ibatis.logging.jdbc.BaseJdbcLogger:181 - ==> Parameters: 52007A8473E72EE6E054000B5DE0B7FC(String) DEBUG [2017-07-10 11:39:30,840][] org.apache.ibatis.logging.jdbc.BaseJdbcLogger:181 - <== Total: 1 DEBUG [2017-07-10 11:39:30,840][] org.mybatis.spring.SqlSessionUtils:191 - Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@36332959] DEBUG [2017-07-10 11:39:30,841][] org.springframework.jdbc.datasource.DataSourceUtils:327 - Returning JDBC Connection to DataSource DEBUG [2017-07-10 11:39:30,841][] org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodProcessor:234 - Written [{profitAccountList=[com.pingan.property.icore.pap.aggregation.profit.dto.ProfitAccountDTO@620ddcad, com.pingan.property.icore.pap.aggregation.profit.dto.ProfitAccountDTO@14b61ef2, com.pingan.property.icore.pap.aggregation.profit.dto.ProfitAccountDTO@3b6084dc]}] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@19200eab] DEBUG [2017-07-10 11:39:30,842][] org.springframework.web.servlet.DispatcherServlet:1044 - Null ModelAndView returned to DispatcherServlet with name \'dispatcherServlet\': assuming HandlerAdapter completed request handling DEBUG [2017-07-10 11:39:30,842][] org.springframework.web.servlet.FrameworkServlet:1000 - Successfully completed request

内容版权声明:除非注明,否则皆为本站原创文章。

转载注明出处:https://www.heiqu.com/zgzjyx.html