这个CacheManager 有三个引用该引哪个的（下边是新手入门里的哪个）

   CacheManager cacheManager = ioc.get(CacheManager.class);
        log.debug("Ehcache CacheManager = " + cacheManager);

import net.sf.ehcache.CacheManager;

E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\bin\catalina.bat run
[2017-09-15 06:12:00,481] Artifact nutzbook:war exploded: Waiting for server connection to start artifact deployment...
Using CATALINA_BASE:   "C:\Users\lenovo\.IntelliJIdea2017.2\system\tomcat\Unnamed_nutzbook_2"
Using CATALINA_HOME:   "E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14"
Using CATALINA_TMPDIR: "E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\temp"
Using JRE_HOME:        "D:\Software_Develops\JDK"
Using CLASSPATH:       "E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\bin\bootstrap.jar;E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\bin\tomcat-juli.jar"
15-Sep-2017 18:12:01.372 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.5.14
15-Sep-2017 18:12:01.374 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Apr 13 2017 12:55:45 UTC
15-Sep-2017 18:12:01.374 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Server number:         8.5.14.0
15-Sep-2017 18:12:01.375 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Windows 10
15-Sep-2017 18:12:01.375 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            10.0
15-Sep-2017 18:12:01.375 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
15-Sep-2017 18:12:01.375 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             D:\Software_Develops\JDK\jre
15-Sep-2017 18:12:01.375 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           1.8.0_121-b13
15-Sep-2017 18:12:01.375 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Oracle Corporation
15-Sep-2017 18:12:01.375 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         C:\Users\lenovo\.IntelliJIdea2017.2\system\tomcat\Unnamed_nutzbook_2
15-Sep-2017 18:12:01.375 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14
15-Sep-2017 18:12:01.376 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=C:\Users\lenovo\.IntelliJIdea2017.2\system\tomcat\Unnamed_nutzbook_2\conf\logging.properties
15-Sep-2017 18:12:01.376 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
15-Sep-2017 18:12:01.376 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dfile.encoding=UTF-8
15-Sep-2017 18:12:01.376 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote=
15-Sep-2017 18:12:01.376 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote.port=1099
15-Sep-2017 18:12:01.376 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote.ssl=false
15-Sep-2017 18:12:01.376 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote.authenticate=false
15-Sep-2017 18:12:01.376 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.rmi.server.hostname=127.0.0.1
15-Sep-2017 18:12:01.376 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
15-Sep-2017 18:12:01.377 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
15-Sep-2017 18:12:01.377 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=C:\Users\lenovo\.IntelliJIdea2017.2\system\tomcat\Unnamed_nutzbook_2
15-Sep-2017 18:12:01.377 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14
15-Sep-2017 18:12:01.377 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\temp
15-Sep-2017 18:12:01.377 信息 [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded APR based Apache Tomcat Native library 1.2.12 using APR version 1.5.2.
15-Sep-2017 18:12:01.377 信息 [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
15-Sep-2017 18:12:01.379 信息 [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
15-Sep-2017 18:12:02.053 信息 [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized (OpenSSL 1.0.2k  26 Jan 2017)
15-Sep-2017 18:12:02.170 信息 [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
15-Sep-2017 18:12:02.189 信息 [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
15-Sep-2017 18:12:02.192 信息 [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-8009"]
15-Sep-2017 18:12:02.195 信息 [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
15-Sep-2017 18:12:02.195 信息 [main] org.apache.catalina.startup.Catalina.load Initialization processed in 1167 ms
15-Sep-2017 18:12:02.225 信息 [main] org.apache.catalina.core.StandardService.startInternal Starting service Catalina
15-Sep-2017 18:12:02.225 信息 [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.14
15-Sep-2017 18:12:02.233 信息 [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
15-Sep-2017 18:12:02.244 信息 [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
15-Sep-2017 18:12:02.246 信息 [main] org.apache.catalina.startup.Catalina.start Server startup in 51 ms
Connected to server
[2017-09-15 06:12:02,594] Artifact nutzbook:war exploded: Artifact is being deployed, please wait...
15-Sep-2017 18:12:04.644 信息 [RMI TCP Connection(3)-127.0.0.1] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
2017-09-15 18:12:04,762 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:128) INFO  - Starting Shiro environment initialization.
2017-09-15 18:12:04,778 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:76) DEBUG - Checking any specified config locations.
2017-09-15 18:12:04,778 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:81) DEBUG - No INI instance or config locations specified.  Trying default config locations.
2017-09-15 18:12:04,785 org.apache.shiro.io.ResourceUtils.loadFromClassPath(ResourceUtils.java:159) DEBUG - Opening resource from class path [shiro.ini]
2017-09-15 18:12:04,790 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [main]
2017-09-15 18:12:04,793 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [urls]
2017-09-15 18:12:04,794 org.apache.shiro.web.env.IniWebEnvironment.getDefaultIni(IniWebEnvironment.java:136) DEBUG - Discovered non-empty INI configuration at location 'classpath:shiro.ini'.  Using for configuration.
2017-09-15 18:12:04,798 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=main,urls]
2017-09-15 18:12:05,137 org.apache.shiro.config.ReflectionBuilder.createNewInstance(ReflectionBuilder.java:296) INFO  - An instance with name 'authc' already exists.  Redefining this object as a new instance of type org.nutz.integration.shiro.SimpleAuthenticationFilter
2017-09-15 18:12:05,171 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: false
2017-09-15 18:12:05,172 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Boolean' value 'false' to type 'Boolean'
2017-09-15 18:12:05,172 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Boolean
2017-09-15 18:12:05,175 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-15 18:12:05,176 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Byte'
2017-09-15 18:12:05,176 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Byte value '0'
2017-09-15 18:12:05,177 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value:  
2017-09-15 18:12:05,178 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Character' value ' ' to type 'Character'
2017-09-15 18:12:05,178 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Character
2017-09-15 18:12:05,180 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-15 18:12:05,180 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Double'
2017-09-15 18:12:05,180 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Double value '0.0'
2017-09-15 18:12:05,181 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-15 18:12:05,181 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Float'
2017-09-15 18:12:05,182 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Float value '0.0'
2017-09-15 18:12:05,183 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-15 18:12:05,183 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Integer'
2017-09-15 18:12:05,184 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Integer
2017-09-15 18:12:05,186 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-15 18:12:05,186 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Long'
2017-09-15 18:12:05,187 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Long value '0'
2017-09-15 18:12:05,188 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-15 18:12:05,189 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Short'
2017-09-15 18:12:05,189 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Short value '0'
2017-09-15 18:12:05,191 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0.0
2017-09-15 18:12:05,191 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigDecimal' value '0.0' to type 'BigDecimal'
2017-09-15 18:12:05,191 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigDecimal
2017-09-15 18:12:05,193 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-15 18:12:05,193 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigInteger' value '0' to type 'BigInteger'
2017-09-15 18:12:05,193 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigInteger
2017-09-15 18:12:05,193 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: false
2017-09-15 18:12:05,194 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Boolean' value 'false' to type 'Boolean'
2017-09-15 18:12:05,194 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Boolean
2017-09-15 18:12:05,194 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-15 18:12:05,194 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Byte'
2017-09-15 18:12:05,195 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Byte value '0'
2017-09-15 18:12:05,197 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value:  
2017-09-15 18:12:05,197 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Character' value ' ' to type 'Character'
2017-09-15 18:12:05,197 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Character
2017-09-15 18:12:05,198 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-15 18:12:05,198 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Double'
2017-09-15 18:12:05,199 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Double value '0.0'
2017-09-15 18:12:05,199 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-15 18:12:05,200 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Float'
2017-09-15 18:12:05,200 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Float value '0.0'
2017-09-15 18:12:05,200 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-15 18:12:05,200 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Integer'
2017-09-15 18:12:05,201 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Integer
2017-09-15 18:12:05,201 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-15 18:12:05,201 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Long'
2017-09-15 18:12:05,201 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Long value '0'
2017-09-15 18:12:05,202 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-15 18:12:05,202 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Short'
2017-09-15 18:12:05,202 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Short value '0'
2017-09-15 18:12:05,203 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 
2017-09-15 18:12:05,204 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value '' to type 'String'
2017-09-15 18:12:05,214 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Z@2c7bf75b
2017-09-15 18:12:05,214 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'boolean[]' value '[Z@2c7bf75b' to type 'boolean[]'
2017-09-15 18:12:05,214 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a boolean[]
2017-09-15 18:12:05,215 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [B@daab968
2017-09-15 18:12:05,215 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'byte[]' value '[B@daab968' to type 'byte[]'
2017-09-15 18:12:05,215 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a byte[]
2017-09-15 18:12:05,216 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [C@13d84a84
2017-09-15 18:12:05,216 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'char[]' value '[C@13d84a84' to type 'char[]'
2017-09-15 18:12:05,216 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a char[]
2017-09-15 18:12:05,217 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [D@4488d187
2017-09-15 18:12:05,217 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'double[]' value '[D@4488d187' to type 'double[]'
2017-09-15 18:12:05,218 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a double[]
2017-09-15 18:12:05,218 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [F@37ba2762
2017-09-15 18:12:05,218 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'float[]' value '[F@37ba2762' to type 'float[]'
2017-09-15 18:12:05,219 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a float[]
2017-09-15 18:12:05,219 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [I@6f83b904
2017-09-15 18:12:05,219 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'int[]' value '[I@6f83b904' to type 'int[]'
2017-09-15 18:12:05,219 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a int[]
2017-09-15 18:12:05,220 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [J@3e5e521a
2017-09-15 18:12:05,220 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'long[]' value '[J@3e5e521a' to type 'long[]'
2017-09-15 18:12:05,220 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a long[]
2017-09-15 18:12:05,220 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [S@3cd8b8bf
2017-09-15 18:12:05,221 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'short[]' value '[S@3cd8b8bf' to type 'short[]'
2017-09-15 18:12:05,221 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a short[]
2017-09-15 18:12:05,221 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.math.BigDecimal;@5abf1971
2017-09-15 18:12:05,222 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigDecimal[]' value '[Ljava.math.BigDecimal;@5abf1971' to type 'BigDecimal[]'
2017-09-15 18:12:05,222 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigDecimal[]
2017-09-15 18:12:05,222 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.math.BigInteger;@64848933
2017-09-15 18:12:05,223 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigInteger[]' value '[Ljava.math.BigInteger;@64848933' to type 'BigInteger[]'
2017-09-15 18:12:05,223 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigInteger[]
2017-09-15 18:12:05,223 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Boolean;@3f363e00
2017-09-15 18:12:05,223 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Boolean[]' value '[Ljava.lang.Boolean;@3f363e00' to type 'Boolean[]'
2017-09-15 18:12:05,224 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Boolean[]
2017-09-15 18:12:05,224 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Byte;@61a67a52
2017-09-15 18:12:05,224 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Byte[]' value '[Ljava.lang.Byte;@61a67a52' to type 'Byte[]'
2017-09-15 18:12:05,224 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Byte[]
2017-09-15 18:12:05,225 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Character;@74d71b7f
2017-09-15 18:12:05,225 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Character[]' value '[Ljava.lang.Character;@74d71b7f' to type 'Character[]'
2017-09-15 18:12:05,225 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Character[]
2017-09-15 18:12:05,226 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Double;@5ab4b990
2017-09-15 18:12:05,226 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Double[]' value '[Ljava.lang.Double;@5ab4b990' to type 'Double[]'
2017-09-15 18:12:05,226 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Double[]
2017-09-15 18:12:05,227 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Float;@138ec5cd
2017-09-15 18:12:05,227 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Float[]' value '[Ljava.lang.Float;@138ec5cd' to type 'Float[]'
2017-09-15 18:12:05,227 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Float[]
2017-09-15 18:12:05,227 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Integer;@75b3421f
2017-09-15 18:12:05,230 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer[]' value '[Ljava.lang.Integer;@75b3421f' to type 'Integer[]'
2017-09-15 18:12:05,231 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Integer[]
2017-09-15 18:12:05,231 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Long;@3e1b687b
2017-09-15 18:12:05,233 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Long[]' value '[Ljava.lang.Long;@3e1b687b' to type 'Long[]'
2017-09-15 18:12:05,233 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Long[]
2017-09-15 18:12:05,234 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Short;@7bde45ed
2017-09-15 18:12:05,234 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Short[]' value '[Ljava.lang.Short;@7bde45ed' to type 'Short[]'
2017-09-15 18:12:05,235 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Short[]
2017-09-15 18:12:05,235 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.String;@36e6fbb8
2017-09-15 18:12:05,236 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String[]' value '[Ljava.lang.String;@36e6fbb8' to type 'String[]'
2017-09-15 18:12:05,237 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a String[]
2017-09-15 18:12:05,237 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Class;@30041730
2017-09-15 18:12:05,238 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Class[]' value '[Ljava.lang.Class;@30041730' to type 'Class[]'
2017-09-15 18:12:05,238 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Class[]
2017-09-15 18:12:05,239 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.util.Date;@39fcddf0
2017-09-15 18:12:05,239 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Date[]' value '[Ljava.util.Date;@39fcddf0' to type 'Date[]'
2017-09-15 18:12:05,239 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Date[]
2017-09-15 18:12:05,240 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.util.Calendar;@33de06c1
2017-09-15 18:12:05,240 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Calendar[]' value '[Ljava.util.Calendar;@33de06c1' to type 'Calendar[]'
2017-09-15 18:12:05,241 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Calendar[]
2017-09-15 18:12:05,241 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.io.File;@7cbf70ce
2017-09-15 18:12:05,241 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.io.File[]' value '[Ljava.io.File;@7cbf70ce' to type 'java.io.File[]'
2017-09-15 18:12:05,241 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.io.File[]
2017-09-15 18:12:05,242 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.sql.Date;@2de200a1
2017-09-15 18:12:05,242 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.sql.Date[]' value '[Ljava.sql.Date;@2de200a1' to type 'java.sql.Date[]'
2017-09-15 18:12:05,242 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.sql.Date[]
2017-09-15 18:12:05,243 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.sql.Time;@10c5dff3
2017-09-15 18:12:05,243 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.sql.Time[]' value '[Ljava.sql.Time;@10c5dff3' to type 'java.sql.Time[]'
2017-09-15 18:12:05,243 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.sql.Time[]
2017-09-15 18:12:05,244 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.sql.Timestamp;@caa7318
2017-09-15 18:12:05,244 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.sql.Timestamp[]' value '[Ljava.sql.Timestamp;@caa7318' to type 'java.sql.Timestamp[]'
2017-09-15 18:12:05,244 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.sql.Timestamp[]
2017-09-15 18:12:05,245 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.net.URL;@7abb3e18
2017-09-15 18:12:05,245 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.net.URL[]' value '[Ljava.net.URL;@7abb3e18' to type 'java.net.URL[]'
2017-09-15 18:12:05,245 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.net.URL[]
2017-09-15 18:12:05,272 org.apache.commons.beanutils.ConvertUtilsBean.convert(ConvertUtilsBean.java:481) DEBUG - Convert string '/user/login' to class 'java.lang.String'
2017-09-15 18:12:05,272 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value '/user/login' to type 'String'
2017-09-15 18:12:05,278 org.apache.commons.beanutils.ConvertUtilsBean.convert(ConvertUtilsBean.java:481) DEBUG - Convert string '/user/login' to class 'java.lang.String'
2017-09-15 18:12:05,278 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value '/user/login' to type 'String'
2017-09-15 18:12:05,287 org.apache.commons.beanutils.ConvertUtilsBean.convert(ConvertUtilsBean.java:481) DEBUG - Convert string 'classpath:ehcache.xml' to class 'java.lang.String'
2017-09-15 18:12:05,287 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value 'classpath:ehcache.xml' to type 'String'
2017-09-15 18:12:05,287 org.apache.shiro.cache.ehcache.EhCacheManager.ensureCacheManager(EhCacheManager.java:206) DEBUG - cacheManager property not set.  Constructing CacheManager instance... 
2017-09-15 18:12:05,389 org.apache.shiro.io.ResourceUtils.loadFromClassPath(ResourceUtils.java:159) DEBUG - Opening resource from class path [ehcache.xml]
2017-09-15 18:12:05,394 net.sf.ehcache.config.ConfigurationFactory.parseConfiguration(ConfigurationFactory.java:150) DEBUG - Configuring ehcache from InputStream
2017-09-15 18:12:05,418 net.sf.ehcache.config.BeanHandler.setAttribute(BeanHandler.java:271) DEBUG - Ignoring ehcache attribute xmlns:xsi
2017-09-15 18:12:05,418 net.sf.ehcache.config.BeanHandler.setAttribute(BeanHandler.java:271) DEBUG - Ignoring ehcache attribute xsi:noNamespaceSchemaLocation
2017-09-15 18:12:05,447 net.sf.ehcache.util.PropertyUtil.parseProperties(PropertyUtil.java:87) DEBUG - propertiesString is null.
2017-09-15 18:12:05,463 net.sf.ehcache.CacheManager.configure(CacheManager.java:759) WARN  - One or more caches require a DiskStore but there is no diskStore element configured. Using the default disk store path of E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\temp. Please explicitly configure the diskStore element in ehcache.xml.
2017-09-15 18:12:05,464 net.sf.ehcache.config.ConfigurationHelper.createCacheManagerEventListener(ConfigurationHelper.java:189) DEBUG - No CacheManagerEventListenerFactory class specified. Skipping...
2017-09-15 18:12:05,551 net.sf.ehcache.Cache.createBootstrapCacheLoader(Cache.java:1044) DEBUG - No BootstrapCacheLoaderFactory class specified. Skipping...
2017-09-15 18:12:05,551 net.sf.ehcache.Cache.createCacheWriter(Cache.java:1017) DEBUG - CacheWriter factory not configured. Skipping...
2017-09-15 18:12:05,552 net.sf.ehcache.config.ConfigurationHelper.createCacheExceptionHandler(ConfigurationHelper.java:100) DEBUG - No CacheExceptionHandlerFactory class specified. Skipping...
2017-09-15 18:12:05,561 net.sf.ehcache.Cache.createBootstrapCacheLoader(Cache.java:1044) DEBUG - No BootstrapCacheLoaderFactory class specified. Skipping...
2017-09-15 18:12:05,561 net.sf.ehcache.Cache.createCacheWriter(Cache.java:1017) DEBUG - CacheWriter factory not configured. Skipping...
2017-09-15 18:12:05,562 net.sf.ehcache.config.ConfigurationHelper.createCacheExceptionHandler(ConfigurationHelper.java:100) DEBUG - No CacheExceptionHandlerFactory class specified. Skipping...
2017-09-15 18:12:05,581 net.sf.ehcache.DiskStorePathManager.resolveAndLockIfNeeded(DiskStorePathManager.java:169) DEBUG - Using diskstore path E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\temp
2017-09-15 18:12:05,581 net.sf.ehcache.DiskStorePathManager.resolveAndLockIfNeeded(DiskStorePathManager.java:170) DEBUG - Holding exclusive lock on E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\temp\.ehcache-diskstore.lock
2017-09-15 18:12:05,590 net.sf.ehcache.store.disk.DiskStorageFactory.<init>(DiskStorageFactory.java:170) DEBUG - Matching data file missing (or empty) for index file. Deleting index file E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\temp\shiro-active%0053ession%0043ache.index
2017-09-15 18:12:05,686 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LOCAL_OFFHEAP_SIZE
2017-09-15 18:12:05,688 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LOCAL_OFFHEAP_SIZE_BYTES
2017-09-15 18:12:05,689 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: WRITER_QUEUE_LENGTH
2017-09-15 18:12:05,689 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: REMOTE_SIZE
2017-09-15 18:12:05,690 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LAST_REJOIN_TIMESTAMP
2017-09-15 18:12:05,712 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: OFFHEAP_GET
2017-09-15 18:12:05,714 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: OFFHEAP_PUT
2017-09-15 18:12:05,714 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: OFFHEAP_REMOVE
2017-09-15 18:12:05,716 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: XA_COMMIT
2017-09-15 18:12:05,717 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: XA_ROLLBACK
2017-09-15 18:12:05,718 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: XA_RECOVERY
2017-09-15 18:12:05,720 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: CLUSTER_EVENT
2017-09-15 18:12:05,721 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: NONSTOP
2017-09-15 18:12:05,729 net.sf.ehcache.Cache.initialise(Cache.java:1262) DEBUG - Initialised cache: shiro-activeSessionCache
2017-09-15 18:12:05,729 net.sf.ehcache.config.ConfigurationHelper.createCacheDecorators(ConfigurationHelper.java:334) DEBUG - CacheDecoratorFactory not configured. Skipping for 'shiro-activeSessionCache'.
2017-09-15 18:12:05,729 net.sf.ehcache.config.ConfigurationHelper.createDefaultCacheDecorators(ConfigurationHelper.java:364) DEBUG - CacheDecoratorFactory not configured for defaultCache. Skipping for 'shiro-activeSessionCache'.
2017-09-15 18:12:05,731 org.apache.shiro.cache.ehcache.EhCacheManager.ensureCacheManager(EhCacheManager.java:219) DEBUG - implicit cacheManager created successfully.
2017-09-15 18:12:05,748 org.apache.shiro.config.ReflectionBuilder.resolveReference(ReflectionBuilder.java:396) DEBUG - Encountered object reference '$cacheManager'.  Looking up object with id 'cacheManager'
2017-09-15 18:12:05,749 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:234) DEBUG - No authorizationCache instance set.  Checking for a cacheManager...
2017-09-15 18:12:05,749 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:242) DEBUG - CacheManager [org.apache.shiro.cache.ehcache.EhCacheManager@b398b02] has been configured.  Building authorization cache named [nutzdao_realm.authorizationCache]
2017-09-15 18:12:05,749 org.apache.shiro.cache.ehcache.EhCacheManager.getCache(EhCacheManager.java:159) INFO  - Cache with name 'nutzdao_realm.authorizationCache' does not yet exist.  Creating now.
2017-09-15 18:12:05,771 net.sf.ehcache.store.MemoryStore.<init>(MemoryStore.java:180) DEBUG - Initialized net.sf.ehcache.store.MemoryStore for nutzdao_realm.authorizationCache
2017-09-15 18:12:05,775 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LOCAL_OFFHEAP_SIZE
2017-09-15 18:12:05,776 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LOCAL_OFFHEAP_SIZE_BYTES
2017-09-15 18:12:05,776 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LOCAL_DISK_SIZE
2017-09-15 18:12:05,777 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LOCAL_DISK_SIZE_BYTES
2017-09-15 18:12:05,777 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: WRITER_QUEUE_LENGTH
2017-09-15 18:12:05,777 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: REMOTE_SIZE
2017-09-15 18:12:05,778 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LAST_REJOIN_TIMESTAMP
2017-09-15 18:12:05,779 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: OFFHEAP_GET
2017-09-15 18:12:05,779 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: OFFHEAP_PUT
2017-09-15 18:12:05,780 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: OFFHEAP_REMOVE
2017-09-15 18:12:05,780 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: DISK_GET
2017-09-15 18:12:05,781 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: DISK_PUT
2017-09-15 18:12:05,781 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: DISK_REMOVE
2017-09-15 18:12:05,781 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: XA_COMMIT
2017-09-15 18:12:05,782 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: XA_ROLLBACK
2017-09-15 18:12:05,782 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: XA_RECOVERY
2017-09-15 18:12:05,783 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: CLUSTER_EVENT
2017-09-15 18:12:05,783 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: NONSTOP
2017-09-15 18:12:05,785 net.sf.ehcache.Cache.initialise(Cache.java:1262) DEBUG - Initialised cache: nutzdao_realm.authorizationCache
2017-09-15 18:12:05,785 net.sf.ehcache.config.ConfigurationHelper.createDefaultCacheDecorators(ConfigurationHelper.java:364) DEBUG - CacheDecoratorFactory not configured for defaultCache. Skipping for 'nutzdao_realm.authorizationCache'.
2017-09-15 18:12:05,786 org.apache.shiro.cache.ehcache.EhCacheManager.getCache(EhCacheManager.java:166) INFO  - Added EhCache named [nutzdao_realm.authorizationCache]
2017-09-15 18:12:05,801 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=main,urls]
2017-09-15 18:12:05,812 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/rs/*] from String definition [anon]
2017-09-15 18:12:05,812 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/rs/*] to filter [anon] with config [null]
2017-09-15 18:12:05,814 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/logout] from String definition [logout]
2017-09-15 18:12:05,815 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/logout] to filter [logout] with config [null]
2017-09-15 18:12:05,816 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/error] from String definition [anon]
2017-09-15 18:12:05,816 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/error] to filter [anon] with config [null]
2017-09-15 18:12:05,816 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/login] from String definition [anon]
2017-09-15 18:12:05,816 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/login] to filter [anon] with config [null]
2017-09-15 18:12:05,817 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/profile/active/mail] from String definition [anon]
2017-09-15 18:12:05,817 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/profile/active/mail] to filter [anon] with config [null]
2017-09-15 18:12:05,818 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:136) DEBUG - Published WebEnvironment as ServletContext attribute with name [org.apache.shiro.web.env.EnvironmentLoader.ENVIRONMENT_ATTRIBUTE_KEY]
2017-09-15 18:12:05,818 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:141) INFO  - Shiro environment initialized in 1053 ms.
2017-09-15 18:12:05,888 org.nutz.mvc.NutFilter._init(NutFilter.java:85) INFO  - NutFilter[nutz] starting ...
2017-09-15 18:12:05,917 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=4 time use 10ms
2017-09-15 18:12:05,963 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=71 time use 46ms
2017-09-15 18:12:06,059 org.nutz.castor.Castors.reload(Castors.java:115) DEBUG - Using 95 castor for Castors
2017-09-15 18:12:06,089 org.nutz.mvc.config.AbstractNutConfig.createLoading(AbstractNutConfig.java:59) DEBUG - Loading by class org.nutz.mvc.impl.NutLoading
2017-09-15 18:12:06,092 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:55) INFO  - Nutz Version : 1.r.62 
2017-09-15 18:12:06,092 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:56) INFO  - Nutz.Mvc[nutz] is initializing ...
2017-09-15 18:12:06,092 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:60) DEBUG - Web Container Information:
2017-09-15 18:12:06,094 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:61) DEBUG -  - Default Charset : UTF-8
2017-09-15 18:12:06,095 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:62) DEBUG -  - Current . path  : E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\bin\.
2017-09-15 18:12:06,095 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:63) DEBUG -  - Java Version    : 1.8.0_121
2017-09-15 18:12:06,095 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:64) DEBUG -  - File separator  : \
2017-09-15 18:12:06,095 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:65) DEBUG -  - Timezone        : Asia/Shanghai
2017-09-15 18:12:06,096 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:66) DEBUG -  - OS              : Windows 10 amd64
2017-09-15 18:12:06,096 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:67) DEBUG -  - ServerInfo      : Apache Tomcat/8.5.14
2017-09-15 18:12:06,097 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:68) DEBUG -  - Servlet API     : 3.1
2017-09-15 18:12:06,097 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:73) DEBUG -  - ContextPath     : /nutzbook/user/goon
2017-09-15 18:12:06,097 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:74) DEBUG -  - context.tempdir : C:\Users\lenovo\.IntelliJIdea2017.2\system\tomcat\Unnamed_nutzbook_2\work\Catalina\localhost\nutzbook#user#goon
2017-09-15 18:12:06,098 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:75) DEBUG -  - MainModule      : net.wendal.nutzbook.MainModule
2017-09-15 18:12:06,101 org.nutz.mvc.impl.NutLoading.createContext(NutLoading.java:235) DEBUG - >> app.root = E:/Work/InstelliJIDEAR_WorkSpaceNo.1/nutzbook/target/nutzbook-1.0-SNAPSHOT
2017-09-15 18:12:06,103 org.nutz.mvc.impl.NutLoading.createIoc(NutLoading.java:376) DEBUG - @IocBy(type=org.nutz.mvc.ioc.provider.ComboIocProvider, args=["*js", "ioc/", "*anno", "net.wendal.nutzbook", "*tx", "*jedis", "*quartz"],init=[])
2017-09-15 18:12:06,187 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 3 resource by src( ioc/ ) , regex( ^(.+[.])(js|json)$ )
2017-09-15 18:12:06,187 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [dao.js]
2017-09-15 18:12:06,193 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [ehcache.js]
2017-09-15 18:12:06,194 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [mail.js]
2017-09-15 18:12:06,195 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 8 bean define from path=[ioc/] --> [dao, cacheProvider, emailAuthenticator, htmlEmail, cacheExecutor, conf, dataSource, cacheManager]
2017-09-15 18:12:06,214 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 23 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-15 18:12:06,244 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.AuthorityModule
2017-09-15 18:12:06,269 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.CaptchaModule
2017-09-15 18:12:06,273 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserModule
2017-09-15 18:12:06,284 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserProfileModule
2017-09-15 18:12:06,290 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2017-09-15 18:12:06,295 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.AuthorityServiceImpl
2017-09-15 18:12:06,296 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.EmailServiceImpl
2017-09-15 18:12:06,298 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.UserService
2017-09-15 18:12:06,304 org.nutz.ioc.loader.annotation.AnnotationIocLoader.<init>(AnnotationIocLoader.java:52) INFO  - Found 8 classes in 1 base-packages!
beans = ["cleanNonActiveUserJob", "authorityService", "userProfileModule", "captchaModule", "authorityModule", "userModule", "emailService", "userService"]
2017-09-15 18:12:06,311 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:40) DEBUG - Loaded 5 bean define from reader --
[txREPEATABLE_READ, txSERIALIZABLE, txNONE, txREAD_UNCOMMITTED, txREAD_COMMITTED]
2017-09-15 18:12:06,313 org.nutz.ioc.loader.combo.ComboIocLoader.createIocLoader(ComboIocLoader.java:110) DEBUG - found jedis -- org.nutz.integration.jedis.JedisIocLoader
2017-09-15 18:12:06,317 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( org/nutz/integration/jedis/jedis.js ) , regex( ^(.+[.])(js|json)$ )
2017-09-15 18:12:06,318 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [org/nutz/integration/jedis/jedis.js]
2017-09-15 18:12:06,319 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 9 bean define from path=[org/nutz/integration/jedis/jedis.js] --> [redisService, jedisCluster, jedisClusterNodes, jedisClusterWrapper, pubSubService, jedisPoolConfig, jedisPool, jedisAgent, redis]
2017-09-15 18:12:06,324 org.nutz.ioc.loader.combo.ComboIocLoader.createIocLoader(ComboIocLoader.java:110) DEBUG - found quartz -- org.nutz.integration.quartz.QuartzIocLoader
2017-09-15 18:12:06,328 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 0 bean define from path=[] --> []
2017-09-15 18:12:06,336 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:98) INFO  - NutIoc init begin ...
2017-09-15 18:12:06,339 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:115) INFO  - ... NutIoc init complete
2017-09-15 18:12:06,345 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:159) INFO  - Build URL mapping by org.nutz.mvc.impl.UrlMappingImpl ...
2017-09-15 18:12:06,349 org.nutz.mvc.impl.NutLoading.createViewMakers(NutLoading.java:366) DEBUG - @Views(DefaultViewMaker.class)
2017-09-15 18:12:06,367 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( mvc/nutzbook-mvc-chain.js ) , regex( ^(.+[.])(js|json)$ )
2017-09-15 18:12:06,373 org.nutz.mvc.impl.chainconfig.JsonActionChainMakerConfiguretion.<init>(JsonActionChainMakerConfiguretion.java:37) DEBUG - ActionChain Config:
{
   "default": {
      "ps": ["net.wendal.nutzbook.mvc.LogTimeProcessor", "org.nutz.mvc.impl.processor.UpdateRequestAttributesProcessor", "org.nutz.mvc.impl.processor.EncodingProcessor", "org.nutz.mvc.impl.processor.ModuleProcessor", "org.nutz.integration.shiro.NutShiroProcessor", "org.nutz.mvc.impl.processor.ActionFiltersProcessor", "org.nutz.mvc.impl.processor.AdaptorProcessor", "org.nutz.mvc.impl.processor.MethodInvokeProcessor", "org.nutz.mvc.impl.processor.ViewProcessor"],
      "error": "org.nutz.mvc.impl.processor.FailProcessor"
   }
}
2017-09-15 18:12:06,373 org.nutz.mvc.impl.NutLoading.createChainMaker(NutLoading.java:263) DEBUG - @ChainBy(org.nutz.mvc.impl.NutActionChainMaker)
2017-09-15 18:12:06,380 org.nutz.mvc.impl.Loadings.scanModules(Loadings.java:154) DEBUG - module class location 'file:/E:/Work/InstelliJIDEAR_WorkSpaceNo.1/nutzbook/target/nutzbook-1.0-SNAPSHOT/WEB-INF/classes/'
2017-09-15 18:12:06,380 org.nutz.mvc.impl.Loadings.scanModuleInPackage(Loadings.java:184) DEBUG -  > scan 'net.wendal.nutzbook'
2017-09-15 18:12:06,387 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 23 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-15 18:12:06,389 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.AuthorityModule'
2017-09-15 18:12:06,389 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.CaptchaModule'
2017-09-15 18:12:06,389 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserModule'
2017-09-15 18:12:06,390 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserProfileModule'
2017-09-15 18:12:06,500 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/permissions' >> (AuthorityModule.java:72).permissions : Object     | @Ok(json ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,501 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/roles'    >> (AuthorityModule.java:62).roles       : Object     | @Ok(json ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,580 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/users'    >> (AuthorityModule.java:52).users       : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,589 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/permission/add' >> (AuthorityModule.java:266).addPermission : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,590 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/role/add' >> (AuthorityModule.java:177).addRole    : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,592 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/user/fetch/permission' >> (AuthorityModule.java:135).fetchUserPermissions : Object     | @Ok(json ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,593 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/role/fetch' >> (AuthorityModule.java:243).fetchRolePermissions : Object     | @Ok(json ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,594 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/user/update' >> (AuthorityModule.java:91).updateUser  : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,595 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/role/delete' >> (AuthorityModule.java:190).delRole    : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,597 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/permission/update' >> (AuthorityModule.java:294).updateRole : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,599 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/role/update' >> (AuthorityModule.java:210).updateRole : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,600 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/permission/delete' >> (AuthorityModule.java:280).delPermission : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,601 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/user/fetch/role' >> (AuthorityModule.java:154).fetchUserRoles : Object     | @Ok(json ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,609 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/'                    >> (UserModule.java:67).index            : void       | @Ok(jsp:jsp.user.list) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,625 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/add'                 >> (UserModule.java:110).add             : Object     | @Ok(json ) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,629 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/update'              >> (UserModule.java:78).update           : Object     | @Ok(json ) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,630 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/delete'              >> (UserModule.java:88).delete           : Object     | @Ok(json ) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,632 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/query'               >> (UserModule.java:99).query            : Object     | @Ok(json ) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,635 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/login'               >> (UserModule.java:50).login            : Object     | @Ok(json ) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,637 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/logout'              >> (UserModule.java:72).logout           : void       | @Ok(>>:/ ) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,638 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/goon'                >> (UserModule.java:42).loginPage        : void       | @Ok(jsp:jsp.user.login) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,641 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/captcha/next'             >> (CaptchaModule.java:23).next          : BufferedImage | @Ok(raw:png) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,648 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/'            >> (UserProfileModule.java:90).index     : UserProfile | @Ok(jsp:jsp.user.profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,650 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/get'         >> (UserProfileModule.java:46).get       : UserProfile | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,651 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/update'      >> (UserProfileModule.java:62).update    : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,652 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:124).activeMailCallback : String     | @Ok(raw  ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,675 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:23) INFO  - Init file-pool by: E:/Work/InstelliJIDEAR_WorkSpaceNo.1/nutzbook/target/nutzbook-1.0-SNAPSHOT/WEB-INF/tmp/user_avatar [20000]
2017-09-15 18:12:06,678 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:37) DEBUG - file-pool.home: 'E:\Work\InstelliJIDEAR_WorkSpaceNo.1\nutzbook\target\nutzbook-1.0-SNAPSHOT\WEB-INF\tmp\user_avatar'
2017-09-15 18:12:06,680 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:66) INFO  - file-pool.cursor: 0
2017-09-15 18:12:06,686 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:172).uploadAvatar : void       | @Ok(>>:/user/profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,687 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:158).readAvatar : Object     | @Ok(raw:jpg) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,689 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:97).activeMail : Object     | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-15 18:12:06,689 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:217) INFO  - Found 29 module methods
2017-09-15 18:12:06,690 org.nutz.mvc.impl.NutLoading.evalLocalization(NutLoading.java:303) DEBUG - Localization: org.nutz.mvc.impl.NutMessageLoader('msg/')  dft<zh-CN>
2017-09-15 18:12:06,694 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( msg/ ) , regex( ^.+[.]properties$ )
2017-09-15 18:12:06,695 org.nutz.mvc.impl.NutMessageLoader.load(NutMessageLoader.java:27) DEBUG - Load Messages in 1 resource : [[File[E:\Work\InstelliJIDEAR_WorkSpaceNo.1\nutzbook\target\nutzbook-1.0-SNAPSHOT\WEB-INF\classes\msg\zh-CN\user.properties]]]
2017-09-15 18:12:06,700 org.nutz.mvc.impl.NutMessageLoader.load(NutMessageLoader.java:95) DEBUG - Message Loaded, size = 2
2017-09-15 18:12:06,718 org.nutz.mvc.impl.NutLoading.createSessionProvider(NutLoading.java:410) INFO  - SessionBy --> org.nutz.integration.shiro.ShiroSessionProvider@1d0eb8ff
2017-09-15 18:12:06,718 org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:271) INFO  - Setup application...
2017-09-15 18:12:06,722 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-15 18:12:06,725 org.nutz.ioc.aop.SimpleAopMaker.<init>(SimpleAopMaker.java:79) DEBUG - Load AopConfigure for anno=org.nutz.ioc.aop.Aop by type=org.nutz.ioc.aop.config.impl.AnnotationAopConfigration
2017-09-15 18:12:06,726 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dao
2017-09-15 18:12:06,727 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dao
2017-09-15 18:12:06,746 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dao) in JsonLoader(paths=[ioc/])
2017-09-15 18:12:06,746 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dao'<interface org.nutz.dao.Dao>
2017-09-15 18:12:06,765 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.dao.impl.NutDao without AOP
2017-09-15 18:12:06,766 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dao' to [app] 
2017-09-15 18:12:06,769 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2017-09-15 18:12:06,769 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dataSource
2017-09-15 18:12:06,769 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dataSource
2017-09-15 18:12:06,790 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dataSource) in JsonLoader(paths=[ioc/])
2017-09-15 18:12:06,791 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dataSource'<>
2017-09-15 18:12:06,818 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class com.alibaba.druid.pool.DruidDataSource without AOP
2017-09-15 18:12:06,818 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dataSource' to [app] 
2017-09-15 18:12:06,821 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:06,822 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=conf
2017-09-15 18:12:06,822 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=conf
2017-09-15 18:12:06,822 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(conf) in JsonLoader(paths=[ioc/])
2017-09-15 18:12:06,822 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'conf'<>
2017-09-15 18:12:06,823 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.ioc.impl.PropertiesProxy without AOP
2017-09-15 18:12:06,824 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'conf' to [app] 
2017-09-15 18:12:06,946 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 3 resource by src( custom/ ) , regex( ^.+[.]properties$ )
2017-09-15 18:12:06,946 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[E:\Work\InstelliJIDEAR_WorkSpaceNo.1\nutzbook\target\nutzbook-1.0-SNAPSHOT\WEB-INF\classes\custom\cron.properties]
2017-09-15 18:12:06,948 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[E:\Work\InstelliJIDEAR_WorkSpaceNo.1\nutzbook\target\nutzbook-1.0-SNAPSHOT\WEB-INF\classes\custom\db.properties]
2017-09-15 18:12:06,949 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[E:\Work\InstelliJIDEAR_WorkSpaceNo.1\nutzbook\target\nutzbook-1.0-SNAPSHOT\WEB-INF\classes\custom\mail.properties]
2017-09-15 18:12:07,481 com.alibaba.druid.pool.DruidDataSource.init(DruidDataSource.java:715) INFO  - {dataSource-1} inited
2017-09-15 18:12:07,482 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2017-09-15 18:12:07,787 org.nutz.dao.jdbc.Jdbcs.<clinit>(Jdbcs.java:90) DEBUG - Jdbcs init complete
2017-09-15 18:12:07,787 org.nutz.dao.jdbc.Jdbcs.getExpert(Jdbcs.java:103) INFO  - Get Connection from DataSource for JdbcExpert, if you lock at here, check your database server and configure
Fri Sep 15 18:12:07 CST 2017 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
2017-09-15 18:12:08,042 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:188) DEBUG - select expert : org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert
2017-09-15 18:12:08,052 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:199) DEBUG - JDBC Driver --> mysql-connector-java-5.1.40 ( Revision: 402933ef52cad9aa82624e80acbea46e3a701ce6 )
2017-09-15 18:12:08,052 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:200) DEBUG - JDBC Name   --> MySQL Connector Java
2017-09-15 18:12:08,053 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:202) DEBUG - JDBC URL    --> jdbc:mysql://127.0.0.1:3306/nutzbook
2017-09-15 18:12:08,219 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_client=utf8
2017-09-15 18:12:08,219 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_connection=utf8
2017-09-15 18:12:08,219 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_database=utf8
2017-09-15 18:12:08,220 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_filesystem=binary
2017-09-15 18:12:08,220 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_results=
2017-09-15 18:12:08,221 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_server=utf8
2017-09-15 18:12:08,221 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_system=utf8
2017-09-15 18:12:08,221 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_sets_dir=C:\Program Files\MySQL\MySQL Server 5.7\share\charsets\
2017-09-15 18:12:08,225 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:213) DEBUG - Mysql : binlog_format=ROW
2017-09-15 18:12:08,226 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:220) DEBUG - Mysql : database=nutzbook
2017-09-15 18:12:08,227 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:226) DEBUG - Mysql : user=root@localhost
2017-09-15 18:12:08,284 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:221) DEBUG - Database info --> MYSQL:[MySQL - 5.7.17-log]
2017-09-15 18:12:08,289 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cacheExecutor'<>
2017-09-15 18:12:08,289 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=cacheExecutor
2017-09-15 18:12:08,290 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=cacheExecutor
2017-09-15 18:12:08,292 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(cacheExecutor) in JsonLoader(paths=[ioc/])
2017-09-15 18:12:08,292 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'cacheExecutor'<>
2017-09-15 18:12:08,294 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.plugins.cache.dao.DaoCacheInterceptor without AOP
2017-09-15 18:12:08,294 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'cacheExecutor' to [app] 
2017-09-15 18:12:08,314 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cacheProvider'<>
2017-09-15 18:12:08,314 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=cacheProvider
2017-09-15 18:12:08,315 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=cacheProvider
2017-09-15 18:12:08,317 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(cacheProvider) in JsonLoader(paths=[ioc/])
2017-09-15 18:12:08,317 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'cacheProvider'<>
2017-09-15 18:12:08,319 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.plugins.cache.dao.impl.provider.EhcacheDaoCacheProvider without AOP
2017-09-15 18:12:08,319 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'cacheProvider' to [app] 
2017-09-15 18:12:08,331 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cacheManager'<>
2017-09-15 18:12:08,331 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=cacheManager
2017-09-15 18:12:08,332 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=cacheManager
2017-09-15 18:12:08,332 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(cacheManager) in JsonLoader(paths=[ioc/])
2017-09-15 18:12:08,332 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'cacheManager'<>
2017-09-15 18:12:08,337 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.sf.ehcache.CacheManager without AOP
2017-09-15 18:12:08,338 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'cacheManager' to [app] 
2017-09-15 18:12:08,353 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 23 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-15 18:12:08,447 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT COUNT(*) FROM t_user 
2017-09-15 18:12:08,450 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'nutQuartzCronJobFactory'<class org.nutz.integration.quartz.NutQuartzCronJobFactory>
2017-09-15 18:12:08,450 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=nutQuartzCronJobFactory
2017-09-15 18:12:08,450 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=nutQuartzCronJobFactory
2017-09-15 18:12:08,451 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(nutQuartzCronJobFactory) in QuartzIocLoader@681007329
2017-09-15 18:12:08,451 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'nutQuartzCronJobFactory'<class org.nutz.integration.quartz.NutQuartzCronJobFactory>
2017-09-15 18:12:08,452 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.integration.quartz.NutQuartzCronJobFactory without AOP
2017-09-15 18:12:08,452 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'nutQuartzCronJobFactory' to [app] 
2017-09-15 18:12:08,457 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'scheduler'<>
2017-09-15 18:12:08,457 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=scheduler
2017-09-15 18:12:08,457 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=scheduler
2017-09-15 18:12:08,458 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(scheduler) in QuartzIocLoader@681007329
2017-09-15 18:12:08,458 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'scheduler'<>
2017-09-15 18:12:08,458 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'scheduler' to [app] 
2017-09-15 18:12:08,505 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1184) INFO  - Using default implementation for ThreadExecutor
2017-09-15 18:12:08,525 org.quartz.core.SchedulerSignalerImpl.<init>(SchedulerSignalerImpl.java:61) INFO  - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2017-09-15 18:12:08,526 org.quartz.core.QuartzScheduler.<init>(QuartzScheduler.java:240) INFO  - Quartz Scheduler v.2.2.1 created.
2017-09-15 18:12:08,527 org.quartz.simpl.RAMJobStore.initialize(RAMJobStore.java:155) INFO  - RAMJobStore initialized.
2017-09-15 18:12:08,527 org.quartz.core.QuartzScheduler.initialize(QuartzScheduler.java:305) INFO  - Scheduler meta-data: Quartz Scheduler (v2.2.1) 'NutzbookScheduler' with instanceId 'NON_CLUSTERED'
  Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
  NOT STARTED.
  Currently in standby mode.
  Number of jobs executed: 0
  Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 3 threads.
  Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.

2017-09-15 18:12:08,527 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1339) INFO  - Quartz scheduler 'NutzbookScheduler' initialized from default resource file in Quartz package: 'quartz.properties'
2017-09-15 18:12:08,527 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1343) INFO  - Quartz scheduler version: 2.2.1
2017-09-15 18:12:08,528 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'jobFactory'<>
2017-09-15 18:12:08,528 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=jobFactory
2017-09-15 18:12:08,528 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=jobFactory
2017-09-15 18:12:08,529 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(jobFactory) in QuartzIocLoader@681007329
2017-09-15 18:12:08,529 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'jobFactory'<>
2017-09-15 18:12:08,530 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.integration.quartz.NutQuartzJobFactory without AOP
2017-09-15 18:12:08,531 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'jobFactory' to [app] 
2017-09-15 18:12:08,592 org.quartz.core.QuartzScheduler.setJobFactory(QuartzScheduler.java:2311) INFO  - JobFactory set to: org.nutz.integration.quartz.NutQuartzJobFactory@6443c753
2017-09-15 18:12:08,593 org.quartz.core.QuartzScheduler.start(QuartzScheduler.java:575) INFO  - Scheduler NutzbookScheduler_$_NON_CLUSTERED started.
2017-09-15 18:12:08,593 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-15 18:12:08,593 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:08,594 org.nutz.integration.quartz.NutQuartzCronJobFactory.init(NutQuartzCronJobFactory.java:35) DEBUG - job define name=net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob cron=0 0/60 * * * ?
2017-09-15 18:12:08,617 org.nutz.integration.quartz.NutQuartzCronJobFactory.init(NutQuartzCronJobFactory.java:28) DEBUG - found cron job packages = net.wendal.nutzbook.quartz.job
2017-09-15 18:12:08,617 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-15 18:12:08,619 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( net/wendal/nutzbook/quartz/job/ ) , regex( ^.+[.]class$ )
2017-09-15 18:12:08,623 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'htmlEmail'<class org.apache.commons.mail.HtmlEmail>
2017-09-15 18:12:08,624 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=htmlEmail
2017-09-15 18:12:08,624 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=htmlEmail
2017-09-15 18:12:08,626 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(htmlEmail) in JsonLoader(paths=[ioc/])
2017-09-15 18:12:08,626 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'htmlEmail'<class org.apache.commons.mail.HtmlEmail>
2017-09-15 18:12:08,640 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.apache.commons.mail.ImageHtmlEmail without AOP
2017-09-15 18:12:08,750 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:08,754 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:08,755 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'emailAuthenticator'<>
2017-09-15 18:12:08,755 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=emailAuthenticator
2017-09-15 18:12:08,755 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=emailAuthenticator
2017-09-15 18:12:08,756 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(emailAuthenticator) in JsonLoader(paths=[ioc/])
2017-09-15 18:12:08,756 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'emailAuthenticator'<>
2017-09-15 18:12:08,759 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.apache.commons.mail.DefaultAuthenticator without AOP
2017-09-15 18:12:08,761 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'emailAuthenticator' to [app] 
2017-09-15 18:12:08,761 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:08,762 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:08,762 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:08,763 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:08,765 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:08,765 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:08,779 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
15-Sep-2017 18:12:12.241 信息 [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\webapps\manager
15-Sep-2017 18:12:12.336 信息 [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\webapps\manager has finished in 96 ms
2017-09-15 18:12:27,657 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'authorityService'<interface net.wendal.nutzbook.service.AuthorityService>
2017-09-15 18:12:27,658 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=authorityService
2017-09-15 18:12:27,660 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(authorityService) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-15 18:12:27,661 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'authorityService'<interface net.wendal.nutzbook.service.AuthorityService>
2017-09-15 18:12:27,662 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.service.AuthorityServiceImpl without AOP
2017-09-15 18:12:27,663 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'authorityService' to [app] 
2017-09-15 18:12:27,678 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-15 18:12:27,694 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 23 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-15 18:12:27,697 net.wendal.nutzbook.service.AuthorityServiceImpl.initFormPackage(AuthorityServiceImpl.java:59) DEBUG - found 15 permission
2017-09-15 18:12:27,697 net.wendal.nutzbook.service.AuthorityServiceImpl.initFormPackage(AuthorityServiceImpl.java:60) DEBUG - found 0 role
2017-09-15 18:12:27,704 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM t_permission 
2017-09-15 18:12:27,728 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM t_role 
2017-09-15 18:12:27,743 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM t_user  WHERE name=?
    |     1 |
    |-------|
    | admin |
  For example:> "SELECT * FROM t_user  WHERE name='admin'"
2017-09-15 18:12:27,753 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM t_role  WHERE name=?
    |     1 |
    |-------|
    | admin |
  For example:> "SELECT * FROM t_role  WHERE name='admin'"
2017-09-15 18:12:27,764 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT COUNT(*) FROM t_user_role  WHERE u_id=? AND role_id=?
    | 1 | 2 |
    |---|---|
    | 1 | 1 |
  For example:> "SELECT COUNT(*) FROM t_user_role  WHERE u_id=1 AND role_id=1"
2017-09-15 18:12:27,768 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM t_role_permission  WHERE role_id=?
    | 1 |
    |---|
    | 1 |
  For example:> "SELECT * FROM t_role_permission  WHERE role_id=1"
2017-09-15 18:12:27,772 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM t_permission  WHERE name LIKE ? OR name LIKE ? OR name LIKE ?
    |           1 |      2 |       3 |
    |-------------|--------|---------|
    | authority:% | user:% | topic:% |
  For example:> "SELECT * FROM t_permission  WHERE name LIKE 'authority:%' OR name LIKE 'user:%' OR name LIKE 'topic:%'"
2017-09-15 18:12:27,776 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cacheManager'<class net.sf.ehcache.CacheManager>
2017-09-15 18:12:27,832 net.wendal.nutzbook.MainSetup.init(MainSetup.java:54) DEBUG - Ehcache CacheManager = nutzbook
2017-09-15 18:12:27,835 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'jedisAgent'<class org.nutz.integration.jedis.JedisAgent>
2017-09-15 18:12:27,835 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=jedisAgent
2017-09-15 18:12:27,835 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=jedisAgent
2017-09-15 18:12:27,835 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(jedisAgent) in JedisIocLoader@1943292558
2017-09-15 18:12:27,836 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'jedisAgent'<class org.nutz.integration.jedis.JedisAgent>
2017-09-15 18:12:27,847 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.integration.jedis.JedisAgent without AOP
2017-09-15 18:12:27,848 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'jedisAgent' to [app] 
2017-09-15 18:12:27,864 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:27,864 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'jedisPool'<class redis.clients.util.Pool>
2017-09-15 18:12:27,864 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=jedisPool
2017-09-15 18:12:27,865 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=jedisPool
2017-09-15 18:12:27,867 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(jedisPool) in JedisIocLoader@1943292558
2017-09-15 18:12:27,867 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'jedisPool'<class redis.clients.util.Pool>
2017-09-15 18:12:27,875 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class redis.clients.jedis.JedisPool without AOP
2017-09-15 18:12:27,875 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'jedisPool' to [app] 
2017-09-15 18:12:27,878 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'jedisPoolConfig'<>
2017-09-15 18:12:27,879 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=jedisPoolConfig
2017-09-15 18:12:27,879 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=jedisPoolConfig
2017-09-15 18:12:27,880 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(jedisPoolConfig) in JedisIocLoader@1943292558
2017-09-15 18:12:27,880 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'jedisPoolConfig'<>
2017-09-15 18:12:27,880 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class redis.clients.jedis.JedisPoolConfig without AOP
2017-09-15 18:12:27,880 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'jedisPoolConfig' to [app] 
2017-09-15 18:12:27,917 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:27,918 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:27,919 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:27,919 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:27,919 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:27,920 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:27,920 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'jedisPoolConfig'<>
2017-09-15 18:12:27,920 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:27,920 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:27,920 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:27,921 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:27,921 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-15 18:12:27,991 net.wendal.nutzbook.MainSetup.init(MainSetup.java:59) DEBUG - redis say : OK
2017-09-15 18:12:27,991 net.wendal.nutzbook.MainSetup.init(MainSetup.java:61) DEBUG - redis say : http://nutzbook.wendal.net
2017-09-15 18:12:27,992 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:141) INFO  - Nutz.Mvc[nutz] is up in 21894ms
2017-09-15 18:12:27,993 org.nutz.mvc.NutFilter._init(NutFilter.java:117) INFO  - exclusionsPrefix  = ^(/rs/|/druid/)
[2017-09-15 06:12:28,008] Artifact nutzbook:war exploded: Artifact is deployed successfully
[2017-09-15 06:12:28,008] Artifact nutzbook:war exploded: Deploy took 25,414 milliseconds
2017-09-15 18:12:29,196 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/captcha/next : CaptchaModule.next(CaptchaModule.java:23)
2017-09-15 18:12:29,198 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-15 18:12:29,199 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=captchaModule
2017-09-15 18:12:29,199 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(captchaModule) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-15 18:12:29,199 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-15 18:12:29,200 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.module.CaptchaModule without AOP
2017-09-15 18:12:29,200 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'captchaModule' to [app] 
2017-09-15 18:12:29,588 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:24) DEBUG - [ GET]URI=/nutzbook/user/goon/captcha/next 392ms
2017-09-15 18:12:37,810 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-15 18:12:39,908 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [POST] path=/user/login : UserModule.login(UserModule.java:50)
2017-09-15 18:12:39,909 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userModule'<class net.wendal.nutzbook.module.UserModule>
2017-09-15 18:12:39,909 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=userModule
2017-09-15 18:12:39,909 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(userModule) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-15 18:12:39,909 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'userModule'<class net.wendal.nutzbook.module.UserModule>
2017-09-15 18:12:39,910 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'txREAD_COMMITTED'<interface org.nutz.aop.MethodInterceptor>
2017-09-15 18:12:39,910 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=txREAD_COMMITTED
2017-09-15 18:12:39,910 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=txREAD_COMMITTED
2017-09-15 18:12:39,911 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(txREAD_COMMITTED) in TransIocLoader@650847191
2017-09-15 18:12:39,912 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'txREAD_COMMITTED'<interface org.nutz.aop.MethodInterceptor>
2017-09-15 18:12:39,912 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'txREAD_COMMITTED' to [app] 
2017-09-15 18:12:39,923 org.nutz.aop.asm.AsmClassAgent.<clinit>(AsmClassAgent.java:29) DEBUG - AsmClassAgent will define class in Version 50
2017-09-15 18:12:39,933 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'userModule' to [app] 
2017-09-15 18:12:39,947 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userService'<class net.wendal.nutzbook.service.UserService>
2017-09-15 18:12:39,947 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=userService
2017-09-15 18:12:39,947 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(userService) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-15 18:12:39,947 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'userService'<class net.wendal.nutzbook.service.UserService>
2017-09-15 18:12:39,947 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.service.UserService without AOP
2017-09-15 18:12:39,947 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'userService' to [app] 
2017-09-15 18:12:40,000 org.nutz.service.EntityService.<init>(EntityService.java:41) DEBUG - Get TypeParams for self : net.wendal.nutzbook.bean.User
2017-09-15 18:12:40,000 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<>
2017-09-15 18:12:40,002 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-15 18:12:40,003 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cacheManager'<interface org.apache.shiro.cache.CacheManager>
2017-09-15 18:12:40,004 org.nutz.ioc.impl.ScopeContext.remove(ScopeContext.java:84) DEBUG - Remove object 'userModule' from [app] 
2017-09-15 18:12:40,004 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:24) DEBUG - [POST]URI=/nutzbook/user/goon/user/login 96ms
2017-09-15 18:12:40,006 org.nutz.mvc.impl.processor.FailProcessor.process(FailProcessor.java:28) WARN  - Error@/user/login :
org.nutz.ioc.IocException: IocBean[userModule] throw Exception when creating
	at org.nutz.ioc.impl.ObjectMakerImpl.make(ObjectMakerImpl.java:149)
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:210)
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:239)
	at org.nutz.mvc.impl.processor.ModuleProcessor.process(ModuleProcessor.java:116)
	at org.nutz.mvc.impl.processor.AbstractProcessor.doNext(AbstractProcessor.java:44)
	at org.nutz.mvc.impl.processor.EncodingProcessor.process(EncodingProcessor.java:27)
	at org.nutz.mvc.impl.processor.AbstractProcessor.doNext(AbstractProcessor.java:44)
	at org.nutz.mvc.impl.processor.UpdateRequestAttributesProcessor.process(UpdateRequestAttributesProcessor.java:15)
	at org.nutz.mvc.impl.processor.AbstractProcessor.doNext(AbstractProcessor.java:44)
	at net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:19)
	at org.nutz.mvc.impl.NutActionChain.doChain(NutActionChain.java:44)
	at org.nutz.mvc.impl.ActionInvoker.invoke(ActionInvoker.java:67)
	at org.nutz.mvc.ActionHandler.handle(ActionHandler.java:31)
	at org.nutz.mvc.NutFilter.doFilter(NutFilter.java:202)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at com.alibaba.druid.support.http.WebStatFilter.doFilter(WebStatFilter.java:123)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)
	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
	at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:449)
	at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365)
	at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
	at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
	at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:383)
	at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80)
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:624)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1455)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.RuntimeException: IocBean[userModule] fail at field=[cacheManager]
	at org.nutz.ioc.weaver.FieldInjector.inject(FieldInjector.java:40)
	at org.nutz.ioc.weaver.DefaultWeaver.fill(DefaultWeaver.java:56)
	at org.nutz.ioc.impl.ObjectMakerImpl.make(ObjectMakerImpl.java:135)
	... 49 more
Caused by: java.lang.RuntimeException: Fail to set field[net.wendal.nutzbook.module.BaseModule#cacheManager] using value[nutzbook]
	at org.nutz.lang.inject.InjectByField.inject(InjectByField.java:24)
	at org.nutz.ioc.weaver.FieldInjector.inject(FieldInjector.java:33)
	... 51 more
Caused by: org.nutz.castor.FailToCastObjectException: Fail to cast from <net.sf.ehcache.CacheManager> to <org.apache.shiro.cache.CacheManager> for {nutzbook}
	at org.nutz.castor.Castors.cast(Castors.java:262)
	at org.nutz.castor.Castors.castTo(Castors.java:316)
	at org.nutz.lang.inject.InjectByField.inject(InjectByField.java:19)
	... 52 more
Caused by: org.nutz.lang.born.BorningException: Fail to born or cast to 'org.apache.shiro.cache.CacheManager'
 by args: [@(nutzbook)]
 because: No suitable Constructor or Factory Method!!
	at org.nutz.lang.Mirror.born(Mirror.java:988)
	at org.nutz.castor.castor.Object2Object.cast(Object2Object.java:12)
	at org.nutz.castor.Castors.cast(Castors.java:252)
	... 54 more
2017-09-15 18:12:41,725 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/captcha/next : CaptchaModule.next(CaptchaModule.java:23)
2017-09-15 18:12:41,725 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-15 18:12:41,748 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:24) DEBUG - [ GET]URI=/nutzbook/user/goon/captcha/next 23ms
2017-09-15 18:12:50,007 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [POST] path=/user/login : UserModule.login(UserModule.java:50)
2017-09-15 18:12:50,007 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userModule'<class net.wendal.nutzbook.module.UserModule>
2017-09-15 18:12:50,007 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=userModule
2017-09-15 18:12:50,007 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(userModule) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-15 18:12:50,008 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'userModule'<class net.wendal.nutzbook.module.UserModule>
2017-09-15 18:12:50,008 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'txREAD_COMMITTED'<interface org.nutz.aop.MethodInterceptor>
2017-09-15 18:12:50,009 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'userModule' to [app] 
2017-09-15 18:12:50,010 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userService'<class net.wendal.nutzbook.service.UserService>
2017-09-15 18:12:50,010 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-15 18:12:50,010 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cacheManager'<interface org.apache.shiro.cache.CacheManager>
2017-09-15 18:12:50,011 org.nutz.ioc.impl.ScopeContext.remove(ScopeContext.java:84) DEBUG - Remove object 'userModule' from [app] 
2017-09-15 18:12:50,011 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:24) DEBUG - [POST]URI=/nutzbook/user/goon/user/login 4ms
2017-09-15 18:12:50,011 org.nutz.mvc.impl.processor.FailProcessor.process(FailProcessor.java:28) WARN  - Error@/user/login :
org.nutz.ioc.IocException: IocBean[userModule] throw Exception when creating
	at org.nutz.ioc.impl.ObjectMakerImpl.make(ObjectMakerImpl.java:149)
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:210)
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:239)
	at org.nutz.mvc.impl.processor.ModuleProcessor.process(ModuleProcessor.java:116)
	at org.nutz.mvc.impl.processor.AbstractProcessor.doNext(AbstractProcessor.java:44)
	at org.nutz.mvc.impl.processor.EncodingProcessor.process(EncodingProcessor.java:27)
	at org.nutz.mvc.impl.processor.AbstractProcessor.doNext(AbstractProcessor.java:44)
	at org.nutz.mvc.impl.processor.UpdateRequestAttributesProcessor.process(UpdateRequestAttributesProcessor.java:15)
	at org.nutz.mvc.impl.processor.AbstractProcessor.doNext(AbstractProcessor.java:44)
	at net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:19)
	at org.nutz.mvc.impl.NutActionChain.doChain(NutActionChain.java:44)
	at org.nutz.mvc.impl.ActionInvoker.invoke(ActionInvoker.java:67)
	at org.nutz.mvc.ActionHandler.handle(ActionHandler.java:31)
	at org.nutz.mvc.NutFilter.doFilter(NutFilter.java:202)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at com.alibaba.druid.support.http.WebStatFilter.doFilter(WebStatFilter.java:123)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)
	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
	at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:449)
	at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365)
	at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
	at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
	at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:383)
	at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80)
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:624)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1455)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.RuntimeException: IocBean[userModule] fail at field=[cacheManager]
	at org.nutz.ioc.weaver.FieldInjector.inject(FieldInjector.java:40)
	at org.nutz.ioc.weaver.DefaultWeaver.fill(DefaultWeaver.java:56)
	at org.nutz.ioc.impl.ObjectMakerImpl.make(ObjectMakerImpl.java:135)
	... 49 more
Caused by: java.lang.RuntimeException: Fail to set field[net.wendal.nutzbook.module.BaseModule#cacheManager] using value[nutzbook]
	at org.nutz.lang.inject.InjectByField.inject(InjectByField.java:24)
	at org.nutz.ioc.weaver.FieldInjector.inject(FieldInjector.java:33)
	... 51 more
Caused by: org.nutz.castor.FailToCastObjectException: Fail to cast from <net.sf.ehcache.CacheManager> to <org.apache.shiro.cache.CacheManager> for {nutzbook}
	at org.nutz.castor.Castors.cast(Castors.java:262)
	at org.nutz.castor.Castors.castTo(Castors.java:316)
	at org.nutz.lang.inject.InjectByField.inject(InjectByField.java:19)
	... 52 more
Caused by: org.nutz.lang.born.BorningException: Fail to born or cast to 'org.apache.shiro.cache.CacheManager'
 by args: [@(nutzbook)]
 because: No suitable Constructor or Factory Method!!
	at org.nutz.lang.Mirror.born(Mirror.java:988)
	at org.nutz.castor.castor.Object2Object.cast(Object2Object.java:12)
	at org.nutz.castor.Castors.cast(Castors.java:252)
	... 54 more
2017-09-15 18:12:51,575 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/captcha/next : CaptchaModule.next(CaptchaModule.java:23)
2017-09-15 18:12:51,576 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-15 18:12:51,598 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:24) DEBUG - [ GET]URI=/nutzbook/user/goon/captcha/next 22ms
2017-09-15 18:13:02,918 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [POST] path=/user/login : UserModule.login(UserModule.java:50)
2017-09-15 18:13:02,918 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userModule'<class net.wendal.nutzbook.module.UserModule>
2017-09-15 18:13:02,918 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=userModule
2017-09-15 18:13:02,918 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(userModule) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-15 18:13:02,919 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'userModule'<class net.wendal.nutzbook.module.UserModule>
2017-09-15 18:13:02,919 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'txREAD_COMMITTED'<interface org.nutz.aop.MethodInterceptor>
2017-09-15 18:13:02,919 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'userModule' to [app] 
2017-09-15 18:13:02,920 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userService'<class net.wendal.nutzbook.service.UserService>
2017-09-15 18:13:02,920 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-15 18:13:02,920 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cacheManager'<interface org.apache.shiro.cache.CacheManager>
2017-09-15 18:13:02,920 org.nutz.ioc.impl.ScopeContext.remove(ScopeContext.java:84) DEBUG - Remove object 'userModule' from [app] 
2017-09-15 18:13:02,920 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:24) DEBUG - [POST]URI=/nutzbook/user/goon/user/login 2ms
2017-09-15 18:13:02,920 org.nutz.mvc.impl.processor.FailProcessor.process(FailProcessor.java:28) WARN  - Error@/user/login :
org.nutz.ioc.IocException: IocBean[userModule] throw Exception when creating
	at org.nutz.ioc.impl.ObjectMakerImpl.make(ObjectMakerImpl.java:149)
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:210)
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:239)
	at org.nutz.mvc.impl.processor.ModuleProcessor.process(ModuleProcessor.java:116)
	at org.nutz.mvc.impl.processor.AbstractProcessor.doNext(AbstractProcessor.java:44)
	at org.nutz.mvc.impl.processor.EncodingProcessor.process(EncodingProcessor.java:27)
	at org.nutz.mvc.impl.processor.AbstractProcessor.doNext(AbstractProcessor.java:44)
	at org.nutz.mvc.impl.processor.UpdateRequestAttributesProcessor.process(UpdateRequestAttributesProcessor.java:15)
	at org.nutz.mvc.impl.processor.AbstractProcessor.doNext(AbstractProcessor.java:44)
	at net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:19)
	at org.nutz.mvc.impl.NutActionChain.doChain(NutActionChain.java:44)
	at org.nutz.mvc.impl.ActionInvoker.invoke(ActionInvoker.java:67)
	at org.nutz.mvc.ActionHandler.handle(ActionHandler.java:31)
	at org.nutz.mvc.NutFilter.doFilter(NutFilter.java:202)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at com.alibaba.druid.support.http.WebStatFilter.doFilter(WebStatFilter.java:123)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)
	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
	at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:449)
	at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365)
	at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
	at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
	at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:383)
	at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80)
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:624)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1455)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.RuntimeException: IocBean[userModule] fail at field=[cacheManager]
	at org.nutz.ioc.weaver.FieldInjector.inject(FieldInjector.java:40)
	at org.nutz.ioc.weaver.DefaultWeaver.fill(DefaultWeaver.java:56)
	at org.nutz.ioc.impl.ObjectMakerImpl.make(ObjectMakerImpl.java:135)
	... 49 more
Caused by: java.lang.RuntimeException: Fail to set field[net.wendal.nutzbook.module.BaseModule#cacheManager] using value[nutzbook]
	at org.nutz.lang.inject.InjectByField.inject(InjectByField.java:24)
	at org.nutz.ioc.weaver.FieldInjector.inject(FieldInjector.java:33)
	... 51 more
Caused by: org.nutz.castor.FailToCastObjectException: Fail to cast from <net.sf.ehcache.CacheManager> to <org.apache.shiro.cache.CacheManager> for {nutzbook}
	at org.nutz.castor.Castors.cast(Castors.java:262)
	at org.nutz.castor.Castors.castTo(Castors.java:316)
	at org.nutz.lang.inject.InjectByField.inject(InjectByField.java:19)
	... 52 more
Caused by: org.nutz.lang.born.BorningException: Fail to born or cast to 'org.apache.shiro.cache.CacheManager'
 by args: [@(nutzbook)]
 because: No suitable Constructor or Factory Method!!
	at org.nutz.lang.Mirror.born(Mirror.java:988)
	at org.nutz.castor.castor.Object2Object.cast(Object2Object.java:12)
	at org.nutz.castor.Castors.cast(Castors.java:252)
	... 54 more
2017-09-15 18:13:04,583 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-15 18:13:28,296 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers

package net.wendal.nutzbook.module;

import net.wendal.nutzbook.bean.User;
import net.wendal.nutzbook.bean.UserProfile;
import net.wendal.nutzbook.service.UserService;
import net.wendal.nutzbook.util.Toolkit;
import org.apache.log4j.Logger;
import org.apache.shiro.SecurityUtils;
import org.apache.shiro.authz.annotation.RequiresPermissions;
import org.nutz.aop.interceptor.ioc.TransAop;
import org.nutz.dao.Cnd;
import org.nutz.dao.QueryResult;
import org.nutz.dao.pager.Pager;
import org.nutz.integration.shiro.SimpleShiroToken;
import org.nutz.ioc.aop.Aop;
import org.nutz.ioc.loader.annotation.Inject;
import org.nutz.ioc.loader.annotation.IocBean;
import org.nutz.lang.Strings;
import org.nutz.lang.util.NutMap;
import org.nutz.mvc.Scope;
import org.nutz.mvc.annotation.*;

import javax.servlet.http.HttpSession;

@IocBean // 还记得@IocBy吗? 这个跟@IocBy有很大的关系哦
@At("/user")
@Ok("json")
@Fail("http:500")
public class UserModule extends BaseModule {
    Logger log = Logger.getRootLogger();
    @Inject
    protected UserService userService;

    @GET
    @At("/goon")
    @Ok("jsp:jsp.user.login") // 降内部重定向到登录jsp
    public void loginPage() {
    }
    @At
    @POST
    public Object login(@Param("username")String username,
                        @Param("password")String password,
                        @Param("captcha")String captcha,
                        @Attr(scope=Scope.SESSION, value="nutz_captcha")String _captcha,
                        HttpSession session) {
        NutMap re = new NutMap();
        if (!Toolkit.checkCaptcha(_captcha, captcha)) {
            return re.setv("ok", false).setv("msg", "验证码错误");
        }
        int userId = userService.fetch(username, password);
        if (userId < 0) {
            return re.setv("ok", false).setv("msg", "用户名或密码错误");
        } else {
            session.setAttribute("me", userId);
            // 完成nutdao_realm后启用.
             SecurityUtils.getSubject().login(new SimpleShiroToken(userId));
            return re.setv("ok", true);
        }
    }

    @At("/")
    @Ok("jsp:jsp.user.list") // 真实路径是 /WEB-INF/jsp/user/list.jsp
    public void index() {}

    @At
    @Ok(">>:/")
    public void logout(HttpSession session) {
        session.invalidate();
    }

    @At
    @RequiresPermissions("user:update")
    public Object update(@Param("password")String password, @Attr("me")int me) {
        if (Strings.isBlank(password) || password.length() < 6)
            return new NutMap().setv("ok", false).setv("msg", "密码不符合要求");
        userService.updatePassword(me, password);
        return new NutMap().setv("ok", true);
    }

    @At
    @Aop(TransAop.READ_COMMITTED)
    @RequiresPermissions("user:delete")
    public Object delete(@Param("id") int id, @Attr("me") int me) {
        if (me == id) {
            return new NutMap().setv("ok", false).setv("msg", "不能删除当前用户!!");
        }
        dao.delete(User.class, id); // 再严谨一些的话,需要判断是否为>0
        dao.clear(UserProfile.class, Cnd.where("userId", "=", me));
        return new NutMap().setv("ok", true);
    }

    @At
    @RequiresPermissions("user:query")
    public Object query(@Param("name") String name, @Param("..") Pager pager) {
        Cnd cnd = Strings.isBlank(name) ? null : Cnd.where("name", "like", "%" + name + "%");
        QueryResult qr = new QueryResult();
        qr.setList(dao.query(User.class, cnd, pager));
        pager.setRecordCount(dao.count(User.class, cnd));
        qr.setPager(pager);
        return qr; //默认分页是第1页,每页20条
    }

    @At
    @RequiresPermissions("user:add")
    public Object add(@Param("..")User user) { // 两个点号是按对象属性一一设置
        NutMap re = new NutMap();
        String msg = checkUser(user, true);
        if (msg != null){
            return re.setv("ok", false).setv("msg", msg);
        }
        user = userService.add(user.getName(), user.getPassword());
        return re.setv("ok", true).setv("data", user);
    }

    protected String checkUser(User user, boolean create) {
        if (user == null) {
            return "空对象";
        }
        if (create) {
            if (Strings.isBlank(user.getName()) || Strings.isBlank(user.getPassword()))
                return "用户名/密码不能为空";
        } else {
            if (Strings.isBlank(user.getPassword()))
                return "密码不能为空";
        }
        String passwd = user.getPassword().trim();
        if (6 > passwd.length() || passwd.length() > 12) {
            return "密码长度错误";
        }
        user.setPassword(passwd);
        if (create) {
            int count = dao.count(User.class, Cnd.where("name", "=", user.getName()));
            if (count != 0) {
                return "用户名已经存在";
            }
        } else {
            if (user.getId() < 1) {
                return "用户Id非法";
            }
        }
        if (user.getName() != null)
            user.setName(user.getName().trim());
        return null;
    }

}

baseModule是这个

import org.apache.shiro.cache.CacheManager;

但是跑起来以后 http://localhost:8080/nutzbook/page/simple_role.jsp访问不聊了，后台也不包错，浏览器显示

找不到 localhost 的网页

登陆了，但只能登录登出

package net.wendal.nutzbook.module;

import net.wendal.nutzbook.bean.User;
import net.wendal.nutzbook.bean.UserProfile;
import net.wendal.nutzbook.service.UserService;
import net.wendal.nutzbook.util.Toolkit;
import org.apache.log4j.Logger;
import org.apache.shiro.SecurityUtils;
import org.apache.shiro.authz.annotation.RequiresPermissions;
import org.nutz.aop.interceptor.ioc.TransAop;
import org.nutz.dao.Cnd;
import org.nutz.dao.QueryResult;
import org.nutz.dao.pager.Pager;
import org.nutz.integration.shiro.SimpleShiroToken;
import org.nutz.ioc.aop.Aop;
import org.nutz.ioc.loader.annotation.Inject;
import org.nutz.ioc.loader.annotation.IocBean;
import org.nutz.lang.Strings;
import org.nutz.lang.util.NutMap;
import org.nutz.mvc.Scope;
import org.nutz.mvc.annotation.*;

import javax.servlet.http.HttpSession;

@IocBean // 还记得@IocBy吗? 这个跟@IocBy有很大的关系哦
@At("/user")
@Ok("json")
@Fail("http:500")
public class UserModule extends BaseModule {
    Logger log = Logger.getRootLogger();
    @Inject
    protected UserService userService;

    @GET
    @At("/goon")
    @Ok("jsp:jsp.user.login") // 降内部重定向到登录jsp
    public void loginPage() {
    }
    @At
    @POST
    public Object login(@Param("username")String username,
                        @Param("password")String password,
                        @Param("captcha")String captcha,
                        @Attr(scope=Scope.SESSION, value="nutz_captcha")String _captcha,
                        HttpSession session) {
        NutMap re = new NutMap();
        if (!Toolkit.checkCaptcha(_captcha, captcha)) {
            return re.setv("ok", false).setv("msg", "验证码错误");
        }
        int userId = userService.fetch(username, password);
        if (userId < 0) {
            return re.setv("ok", false).setv("msg", "用户名或密码错误");
        } else {
            session.setAttribute("me", userId);
            // 完成nutdao_realm后启用.
             SecurityUtils.getSubject().login(new SimpleShiroToken(userId));
            return re.setv("ok", true);
        }
    }

    @At("/")
    @Ok("jsp:jsp.user.list") // 真实路径是 /WEB-INF/jsp/user/list.jsp
    public void index() {}

    @At
    @Ok(">>:/")
    public void logout(HttpSession session) {
        session.invalidate();
    }

    @At
    @RequiresPermissions("user:update")
    public Object update(@Param("password")String password, @Attr("me")int me) {
        if (Strings.isBlank(password) || password.length() < 6)
            return new NutMap().setv("ok", false).setv("msg", "密码不符合要求");
        userService.updatePassword(me, password);
        return new NutMap().setv("ok", true);
    }

    @At
    @Aop(TransAop.READ_COMMITTED)
    @RequiresPermissions("user:delete")
    public Object delete(@Param("id") int id, @Attr("me") int me) {
        if (me == id) {
            return new NutMap().setv("ok", false).setv("msg", "不能删除当前用户!!");
        }
        dao.delete(User.class, id); // 再严谨一些的话,需要判断是否为>0
        dao.clear(UserProfile.class, Cnd.where("userId", "=", me));
        return new NutMap().setv("ok", true);
    }

    @At
    @RequiresPermissions("user:query")
    public Object query(@Param("name") String name, @Param("..") Pager pager) {
        Cnd cnd = Strings.isBlank(name) ? null : Cnd.where("name", "like", "%" + name + "%");
        QueryResult qr = new QueryResult();
        qr.setList(dao.query(User.class, cnd, pager));
        pager.setRecordCount(dao.count(User.class, cnd));
        qr.setPager(pager);
        return qr; //默认分页是第1页,每页20条
    }

    @At
    @RequiresPermissions("user:add")
    public Object add(@Param("..")User user) { // 两个点号是按对象属性一一设置
        NutMap re = new NutMap();
        String msg = checkUser(user, true);
        if (msg != null){
            return re.setv("ok", false).setv("msg", msg);
        }
        user = userService.add(user.getName(), user.getPassword());
        return re.setv("ok", true).setv("data", user);
    }

    protected String checkUser(User user, boolean create) {
        if (user == null) {
            return "空对象";
        }
        if (create) {
            if (Strings.isBlank(user.getName()) || Strings.isBlank(user.getPassword()))
                return "用户名/密码不能为空";
        } else {
            if (Strings.isBlank(user.getPassword()))
                return "密码不能为空";
        }
        String passwd = user.getPassword().trim();
        if (6 > passwd.length() || passwd.length() > 12) {
            return "密码长度错误";
        }
        user.setPassword(passwd);
        if (create) {
            int count = dao.count(User.class, Cnd.where("name", "=", user.getName()));
            if (count != 0) {
                return "用户名已经存在";
            }
        } else {
            if (user.getId() < 1) {
                return "用户Id非法";
            }
        }
        if (user.getName() != null)
            user.setName(user.getName().trim());
        return null;
    }

}

嗯，加了shiro以后所有的权限都用不了，而且检查数据库，权限表没有问题和新手入门里的数据一样，而且最困难就是找不到问题的原因所在

E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\bin\catalina.bat run
[2017-09-16 09:25:20,038] Artifact nutzbook:war exploded: Waiting for server connection to start artifact deployment...
Using CATALINA_BASE:   "C:\Users\lenovo\.IntelliJIdea2017.2\system\tomcat\Unnamed_nutzbook_2"
Using CATALINA_HOME:   "E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14"
Using CATALINA_TMPDIR: "E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\temp"
Using JRE_HOME:        "D:\Software_Develops\JDK"
Using CLASSPATH:       "E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\bin\bootstrap.jar;E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\bin\tomcat-juli.jar"
16-Sep-2017 09:25:21.144 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.5.14
16-Sep-2017 09:25:21.147 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Apr 13 2017 12:55:45 UTC
16-Sep-2017 09:25:21.147 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Server number:         8.5.14.0
16-Sep-2017 09:25:21.147 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Windows 10
16-Sep-2017 09:25:21.147 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            10.0
16-Sep-2017 09:25:21.147 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
16-Sep-2017 09:25:21.147 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             D:\Software_Develops\JDK\jre
16-Sep-2017 09:25:21.147 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           1.8.0_121-b13
16-Sep-2017 09:25:21.147 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Oracle Corporation
16-Sep-2017 09:25:21.147 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         C:\Users\lenovo\.IntelliJIdea2017.2\system\tomcat\Unnamed_nutzbook_2
16-Sep-2017 09:25:21.147 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14
16-Sep-2017 09:25:21.148 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=C:\Users\lenovo\.IntelliJIdea2017.2\system\tomcat\Unnamed_nutzbook_2\conf\logging.properties
16-Sep-2017 09:25:21.148 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
16-Sep-2017 09:25:21.148 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dfile.encoding=UTF-8
16-Sep-2017 09:25:21.148 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote=
16-Sep-2017 09:25:21.148 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote.port=1099
16-Sep-2017 09:25:21.148 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote.ssl=false
16-Sep-2017 09:25:21.148 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote.authenticate=false
16-Sep-2017 09:25:21.148 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.rmi.server.hostname=127.0.0.1
16-Sep-2017 09:25:21.148 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
16-Sep-2017 09:25:21.148 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
16-Sep-2017 09:25:21.149 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=C:\Users\lenovo\.IntelliJIdea2017.2\system\tomcat\Unnamed_nutzbook_2
16-Sep-2017 09:25:21.149 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14
16-Sep-2017 09:25:21.149 信息 [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\temp
16-Sep-2017 09:25:21.149 信息 [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded APR based Apache Tomcat Native library 1.2.12 using APR version 1.5.2.
16-Sep-2017 09:25:21.149 信息 [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
16-Sep-2017 09:25:21.149 信息 [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
16-Sep-2017 09:25:21.942 信息 [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized (OpenSSL 1.0.2k  26 Jan 2017)
16-Sep-2017 09:25:22.142 信息 [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
16-Sep-2017 09:25:22.183 信息 [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
16-Sep-2017 09:25:22.192 信息 [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-8009"]
16-Sep-2017 09:25:22.195 信息 [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
16-Sep-2017 09:25:22.195 信息 [main] org.apache.catalina.startup.Catalina.load Initialization processed in 1490 ms
16-Sep-2017 09:25:22.231 信息 [main] org.apache.catalina.core.StandardService.startInternal Starting service Catalina
16-Sep-2017 09:25:22.231 信息 [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.14
16-Sep-2017 09:25:22.241 信息 [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
16-Sep-2017 09:25:22.249 信息 [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
16-Sep-2017 09:25:22.253 信息 [main] org.apache.catalina.startup.Catalina.start Server startup in 57 ms
Connected to server
[2017-09-16 09:25:22,711] Artifact nutzbook:war exploded: Artifact is being deployed, please wait...
16-Sep-2017 09:25:25.617 信息 [RMI TCP Connection(3)-127.0.0.1] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
2017-09-16 09:25:25,757 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:128) INFO  - Starting Shiro environment initialization.
2017-09-16 09:25:25,784 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:76) DEBUG - Checking any specified config locations.
2017-09-16 09:25:25,784 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:81) DEBUG - No INI instance or config locations specified.  Trying default config locations.
2017-09-16 09:25:25,790 org.apache.shiro.io.ResourceUtils.loadFromClassPath(ResourceUtils.java:159) DEBUG - Opening resource from class path [shiro.ini]
2017-09-16 09:25:25,796 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [main]
2017-09-16 09:25:25,801 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [urls]
2017-09-16 09:25:25,802 org.apache.shiro.web.env.IniWebEnvironment.getDefaultIni(IniWebEnvironment.java:136) DEBUG - Discovered non-empty INI configuration at location 'classpath:shiro.ini'.  Using for configuration.
2017-09-16 09:25:25,807 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=main,urls]
2017-09-16 09:25:26,323 org.apache.shiro.config.ReflectionBuilder.createNewInstance(ReflectionBuilder.java:296) INFO  - An instance with name 'authc' already exists.  Redefining this object as a new instance of type org.nutz.integration.shiro.SimpleAuthenticationFilter
2017-09-16 09:25:26,365 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: false
2017-09-16 09:25:26,365 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Boolean' value 'false' to type 'Boolean'
2017-09-16 09:25:26,366 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Boolean
2017-09-16 09:25:26,369 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-16 09:25:26,369 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Byte'
2017-09-16 09:25:26,370 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Byte value '0'
2017-09-16 09:25:26,371 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value:  
2017-09-16 09:25:26,372 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Character' value ' ' to type 'Character'
2017-09-16 09:25:26,372 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Character
2017-09-16 09:25:26,373 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-16 09:25:26,374 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Double'
2017-09-16 09:25:26,375 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Double value '0.0'
2017-09-16 09:25:26,376 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-16 09:25:26,376 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Float'
2017-09-16 09:25:26,377 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Float value '0.0'
2017-09-16 09:25:26,378 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-16 09:25:26,378 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Integer'
2017-09-16 09:25:26,379 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Integer
2017-09-16 09:25:26,381 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-16 09:25:26,381 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Long'
2017-09-16 09:25:26,382 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Long value '0'
2017-09-16 09:25:26,383 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-16 09:25:26,384 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Short'
2017-09-16 09:25:26,384 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Short value '0'
2017-09-16 09:25:26,386 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0.0
2017-09-16 09:25:26,386 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigDecimal' value '0.0' to type 'BigDecimal'
2017-09-16 09:25:26,387 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigDecimal
2017-09-16 09:25:26,388 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-16 09:25:26,388 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigInteger' value '0' to type 'BigInteger'
2017-09-16 09:25:26,388 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigInteger
2017-09-16 09:25:26,389 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: false
2017-09-16 09:25:26,389 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Boolean' value 'false' to type 'Boolean'
2017-09-16 09:25:26,389 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Boolean
2017-09-16 09:25:26,390 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-16 09:25:26,390 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Byte'
2017-09-16 09:25:26,390 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Byte value '0'
2017-09-16 09:25:26,391 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value:  
2017-09-16 09:25:26,391 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Character' value ' ' to type 'Character'
2017-09-16 09:25:26,391 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Character
2017-09-16 09:25:26,392 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-16 09:25:26,392 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Double'
2017-09-16 09:25:26,392 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Double value '0.0'
2017-09-16 09:25:26,393 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-16 09:25:26,393 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Float'
2017-09-16 09:25:26,393 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Float value '0.0'
2017-09-16 09:25:26,394 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-16 09:25:26,394 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Integer'
2017-09-16 09:25:26,394 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Integer
2017-09-16 09:25:26,395 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-16 09:25:26,395 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Long'
2017-09-16 09:25:26,395 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Long value '0'
2017-09-16 09:25:26,395 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2017-09-16 09:25:26,396 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Short'
2017-09-16 09:25:26,396 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Short value '0'
2017-09-16 09:25:26,398 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 
2017-09-16 09:25:26,398 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value '' to type 'String'
2017-09-16 09:25:26,407 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Z@15f2c0d3
2017-09-16 09:25:26,407 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'boolean[]' value '[Z@15f2c0d3' to type 'boolean[]'
2017-09-16 09:25:26,407 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a boolean[]
2017-09-16 09:25:26,408 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [B@47a2b6c6
2017-09-16 09:25:26,408 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'byte[]' value '[B@47a2b6c6' to type 'byte[]'
2017-09-16 09:25:26,408 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a byte[]
2017-09-16 09:25:26,408 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [C@3a4f7c16
2017-09-16 09:25:26,409 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'char[]' value '[C@3a4f7c16' to type 'char[]'
2017-09-16 09:25:26,409 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a char[]
2017-09-16 09:25:26,409 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [D@cab95c4
2017-09-16 09:25:26,409 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'double[]' value '[D@cab95c4' to type 'double[]'
2017-09-16 09:25:26,409 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a double[]
2017-09-16 09:25:26,410 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [F@f5c28da
2017-09-16 09:25:26,410 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'float[]' value '[F@f5c28da' to type 'float[]'
2017-09-16 09:25:26,410 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a float[]
2017-09-16 09:25:26,411 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [I@5d9aab71
2017-09-16 09:25:26,411 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'int[]' value '[I@5d9aab71' to type 'int[]'
2017-09-16 09:25:26,411 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a int[]
2017-09-16 09:25:26,412 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [J@1cf4c318
2017-09-16 09:25:26,412 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'long[]' value '[J@1cf4c318' to type 'long[]'
2017-09-16 09:25:26,412 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a long[]
2017-09-16 09:25:26,413 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [S@4c2160f7
2017-09-16 09:25:26,413 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'short[]' value '[S@4c2160f7' to type 'short[]'
2017-09-16 09:25:26,414 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a short[]
2017-09-16 09:25:26,415 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.math.BigDecimal;@22558b51
2017-09-16 09:25:26,415 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigDecimal[]' value '[Ljava.math.BigDecimal;@22558b51' to type 'BigDecimal[]'
2017-09-16 09:25:26,415 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigDecimal[]
2017-09-16 09:25:26,416 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.math.BigInteger;@10ca9711
2017-09-16 09:25:26,416 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigInteger[]' value '[Ljava.math.BigInteger;@10ca9711' to type 'BigInteger[]'
2017-09-16 09:25:26,416 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigInteger[]
2017-09-16 09:25:26,417 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Boolean;@592a6d80
2017-09-16 09:25:26,417 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Boolean[]' value '[Ljava.lang.Boolean;@592a6d80' to type 'Boolean[]'
2017-09-16 09:25:26,417 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Boolean[]
2017-09-16 09:25:26,418 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Byte;@54a35ac5
2017-09-16 09:25:26,418 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Byte[]' value '[Ljava.lang.Byte;@54a35ac5' to type 'Byte[]'
2017-09-16 09:25:26,418 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Byte[]
2017-09-16 09:25:26,418 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Character;@521151d3
2017-09-16 09:25:26,419 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Character[]' value '[Ljava.lang.Character;@521151d3' to type 'Character[]'
2017-09-16 09:25:26,419 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Character[]
2017-09-16 09:25:26,419 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Double;@25a887f0
2017-09-16 09:25:26,420 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Double[]' value '[Ljava.lang.Double;@25a887f0' to type 'Double[]'
2017-09-16 09:25:26,420 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Double[]
2017-09-16 09:25:26,420 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Float;@4e88ca6a
2017-09-16 09:25:26,420 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Float[]' value '[Ljava.lang.Float;@4e88ca6a' to type 'Float[]'
2017-09-16 09:25:26,421 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Float[]
2017-09-16 09:25:26,421 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Integer;@58f31bfc
2017-09-16 09:25:26,421 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer[]' value '[Ljava.lang.Integer;@58f31bfc' to type 'Integer[]'
2017-09-16 09:25:26,421 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Integer[]
2017-09-16 09:25:26,422 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Long;@3a703b29
2017-09-16 09:25:26,422 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Long[]' value '[Ljava.lang.Long;@3a703b29' to type 'Long[]'
2017-09-16 09:25:26,422 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Long[]
2017-09-16 09:25:26,422 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Short;@6fed5e7f
2017-09-16 09:25:26,423 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Short[]' value '[Ljava.lang.Short;@6fed5e7f' to type 'Short[]'
2017-09-16 09:25:26,423 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Short[]
2017-09-16 09:25:26,423 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.String;@7d115281
2017-09-16 09:25:26,424 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String[]' value '[Ljava.lang.String;@7d115281' to type 'String[]'
2017-09-16 09:25:26,424 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a String[]
2017-09-16 09:25:26,425 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Class;@5e57f4e7
2017-09-16 09:25:26,425 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Class[]' value '[Ljava.lang.Class;@5e57f4e7' to type 'Class[]'
2017-09-16 09:25:26,426 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Class[]
2017-09-16 09:25:26,426 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.util.Date;@5b4c47f4
2017-09-16 09:25:26,426 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Date[]' value '[Ljava.util.Date;@5b4c47f4' to type 'Date[]'
2017-09-16 09:25:26,427 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Date[]
2017-09-16 09:25:26,427 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.util.Calendar;@766748b7
2017-09-16 09:25:26,427 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Calendar[]' value '[Ljava.util.Calendar;@766748b7' to type 'Calendar[]'
2017-09-16 09:25:26,427 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Calendar[]
2017-09-16 09:25:26,428 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.io.File;@2e3cfcad
2017-09-16 09:25:26,428 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.io.File[]' value '[Ljava.io.File;@2e3cfcad' to type 'java.io.File[]'
2017-09-16 09:25:26,428 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.io.File[]
2017-09-16 09:25:26,429 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.sql.Date;@4f50f373
2017-09-16 09:25:26,429 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.sql.Date[]' value '[Ljava.sql.Date;@4f50f373' to type 'java.sql.Date[]'
2017-09-16 09:25:26,430 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.sql.Date[]
2017-09-16 09:25:26,430 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.sql.Time;@22c06460
2017-09-16 09:25:26,430 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.sql.Time[]' value '[Ljava.sql.Time;@22c06460' to type 'java.sql.Time[]'
2017-09-16 09:25:26,431 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.sql.Time[]
2017-09-16 09:25:26,431 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.sql.Timestamp;@1805574a
2017-09-16 09:25:26,431 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.sql.Timestamp[]' value '[Ljava.sql.Timestamp;@1805574a' to type 'java.sql.Timestamp[]'
2017-09-16 09:25:26,432 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.sql.Timestamp[]
2017-09-16 09:25:26,432 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.net.URL;@535c0012
2017-09-16 09:25:26,432 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.net.URL[]' value '[Ljava.net.URL;@535c0012' to type 'java.net.URL[]'
2017-09-16 09:25:26,432 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.net.URL[]
2017-09-16 09:25:26,464 org.apache.commons.beanutils.ConvertUtilsBean.convert(ConvertUtilsBean.java:481) DEBUG - Convert string '/user/login' to class 'java.lang.String'
2017-09-16 09:25:26,465 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value '/user/login' to type 'String'
2017-09-16 09:25:26,472 org.apache.commons.beanutils.ConvertUtilsBean.convert(ConvertUtilsBean.java:481) DEBUG - Convert string '/user/login' to class 'java.lang.String'
2017-09-16 09:25:26,473 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value '/user/login' to type 'String'
2017-09-16 09:25:26,487 org.apache.commons.beanutils.ConvertUtilsBean.convert(ConvertUtilsBean.java:481) DEBUG - Convert string 'classpath:ehcache.xml' to class 'java.lang.String'
2017-09-16 09:25:26,487 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value 'classpath:ehcache.xml' to type 'String'
2017-09-16 09:25:26,487 org.apache.shiro.cache.ehcache.EhCacheManager.ensureCacheManager(EhCacheManager.java:206) DEBUG - cacheManager property not set.  Constructing CacheManager instance... 
2017-09-16 09:25:26,586 org.apache.shiro.io.ResourceUtils.loadFromClassPath(ResourceUtils.java:159) DEBUG - Opening resource from class path [ehcache.xml]
2017-09-16 09:25:26,607 net.sf.ehcache.config.ConfigurationFactory.parseConfiguration(ConfigurationFactory.java:150) DEBUG - Configuring ehcache from InputStream
2017-09-16 09:25:26,644 net.sf.ehcache.config.BeanHandler.setAttribute(BeanHandler.java:271) DEBUG - Ignoring ehcache attribute xmlns:xsi
2017-09-16 09:25:26,645 net.sf.ehcache.config.BeanHandler.setAttribute(BeanHandler.java:271) DEBUG - Ignoring ehcache attribute xsi:noNamespaceSchemaLocation
2017-09-16 09:25:26,673 net.sf.ehcache.util.PropertyUtil.parseProperties(PropertyUtil.java:87) DEBUG - propertiesString is null.
2017-09-16 09:25:26,688 net.sf.ehcache.CacheManager.configure(CacheManager.java:759) WARN  - One or more caches require a DiskStore but there is no diskStore element configured. Using the default disk store path of E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\temp. Please explicitly configure the diskStore element in ehcache.xml.
2017-09-16 09:25:26,690 net.sf.ehcache.config.ConfigurationHelper.createCacheManagerEventListener(ConfigurationHelper.java:189) DEBUG - No CacheManagerEventListenerFactory class specified. Skipping...
2017-09-16 09:25:26,769 net.sf.ehcache.Cache.createBootstrapCacheLoader(Cache.java:1044) DEBUG - No BootstrapCacheLoaderFactory class specified. Skipping...
2017-09-16 09:25:26,770 net.sf.ehcache.Cache.createCacheWriter(Cache.java:1017) DEBUG - CacheWriter factory not configured. Skipping...
2017-09-16 09:25:26,770 net.sf.ehcache.config.ConfigurationHelper.createCacheExceptionHandler(ConfigurationHelper.java:100) DEBUG - No CacheExceptionHandlerFactory class specified. Skipping...
2017-09-16 09:25:26,781 net.sf.ehcache.Cache.createBootstrapCacheLoader(Cache.java:1044) DEBUG - No BootstrapCacheLoaderFactory class specified. Skipping...
2017-09-16 09:25:26,781 net.sf.ehcache.Cache.createCacheWriter(Cache.java:1017) DEBUG - CacheWriter factory not configured. Skipping...
2017-09-16 09:25:26,781 net.sf.ehcache.config.ConfigurationHelper.createCacheExceptionHandler(ConfigurationHelper.java:100) DEBUG - No CacheExceptionHandlerFactory class specified. Skipping...
2017-09-16 09:25:26,799 net.sf.ehcache.DiskStorePathManager.resolveAndLockIfNeeded(DiskStorePathManager.java:169) DEBUG - Using diskstore path E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\temp
2017-09-16 09:25:26,799 net.sf.ehcache.DiskStorePathManager.resolveAndLockIfNeeded(DiskStorePathManager.java:170) DEBUG - Holding exclusive lock on E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\temp\.ehcache-diskstore.lock
2017-09-16 09:25:26,808 net.sf.ehcache.store.disk.DiskStorageFactory.<init>(DiskStorageFactory.java:170) DEBUG - Matching data file missing (or empty) for index file. Deleting index file E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\temp\shiro-active%0053ession%0043ache.index
2017-09-16 09:25:26,808 net.sf.ehcache.store.disk.DiskStorageFactory.deleteFile(DiskStorageFactory.java:838) DEBUG - Failed to delete file shiro-active%0053ession%0043ache.index
2017-09-16 09:25:26,884 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LOCAL_OFFHEAP_SIZE
2017-09-16 09:25:26,886 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LOCAL_OFFHEAP_SIZE_BYTES
2017-09-16 09:25:26,888 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: WRITER_QUEUE_LENGTH
2017-09-16 09:25:26,889 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: REMOTE_SIZE
2017-09-16 09:25:26,889 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LAST_REJOIN_TIMESTAMP
2017-09-16 09:25:26,914 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: OFFHEAP_GET
2017-09-16 09:25:26,915 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: OFFHEAP_PUT
2017-09-16 09:25:26,916 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: OFFHEAP_REMOVE
2017-09-16 09:25:26,917 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: XA_COMMIT
2017-09-16 09:25:26,918 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: XA_ROLLBACK
2017-09-16 09:25:26,918 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: XA_RECOVERY
2017-09-16 09:25:26,919 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: CLUSTER_EVENT
2017-09-16 09:25:26,920 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: NONSTOP
2017-09-16 09:25:26,925 net.sf.ehcache.Cache.initialise(Cache.java:1262) DEBUG - Initialised cache: shiro-activeSessionCache
2017-09-16 09:25:26,925 net.sf.ehcache.config.ConfigurationHelper.createCacheDecorators(ConfigurationHelper.java:334) DEBUG - CacheDecoratorFactory not configured. Skipping for 'shiro-activeSessionCache'.
2017-09-16 09:25:26,925 net.sf.ehcache.config.ConfigurationHelper.createDefaultCacheDecorators(ConfigurationHelper.java:364) DEBUG - CacheDecoratorFactory not configured for defaultCache. Skipping for 'shiro-activeSessionCache'.
2017-09-16 09:25:26,926 org.apache.shiro.cache.ehcache.EhCacheManager.ensureCacheManager(EhCacheManager.java:219) DEBUG - implicit cacheManager created successfully.
2017-09-16 09:25:26,942 org.apache.shiro.config.ReflectionBuilder.resolveReference(ReflectionBuilder.java:396) DEBUG - Encountered object reference '$cacheManager'.  Looking up object with id 'cacheManager'
2017-09-16 09:25:26,942 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:234) DEBUG - No authorizationCache instance set.  Checking for a cacheManager...
2017-09-16 09:25:26,943 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:242) DEBUG - CacheManager [org.apache.shiro.cache.ehcache.EhCacheManager@6fb1f7c] has been configured.  Building authorization cache named [nutzdao_realm.authorizationCache]
2017-09-16 09:25:26,943 org.apache.shiro.cache.ehcache.EhCacheManager.getCache(EhCacheManager.java:159) INFO  - Cache with name 'nutzdao_realm.authorizationCache' does not yet exist.  Creating now.
2017-09-16 09:25:26,960 net.sf.ehcache.store.MemoryStore.<init>(MemoryStore.java:180) DEBUG - Initialized net.sf.ehcache.store.MemoryStore for nutzdao_realm.authorizationCache
2017-09-16 09:25:26,965 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LOCAL_OFFHEAP_SIZE
2017-09-16 09:25:26,965 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LOCAL_OFFHEAP_SIZE_BYTES
2017-09-16 09:25:26,966 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LOCAL_DISK_SIZE
2017-09-16 09:25:26,966 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LOCAL_DISK_SIZE_BYTES
2017-09-16 09:25:26,966 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: WRITER_QUEUE_LENGTH
2017-09-16 09:25:26,966 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: REMOTE_SIZE
2017-09-16 09:25:26,967 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardPassThruStatistics(ExtendedStatisticsImpl.java:224) DEBUG - Mocking Pass-Through Statistic: LAST_REJOIN_TIMESTAMP
2017-09-16 09:25:26,968 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: OFFHEAP_GET
2017-09-16 09:25:26,968 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: OFFHEAP_PUT
2017-09-16 09:25:26,968 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: OFFHEAP_REMOVE
2017-09-16 09:25:26,969 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: DISK_GET
2017-09-16 09:25:26,969 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: DISK_PUT
2017-09-16 09:25:26,969 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: DISK_REMOVE
2017-09-16 09:25:26,969 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: XA_COMMIT
2017-09-16 09:25:26,969 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: XA_ROLLBACK
2017-09-16 09:25:26,970 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: XA_RECOVERY
2017-09-16 09:25:26,970 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: CLUSTER_EVENT
2017-09-16 09:25:26,970 net.sf.ehcache.statistics.extended.ExtendedStatisticsImpl.findStandardOperationStatistics(ExtendedStatisticsImpl.java:206) DEBUG - Mocking Operation Statistic: NONSTOP
2017-09-16 09:25:26,971 net.sf.ehcache.Cache.initialise(Cache.java:1262) DEBUG - Initialised cache: nutzdao_realm.authorizationCache
2017-09-16 09:25:26,972 net.sf.ehcache.config.ConfigurationHelper.createDefaultCacheDecorators(ConfigurationHelper.java:364) DEBUG - CacheDecoratorFactory not configured for defaultCache. Skipping for 'nutzdao_realm.authorizationCache'.
2017-09-16 09:25:26,972 org.apache.shiro.cache.ehcache.EhCacheManager.getCache(EhCacheManager.java:166) INFO  - Added EhCache named [nutzdao_realm.authorizationCache]
2017-09-16 09:25:26,976 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=main,urls]
2017-09-16 09:25:26,982 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/rs/*] from String definition [anon]
2017-09-16 09:25:26,982 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/rs/*] to filter [anon] with config [null]
2017-09-16 09:25:26,983 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/logout] from String definition [logout]
2017-09-16 09:25:26,984 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/logout] to filter [logout] with config [null]
2017-09-16 09:25:26,984 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/error] from String definition [anon]
2017-09-16 09:25:26,984 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/error] to filter [anon] with config [null]
2017-09-16 09:25:26,984 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/login] from String definition [anon]
2017-09-16 09:25:26,984 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/login] to filter [anon] with config [null]
2017-09-16 09:25:26,984 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/profile/active/mail] from String definition [anon]
2017-09-16 09:25:26,984 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/profile/active/mail] to filter [anon] with config [null]
2017-09-16 09:25:26,985 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:136) DEBUG - Published WebEnvironment as ServletContext attribute with name [org.apache.shiro.web.env.EnvironmentLoader.ENVIRONMENT_ATTRIBUTE_KEY]
2017-09-16 09:25:26,985 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:141) INFO  - Shiro environment initialized in 1225 ms.
2017-09-16 09:25:27,028 org.nutz.mvc.NutFilter._init(NutFilter.java:85) INFO  - NutFilter[nutz] starting ...
2017-09-16 09:25:27,055 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=4 time use 12ms
2017-09-16 09:25:27,119 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=71 time use 64ms
2017-09-16 09:25:27,210 org.nutz.castor.Castors.reload(Castors.java:115) DEBUG - Using 95 castor for Castors
2017-09-16 09:25:27,253 org.nutz.mvc.config.AbstractNutConfig.createLoading(AbstractNutConfig.java:59) DEBUG - Loading by class org.nutz.mvc.impl.NutLoading
2017-09-16 09:25:27,256 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:55) INFO  - Nutz Version : 1.r.62 
2017-09-16 09:25:27,256 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:56) INFO  - Nutz.Mvc[nutz] is initializing ...
2017-09-16 09:25:27,256 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:60) DEBUG - Web Container Information:
2017-09-16 09:25:27,258 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:61) DEBUG -  - Default Charset : UTF-8
2017-09-16 09:25:27,258 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:62) DEBUG -  - Current . path  : E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\bin\.
2017-09-16 09:25:27,258 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:63) DEBUG -  - Java Version    : 1.8.0_121
2017-09-16 09:25:27,259 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:64) DEBUG -  - File separator  : \
2017-09-16 09:25:27,259 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:65) DEBUG -  - Timezone        : Asia/Shanghai
2017-09-16 09:25:27,260 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:66) DEBUG -  - OS              : Windows 10 amd64
2017-09-16 09:25:27,261 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:67) DEBUG -  - ServerInfo      : Apache Tomcat/8.5.14
2017-09-16 09:25:27,261 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:68) DEBUG -  - Servlet API     : 3.1
2017-09-16 09:25:27,261 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:73) DEBUG -  - ContextPath     : /nutzbook/user/goon
2017-09-16 09:25:27,262 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:74) DEBUG -  - context.tempdir : C:\Users\lenovo\.IntelliJIdea2017.2\system\tomcat\Unnamed_nutzbook_2\work\Catalina\localhost\nutzbook#user#goon
2017-09-16 09:25:27,264 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:75) DEBUG -  - MainModule      : net.wendal.nutzbook.MainModule
2017-09-16 09:25:27,267 org.nutz.mvc.impl.NutLoading.createContext(NutLoading.java:235) DEBUG - >> app.root = E:/Work/InstelliJIDEAR_WorkSpaceNo.1/nutzbook/target/nutzbook-1.0-SNAPSHOT
2017-09-16 09:25:27,269 org.nutz.mvc.impl.NutLoading.createIoc(NutLoading.java:376) DEBUG - @IocBy(type=org.nutz.mvc.ioc.provider.ComboIocProvider, args=["*js", "ioc/", "*anno", "net.wendal.nutzbook", "*tx", "*jedis", "*quartz"],init=[])
2017-09-16 09:25:27,342 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 3 resource by src( ioc/ ) , regex( ^(.+[.])(js|json)$ )
2017-09-16 09:25:27,342 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [dao.js]
2017-09-16 09:25:27,424 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [ehcache.js]
2017-09-16 09:25:27,425 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [mail.js]
2017-09-16 09:25:27,426 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 8 bean define from path=[ioc/] --> [dao, cacheProvider, emailAuthenticator, htmlEmail, cacheExecutor, conf, dataSource, cacheManager]
2017-09-16 09:25:27,446 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 23 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-16 09:25:27,477 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.AuthorityModule
2017-09-16 09:25:27,502 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.CaptchaModule
2017-09-16 09:25:27,506 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserModule
2017-09-16 09:25:27,517 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserProfileModule
2017-09-16 09:25:27,522 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2017-09-16 09:25:27,526 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.AuthorityServiceImpl
2017-09-16 09:25:27,527 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.EmailServiceImpl
2017-09-16 09:25:27,530 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.UserService
2017-09-16 09:25:27,535 org.nutz.ioc.loader.annotation.AnnotationIocLoader.<init>(AnnotationIocLoader.java:52) INFO  - Found 8 classes in 1 base-packages!
beans = ["cleanNonActiveUserJob", "authorityService", "userProfileModule", "captchaModule", "authorityModule", "userModule", "emailService", "userService"]
2017-09-16 09:25:27,541 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:40) DEBUG - Loaded 5 bean define from reader --
[txREPEATABLE_READ, txSERIALIZABLE, txNONE, txREAD_UNCOMMITTED, txREAD_COMMITTED]
2017-09-16 09:25:27,542 org.nutz.ioc.loader.combo.ComboIocLoader.createIocLoader(ComboIocLoader.java:110) DEBUG - found jedis -- org.nutz.integration.jedis.JedisIocLoader
2017-09-16 09:25:27,545 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( org/nutz/integration/jedis/jedis.js ) , regex( ^(.+[.])(js|json)$ )
2017-09-16 09:25:27,546 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [org/nutz/integration/jedis/jedis.js]
2017-09-16 09:25:27,547 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 9 bean define from path=[org/nutz/integration/jedis/jedis.js] --> [redisService, jedisCluster, jedisClusterNodes, jedisClusterWrapper, pubSubService, jedisPoolConfig, jedisPool, jedisAgent, redis]
2017-09-16 09:25:27,551 org.nutz.ioc.loader.combo.ComboIocLoader.createIocLoader(ComboIocLoader.java:110) DEBUG - found quartz -- org.nutz.integration.quartz.QuartzIocLoader
2017-09-16 09:25:27,554 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 0 bean define from path=[] --> []
2017-09-16 09:25:27,558 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:98) INFO  - NutIoc init begin ...
2017-09-16 09:25:27,563 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:115) INFO  - ... NutIoc init complete
2017-09-16 09:25:27,568 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:159) INFO  - Build URL mapping by org.nutz.mvc.impl.UrlMappingImpl ...
2017-09-16 09:25:27,572 org.nutz.mvc.impl.NutLoading.createViewMakers(NutLoading.java:366) DEBUG - @Views(DefaultViewMaker.class)
2017-09-16 09:25:27,585 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( mvc/nutzbook-mvc-chain.js ) , regex( ^(.+[.])(js|json)$ )
2017-09-16 09:25:27,591 org.nutz.mvc.impl.chainconfig.JsonActionChainMakerConfiguretion.<init>(JsonActionChainMakerConfiguretion.java:37) DEBUG - ActionChain Config:
{
   "default": {
      "ps": ["net.wendal.nutzbook.mvc.LogTimeProcessor", "org.nutz.mvc.impl.processor.UpdateRequestAttributesProcessor", "org.nutz.mvc.impl.processor.EncodingProcessor", "org.nutz.mvc.impl.processor.ModuleProcessor", "org.nutz.integration.shiro.NutShiroProcessor", "org.nutz.mvc.impl.processor.ActionFiltersProcessor", "org.nutz.mvc.impl.processor.AdaptorProcessor", "org.nutz.mvc.impl.processor.MethodInvokeProcessor", "org.nutz.mvc.impl.processor.ViewProcessor"],
      "error": "org.nutz.mvc.impl.processor.FailProcessor"
   }
}
2017-09-16 09:25:27,591 org.nutz.mvc.impl.NutLoading.createChainMaker(NutLoading.java:263) DEBUG - @ChainBy(org.nutz.mvc.impl.NutActionChainMaker)
2017-09-16 09:25:27,596 org.nutz.mvc.impl.Loadings.scanModules(Loadings.java:154) DEBUG - module class location 'file:/E:/Work/InstelliJIDEAR_WorkSpaceNo.1/nutzbook/target/nutzbook-1.0-SNAPSHOT/WEB-INF/classes/'
2017-09-16 09:25:27,596 org.nutz.mvc.impl.Loadings.scanModuleInPackage(Loadings.java:184) DEBUG -  > scan 'net.wendal.nutzbook'
2017-09-16 09:25:27,603 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 23 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-16 09:25:27,604 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.AuthorityModule'
2017-09-16 09:25:27,605 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.CaptchaModule'
2017-09-16 09:25:27,605 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserModule'
2017-09-16 09:25:27,605 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserProfileModule'
2017-09-16 09:25:27,688 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/'                    >> (UserModule.java:63).index            : void       | @Ok(jsp:jsp.user.list) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,714 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/add'                 >> (UserModule.java:106).add             : Object     | @Ok(json ) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,720 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/update'              >> (UserModule.java:74).update           : Object     | @Ok(json ) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,721 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/delete'              >> (UserModule.java:84).delete           : Object     | @Ok(json ) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,731 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/query'               >> (UserModule.java:95).query            : Object     | @Ok(json ) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,735 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/logout'              >> (UserModule.java:68).logout           : void       | @Ok(>>:/ ) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,738 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/login'               >> (UserModule.java:46).login            : Object     | @Ok(json ) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,739 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/goon'                >> (UserModule.java:38).loginPage        : void       | @Ok(jsp:jsp.user.login) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,746 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/'            >> (UserProfileModule.java:90).index     : UserProfile | @Ok(jsp:jsp.user.profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,748 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/get'         >> (UserProfileModule.java:46).get       : UserProfile | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,758 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/update'      >> (UserProfileModule.java:62).update    : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,762 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:158).readAvatar : Object     | @Ok(raw:jpg) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,764 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:97).activeMail : Object     | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,788 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:23) INFO  - Init file-pool by: E:/Work/InstelliJIDEAR_WorkSpaceNo.1/nutzbook/target/nutzbook-1.0-SNAPSHOT/WEB-INF/tmp/user_avatar [20000]
2017-09-16 09:25:27,791 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:37) DEBUG - file-pool.home: 'E:\Work\InstelliJIDEAR_WorkSpaceNo.1\nutzbook\target\nutzbook-1.0-SNAPSHOT\WEB-INF\tmp\user_avatar'
2017-09-16 09:25:27,793 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:66) INFO  - file-pool.cursor: 0
2017-09-16 09:25:27,800 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:172).uploadAvatar : void       | @Ok(>>:/user/profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,802 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:124).activeMailCallback : String     | @Ok(raw  ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,804 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/permissions' >> (AuthorityModule.java:72).permissions : Object     | @Ok(json ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,877 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/users'    >> (AuthorityModule.java:52).users       : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,879 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/roles'    >> (AuthorityModule.java:62).roles       : Object     | @Ok(json ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,880 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/role/add' >> (AuthorityModule.java:177).addRole    : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,880 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/permission/add' >> (AuthorityModule.java:266).addPermission : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,881 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/permission/delete' >> (AuthorityModule.java:280).delPermission : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,882 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/user/fetch/role' >> (AuthorityModule.java:154).fetchUserRoles : Object     | @Ok(json ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,883 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/role/delete' >> (AuthorityModule.java:190).delRole    : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,884 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/permission/update' >> (AuthorityModule.java:294).updateRole : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,885 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/role/update' >> (AuthorityModule.java:210).updateRole : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,885 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/user/update' >> (AuthorityModule.java:91).updateUser  : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,886 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/role/fetch' >> (AuthorityModule.java:243).fetchRolePermissions : Object     | @Ok(json ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,887 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/user/fetch/permission' >> (AuthorityModule.java:135).fetchUserPermissions : Object     | @Ok(json ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,890 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/captcha/next'             >> (CaptchaModule.java:23).next          : BufferedImage | @Ok(raw:png) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-16 09:25:27,890 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:217) INFO  - Found 29 module methods
2017-09-16 09:25:27,891 org.nutz.mvc.impl.NutLoading.evalLocalization(NutLoading.java:303) DEBUG - Localization: org.nutz.mvc.impl.NutMessageLoader('msg/')  dft<zh-CN>
2017-09-16 09:25:27,897 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( msg/ ) , regex( ^.+[.]properties$ )
2017-09-16 09:25:27,898 org.nutz.mvc.impl.NutMessageLoader.load(NutMessageLoader.java:27) DEBUG - Load Messages in 1 resource : [[File[E:\Work\InstelliJIDEAR_WorkSpaceNo.1\nutzbook\target\nutzbook-1.0-SNAPSHOT\WEB-INF\classes\msg\zh-CN\user.properties]]]
2017-09-16 09:25:27,899 org.nutz.mvc.impl.NutMessageLoader.load(NutMessageLoader.java:95) DEBUG - Message Loaded, size = 2
2017-09-16 09:25:27,903 org.nutz.mvc.impl.NutLoading.createSessionProvider(NutLoading.java:410) INFO  - SessionBy --> org.nutz.integration.shiro.ShiroSessionProvider@3dc057e1
2017-09-16 09:25:27,903 org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:271) INFO  - Setup application...
2017-09-16 09:25:27,905 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-16 09:25:27,907 org.nutz.ioc.aop.SimpleAopMaker.<init>(SimpleAopMaker.java:79) DEBUG - Load AopConfigure for anno=org.nutz.ioc.aop.Aop by type=org.nutz.ioc.aop.config.impl.AnnotationAopConfigration
2017-09-16 09:25:27,908 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dao
2017-09-16 09:25:27,909 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dao
2017-09-16 09:25:27,926 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dao) in JsonLoader(paths=[ioc/])
2017-09-16 09:25:27,926 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dao'<interface org.nutz.dao.Dao>
2017-09-16 09:25:27,941 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.dao.impl.NutDao without AOP
2017-09-16 09:25:27,942 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dao' to [app] 
2017-09-16 09:25:27,945 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2017-09-16 09:25:27,945 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dataSource
2017-09-16 09:25:27,946 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dataSource
2017-09-16 09:25:27,960 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dataSource) in JsonLoader(paths=[ioc/])
2017-09-16 09:25:27,960 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dataSource'<>
2017-09-16 09:25:27,982 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class com.alibaba.druid.pool.DruidDataSource without AOP
2017-09-16 09:25:27,983 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dataSource' to [app] 
2017-09-16 09:25:27,985 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:27,985 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=conf
2017-09-16 09:25:27,985 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=conf
2017-09-16 09:25:27,985 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(conf) in JsonLoader(paths=[ioc/])
2017-09-16 09:25:27,985 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'conf'<>
2017-09-16 09:25:27,986 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.ioc.impl.PropertiesProxy without AOP
2017-09-16 09:25:27,986 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'conf' to [app] 
2017-09-16 09:25:28,052 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 3 resource by src( custom/ ) , regex( ^.+[.]properties$ )
2017-09-16 09:25:28,053 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[E:\Work\InstelliJIDEAR_WorkSpaceNo.1\nutzbook\target\nutzbook-1.0-SNAPSHOT\WEB-INF\classes\custom\cron.properties]
2017-09-16 09:25:28,053 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[E:\Work\InstelliJIDEAR_WorkSpaceNo.1\nutzbook\target\nutzbook-1.0-SNAPSHOT\WEB-INF\classes\custom\db.properties]
2017-09-16 09:25:28,054 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[E:\Work\InstelliJIDEAR_WorkSpaceNo.1\nutzbook\target\nutzbook-1.0-SNAPSHOT\WEB-INF\classes\custom\mail.properties]
2017-09-16 09:25:28,492 com.alibaba.druid.pool.DruidDataSource.init(DruidDataSource.java:715) INFO  - {dataSource-1} inited
2017-09-16 09:25:28,493 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2017-09-16 09:25:28,812 org.nutz.dao.jdbc.Jdbcs.<clinit>(Jdbcs.java:90) DEBUG - Jdbcs init complete
2017-09-16 09:25:28,813 org.nutz.dao.jdbc.Jdbcs.getExpert(Jdbcs.java:103) INFO  - Get Connection from DataSource for JdbcExpert, if you lock at here, check your database server and configure
Sat Sep 16 09:25:28 CST 2017 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
2017-09-16 09:25:29,114 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:188) DEBUG - select expert : org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert
2017-09-16 09:25:29,120 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:199) DEBUG - JDBC Driver --> mysql-connector-java-5.1.40 ( Revision: 402933ef52cad9aa82624e80acbea46e3a701ce6 )
2017-09-16 09:25:29,121 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:200) DEBUG - JDBC Name   --> MySQL Connector Java
2017-09-16 09:25:29,121 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:202) DEBUG - JDBC URL    --> jdbc:mysql://127.0.0.1:3306/nutzbook
2017-09-16 09:25:29,223 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_client=utf8
2017-09-16 09:25:29,224 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_connection=utf8
2017-09-16 09:25:29,224 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_database=utf8
2017-09-16 09:25:29,224 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_filesystem=binary
2017-09-16 09:25:29,224 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_results=
2017-09-16 09:25:29,224 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_server=utf8
2017-09-16 09:25:29,224 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_system=utf8
2017-09-16 09:25:29,225 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_sets_dir=C:\Program Files\MySQL\MySQL Server 5.7\share\charsets\
2017-09-16 09:25:29,228 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:213) DEBUG - Mysql : binlog_format=ROW
2017-09-16 09:25:29,228 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:220) DEBUG - Mysql : database=nutzbook
2017-09-16 09:25:29,229 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:226) DEBUG - Mysql : user=root@localhost
2017-09-16 09:25:29,266 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:221) DEBUG - Database info --> MYSQL:[MySQL - 5.7.17-log]
2017-09-16 09:25:29,270 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cacheExecutor'<>
2017-09-16 09:25:29,270 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=cacheExecutor
2017-09-16 09:25:29,270 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=cacheExecutor
2017-09-16 09:25:29,273 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(cacheExecutor) in JsonLoader(paths=[ioc/])
2017-09-16 09:25:29,273 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'cacheExecutor'<>
2017-09-16 09:25:29,275 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.plugins.cache.dao.DaoCacheInterceptor without AOP
2017-09-16 09:25:29,275 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'cacheExecutor' to [app] 
2017-09-16 09:25:29,301 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cacheProvider'<>
2017-09-16 09:25:29,301 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=cacheProvider
2017-09-16 09:25:29,301 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=cacheProvider
2017-09-16 09:25:29,304 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(cacheProvider) in JsonLoader(paths=[ioc/])
2017-09-16 09:25:29,304 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'cacheProvider'<>
2017-09-16 09:25:29,306 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.plugins.cache.dao.impl.provider.EhcacheDaoCacheProvider without AOP
2017-09-16 09:25:29,307 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'cacheProvider' to [app] 
2017-09-16 09:25:29,318 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cacheManager'<>
2017-09-16 09:25:29,319 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=cacheManager
2017-09-16 09:25:29,319 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=cacheManager
2017-09-16 09:25:29,319 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(cacheManager) in JsonLoader(paths=[ioc/])
2017-09-16 09:25:29,319 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'cacheManager'<>
2017-09-16 09:25:29,323 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.sf.ehcache.CacheManager without AOP
2017-09-16 09:25:29,323 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'cacheManager' to [app] 
2017-09-16 09:25:29,336 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 23 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-16 09:25:29,424 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT COUNT(*) FROM t_user 
2017-09-16 09:25:29,427 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'nutQuartzCronJobFactory'<class org.nutz.integration.quartz.NutQuartzCronJobFactory>
2017-09-16 09:25:29,427 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=nutQuartzCronJobFactory
2017-09-16 09:25:29,428 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=nutQuartzCronJobFactory
2017-09-16 09:25:29,428 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(nutQuartzCronJobFactory) in QuartzIocLoader@962563564
2017-09-16 09:25:29,428 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'nutQuartzCronJobFactory'<class org.nutz.integration.quartz.NutQuartzCronJobFactory>
2017-09-16 09:25:29,430 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.integration.quartz.NutQuartzCronJobFactory without AOP
2017-09-16 09:25:29,430 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'nutQuartzCronJobFactory' to [app] 
2017-09-16 09:25:29,435 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'scheduler'<>
2017-09-16 09:25:29,435 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=scheduler
2017-09-16 09:25:29,435 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=scheduler
2017-09-16 09:25:29,436 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(scheduler) in QuartzIocLoader@962563564
2017-09-16 09:25:29,436 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'scheduler'<>
2017-09-16 09:25:29,436 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'scheduler' to [app] 
2017-09-16 09:25:29,483 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1184) INFO  - Using default implementation for ThreadExecutor
2017-09-16 09:25:29,501 org.quartz.core.SchedulerSignalerImpl.<init>(SchedulerSignalerImpl.java:61) INFO  - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2017-09-16 09:25:29,502 org.quartz.core.QuartzScheduler.<init>(QuartzScheduler.java:240) INFO  - Quartz Scheduler v.2.2.1 created.
2017-09-16 09:25:29,503 org.quartz.simpl.RAMJobStore.initialize(RAMJobStore.java:155) INFO  - RAMJobStore initialized.
2017-09-16 09:25:29,503 org.quartz.core.QuartzScheduler.initialize(QuartzScheduler.java:305) INFO  - Scheduler meta-data: Quartz Scheduler (v2.2.1) 'NutzbookScheduler' with instanceId 'NON_CLUSTERED'
  Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
  NOT STARTED.
  Currently in standby mode.
  Number of jobs executed: 0
  Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 3 threads.
  Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.

2017-09-16 09:25:29,503 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1339) INFO  - Quartz scheduler 'NutzbookScheduler' initialized from default resource file in Quartz package: 'quartz.properties'
2017-09-16 09:25:29,503 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1343) INFO  - Quartz scheduler version: 2.2.1
2017-09-16 09:25:29,504 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'jobFactory'<>
2017-09-16 09:25:29,504 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=jobFactory
2017-09-16 09:25:29,504 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=jobFactory
2017-09-16 09:25:29,505 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(jobFactory) in QuartzIocLoader@962563564
2017-09-16 09:25:29,505 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'jobFactory'<>
2017-09-16 09:25:29,506 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.integration.quartz.NutQuartzJobFactory without AOP
2017-09-16 09:25:29,506 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'jobFactory' to [app] 
2017-09-16 09:25:29,555 org.quartz.core.QuartzScheduler.setJobFactory(QuartzScheduler.java:2311) INFO  - JobFactory set to: org.nutz.integration.quartz.NutQuartzJobFactory@441c9153
2017-09-16 09:25:29,555 org.quartz.core.QuartzScheduler.start(QuartzScheduler.java:575) INFO  - Scheduler NutzbookScheduler_$_NON_CLUSTERED started.
2017-09-16 09:25:29,555 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-16 09:25:29,556 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:29,556 org.nutz.integration.quartz.NutQuartzCronJobFactory.init(NutQuartzCronJobFactory.java:35) DEBUG - job define name=net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob cron=0 0/60 * * * ?
2017-09-16 09:25:29,572 org.nutz.integration.quartz.NutQuartzCronJobFactory.init(NutQuartzCronJobFactory.java:28) DEBUG - found cron job packages = net.wendal.nutzbook.quartz.job
2017-09-16 09:25:29,572 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-16 09:25:29,573 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( net/wendal/nutzbook/quartz/job/ ) , regex( ^.+[.]class$ )
2017-09-16 09:25:29,577 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'htmlEmail'<class org.apache.commons.mail.HtmlEmail>
2017-09-16 09:25:29,577 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=htmlEmail
2017-09-16 09:25:29,578 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=htmlEmail
2017-09-16 09:25:29,579 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(htmlEmail) in JsonLoader(paths=[ioc/])
2017-09-16 09:25:29,580 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'htmlEmail'<class org.apache.commons.mail.HtmlEmail>
2017-09-16 09:25:29,596 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.apache.commons.mail.ImageHtmlEmail without AOP
2017-09-16 09:25:29,690 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:29,694 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:29,695 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'emailAuthenticator'<>
2017-09-16 09:25:29,695 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=emailAuthenticator
2017-09-16 09:25:29,695 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=emailAuthenticator
2017-09-16 09:25:29,695 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(emailAuthenticator) in JsonLoader(paths=[ioc/])
2017-09-16 09:25:29,696 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'emailAuthenticator'<>
2017-09-16 09:25:29,697 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.apache.commons.mail.DefaultAuthenticator without AOP
2017-09-16 09:25:29,697 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'emailAuthenticator' to [app] 
2017-09-16 09:25:29,698 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:29,698 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:29,699 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:29,699 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:29,701 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:29,702 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:29,716 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:30,600 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'authorityService'<interface net.wendal.nutzbook.service.AuthorityService>
2017-09-16 09:25:30,601 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=authorityService
2017-09-16 09:25:30,601 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(authorityService) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-16 09:25:30,601 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'authorityService'<interface net.wendal.nutzbook.service.AuthorityService>
2017-09-16 09:25:30,602 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.service.AuthorityServiceImpl without AOP
2017-09-16 09:25:30,602 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'authorityService' to [app] 
2017-09-16 09:25:30,614 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-16 09:25:30,621 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 23 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-16 09:25:30,624 net.wendal.nutzbook.service.AuthorityServiceImpl.initFormPackage(AuthorityServiceImpl.java:59) DEBUG - found 15 permission
2017-09-16 09:25:30,624 net.wendal.nutzbook.service.AuthorityServiceImpl.initFormPackage(AuthorityServiceImpl.java:60) DEBUG - found 0 role
2017-09-16 09:25:30,631 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM t_permission 
2017-09-16 09:25:30,653 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM t_role 
2017-09-16 09:25:30,672 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM t_user  WHERE name=?
    |     1 |
    |-------|
    | admin |
  For example:> "SELECT * FROM t_user  WHERE name='admin'"
2017-09-16 09:25:30,685 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM t_role  WHERE name=?
    |     1 |
    |-------|
    | admin |
  For example:> "SELECT * FROM t_role  WHERE name='admin'"
2017-09-16 09:25:30,698 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT COUNT(*) FROM t_user_role  WHERE u_id=? AND role_id=?
    | 1 | 2 |
    |---|---|
    | 1 | 1 |
  For example:> "SELECT COUNT(*) FROM t_user_role  WHERE u_id=1 AND role_id=1"
2017-09-16 09:25:30,702 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM t_role_permission  WHERE role_id=?
    | 1 |
    |---|
    | 1 |
  For example:> "SELECT * FROM t_role_permission  WHERE role_id=1"
2017-09-16 09:25:30,706 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM t_permission  WHERE name LIKE ? OR name LIKE ? OR name LIKE ?
    |           1 |      2 |       3 |
    |-------------|--------|---------|
    | authority:% | user:% | topic:% |
  For example:> "SELECT * FROM t_permission  WHERE name LIKE 'authority:%' OR name LIKE 'user:%' OR name LIKE 'topic:%'"
2017-09-16 09:25:30,713 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cacheManager'<class net.sf.ehcache.CacheManager>
2017-09-16 09:25:30,713 net.wendal.nutzbook.MainSetup.init(MainSetup.java:54) DEBUG - Ehcache CacheManager = nutzbook
2017-09-16 09:25:30,715 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'jedisAgent'<class org.nutz.integration.jedis.JedisAgent>
2017-09-16 09:25:30,715 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=jedisAgent
2017-09-16 09:25:30,716 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=jedisAgent
2017-09-16 09:25:30,716 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(jedisAgent) in JedisIocLoader@196580791
2017-09-16 09:25:30,716 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'jedisAgent'<class org.nutz.integration.jedis.JedisAgent>
2017-09-16 09:25:30,794 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.integration.jedis.JedisAgent without AOP
2017-09-16 09:25:30,794 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'jedisAgent' to [app] 
2017-09-16 09:25:30,814 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:30,815 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'jedisPool'<class redis.clients.util.Pool>
2017-09-16 09:25:30,815 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=jedisPool
2017-09-16 09:25:30,815 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=jedisPool
2017-09-16 09:25:30,816 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(jedisPool) in JedisIocLoader@196580791
2017-09-16 09:25:30,817 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'jedisPool'<class redis.clients.util.Pool>
2017-09-16 09:25:30,819 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class redis.clients.jedis.JedisPool without AOP
2017-09-16 09:25:30,820 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'jedisPool' to [app] 
2017-09-16 09:25:30,822 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'jedisPoolConfig'<>
2017-09-16 09:25:30,822 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=jedisPoolConfig
2017-09-16 09:25:30,822 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=jedisPoolConfig
2017-09-16 09:25:30,823 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(jedisPoolConfig) in JedisIocLoader@196580791
2017-09-16 09:25:30,823 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'jedisPoolConfig'<>
2017-09-16 09:25:30,823 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class redis.clients.jedis.JedisPoolConfig without AOP
2017-09-16 09:25:30,823 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'jedisPoolConfig' to [app] 
2017-09-16 09:25:30,869 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:30,871 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:30,871 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:30,872 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:30,872 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:30,872 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:30,872 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'jedisPoolConfig'<>
2017-09-16 09:25:30,872 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:30,873 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:30,873 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:30,873 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:30,873 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-16 09:25:30,953 net.wendal.nutzbook.MainSetup.init(MainSetup.java:59) DEBUG - redis say : OK
2017-09-16 09:25:30,954 net.wendal.nutzbook.MainSetup.init(MainSetup.java:61) DEBUG - redis say : http://nutzbook.wendal.net
2017-09-16 09:25:30,955 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:141) INFO  - Nutz.Mvc[nutz] is up in 3690ms
2017-09-16 09:25:30,955 org.nutz.mvc.NutFilter._init(NutFilter.java:117) INFO  - exclusionsPrefix  = ^(/rs/|/druid/)
[2017-09-16 09:25:30,995] Artifact nutzbook:war exploded: Artifact is deployed successfully
[2017-09-16 09:25:30,995] Artifact nutzbook:war exploded: Deploy took 8,284 milliseconds
16-Sep-2017 09:25:32.244 信息 [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\webapps\manager
16-Sep-2017 09:25:32.317 信息 [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory E:\Work\InstelliJIDEAR_TomcatNo.2\apache-tomcat-8.5.14\webapps\manager has finished in 72 ms
2017-09-16 09:25:32,568 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/captcha/next : CaptchaModule.next(CaptchaModule.java:23)
2017-09-16 09:25:32,570 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-16 09:25:32,570 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=captchaModule
2017-09-16 09:25:32,570 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(captchaModule) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-16 09:25:32,570 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-16 09:25:32,571 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.module.CaptchaModule without AOP
2017-09-16 09:25:32,571 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'captchaModule' to [app] 
2017-09-16 09:25:32,942 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:24) DEBUG - [ GET]URI=/nutzbook/user/goon/captcha/next 374ms
2017-09-16 09:25:51,801 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [POST] path=/user/login : UserModule.login(UserModule.java:46)
2017-09-16 09:25:51,801 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userModule'<class net.wendal.nutzbook.module.UserModule>
2017-09-16 09:25:51,802 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=userModule
2017-09-16 09:25:51,802 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(userModule) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-16 09:25:51,802 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'userModule'<class net.wendal.nutzbook.module.UserModule>
2017-09-16 09:25:51,803 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'txREAD_COMMITTED'<interface org.nutz.aop.MethodInterceptor>
2017-09-16 09:25:51,803 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=txREAD_COMMITTED
2017-09-16 09:25:51,803 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=txREAD_COMMITTED
2017-09-16 09:25:51,805 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(txREAD_COMMITTED) in TransIocLoader@1738139189
2017-09-16 09:25:51,805 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'txREAD_COMMITTED'<interface org.nutz.aop.MethodInterceptor>
2017-09-16 09:25:51,806 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'txREAD_COMMITTED' to [app] 
2017-09-16 09:25:51,817 org.nutz.aop.asm.AsmClassAgent.<clinit>(AsmClassAgent.java:29) DEBUG - AsmClassAgent will define class in Version 50
2017-09-16 09:25:51,830 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'userModule' to [app] 
2017-09-16 09:25:51,844 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userService'<class net.wendal.nutzbook.service.UserService>
2017-09-16 09:25:51,844 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=userService
2017-09-16 09:25:51,844 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(userService) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-16 09:25:51,844 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'userService'<class net.wendal.nutzbook.service.UserService>
2017-09-16 09:25:51,844 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.service.UserService without AOP
2017-09-16 09:25:51,845 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'userService' to [app] 
2017-09-16 09:25:51,912 org.nutz.service.EntityService.<init>(EntityService.java:41) DEBUG - Get TypeParams for self : net.wendal.nutzbook.bean.User
2017-09-16 09:25:51,912 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<>
2017-09-16 09:25:51,915 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-16 09:25:51,915 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cacheManager'<class net.sf.ehcache.CacheManager>
2017-09-16 09:25:51,915 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'emailService'<interface net.wendal.nutzbook.service.EmailService>
2017-09-16 09:25:51,915 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=emailService
2017-09-16 09:25:51,915 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(emailService) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-16 09:25:51,916 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'emailService'<interface net.wendal.nutzbook.service.EmailService>
2017-09-16 09:25:51,916 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.service.EmailServiceImpl without AOP
2017-09-16 09:25:51,916 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'emailService' to [app] 
2017-09-16 09:25:51,926 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:24) DEBUG - [POST]URI=/nutzbook/user/goon/user/login 124ms
2017-09-16 09:25:53,597 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/captcha/next : CaptchaModule.next(CaptchaModule.java:23)
2017-09-16 09:25:53,598 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-16 09:25:53,626 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:24) DEBUG - [ GET]URI=/nutzbook/user/goon/captcha/next 28ms
2017-09-16 09:25:55,055 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/captcha/next : CaptchaModule.next(CaptchaModule.java:23)
2017-09-16 09:25:55,055 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-16 09:25:55,075 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:24) DEBUG - [ GET]URI=/nutzbook/user/goon/captcha/next 20ms
2017-09-16 09:25:56,662 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/captcha/next : CaptchaModule.next(CaptchaModule.java:23)
2017-09-16 09:25:56,663 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-16 09:25:56,682 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:24) DEBUG - [ GET]URI=/nutzbook/user/goon/captcha/next 19ms
2017-09-16 09:25:57,906 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-16 09:26:06,751 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [POST] path=/user/login : UserModule.login(UserModule.java:46)
2017-09-16 09:26:06,751 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userModule'<class net.wendal.nutzbook.module.UserModule>
2017-09-16 09:26:06,752 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM t_user  WHERE name=?
    |     1 |
    |-------|
    | admin |
  For example:> "SELECT * FROM t_user  WHERE name='admin'"
2017-09-16 09:26:06,768 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-16 09:26:06,768 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM t_user  WHERE id=?
    | 1 |
    |---|
    | 1 |
  For example:> "SELECT * FROM t_user  WHERE id=1"
2017-09-16 09:26:06,777 org.apache.shiro.realm.AuthenticatingRealm.getAuthenticationInfo(AuthenticatingRealm.java:569) DEBUG - Looked up AuthenticationInfo [1] from doGetAuthenticationInfo
2017-09-16 09:26:06,777 org.apache.shiro.realm.AuthenticatingRealm.cacheAuthenticationInfoIfPossible(AuthenticatingRealm.java:507) DEBUG - AuthenticationInfo caching is disabled for info [1].  Submitted token: [org.nutz.integration.shiro.SimpleShiroToken@54ecf583].
2017-09-16 09:26:06,778 org.apache.shiro.authc.AbstractAuthenticator.authenticate(AbstractAuthenticator.java:233) DEBUG - Authentication successful for token [org.nutz.integration.shiro.SimpleShiroToken@54ecf583].  Returned account [1]
2017-09-16 09:26:06,778 org.apache.shiro.subject.support.DefaultSubjectContext.resolveSecurityManager(DefaultSubjectContext.java:102) DEBUG - No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
2017-09-16 09:26:06,778 org.apache.shiro.mgt.DefaultSecurityManager.resolveSession(DefaultSecurityManager.java:436) DEBUG - Context already contains a session.  Returning.
2017-09-16 09:26:06,778 org.apache.shiro.subject.support.DefaultSubjectContext.resolveSecurityManager(DefaultSubjectContext.java:102) DEBUG - No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
2017-09-16 09:26:06,779 org.apache.shiro.web.servlet.SimpleCookie.addCookieHeader(SimpleCookie.java:226) DEBUG - Added HttpServletResponse Cookie [rememberMe=deleteMe; Path=/nutzbook/user/goon; Max-Age=0; Expires=Fri, 15-Sep-2017 01:26:06 GMT]
2017-09-16 09:26:06,779 org.apache.shiro.mgt.AbstractRememberMeManager.onSuccessfulLogin(AbstractRememberMeManager.java:290) DEBUG - AuthenticationToken did not indicate RememberMe is requested.  RememberMe functionality will not be executed for corresponding account.
2017-09-16 09:26:06,780 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:24) DEBUG - [POST]URI=/nutzbook/user/goon/user/login 29ms
2017-09-16 09:26:07,822 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/captcha/next : CaptchaModule.next(CaptchaModule.java:23)
2017-09-16 09:26:07,822 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-16 09:26:07,850 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:24) DEBUG - [ GET]URI=/nutzbook/user/goon/captcha/next 28ms
2017-09-16 09:26:27,683 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-16 09:26:51,276 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-16 09:27:18,841 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-16 09:27:43,864 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-16 09:28:09,046 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-16 09:28:38,181 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-16 09:29:05,983 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-16 09:29:32,247 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers

登陆成功了跳转到 我的ID是1

因为我集成shiro了，除了登陆和退出外，别的请求都显示“找不到 localhost 的网页”