用的是myeclipse没有maven；
清了以后还是这样T.T

@Wizzercn

兽哥，头疼，又是类找不到

@wendal

package net.wendal.nutzbook.module;

import java.awt.image.BufferedImage;

import javax.servlet.http.HttpSession;

import net.wendal.nutzbook.util.Toolkit;

import org.nutz.ioc.loader.annotation.IocBean;
import org.nutz.mvc.annotation.At;
import org.nutz.mvc.annotation.Ok;
import org.nutz.mvc.annotation.Param;

import cn.apiclub.captcha.Captcha;
import cn.apiclub.captcha.backgrounds.GradiatedBackgroundProducer;
import cn.apiclub.captcha.gimpy.FishEyeGimpyRenderer;

@IocBean
@At("/captcha")
public class CaptchaModule {
	@At
	@Ok("raw:png")
	public BufferedImage next(HttpSession session,
			@Param("w")int w,
			@Param("h")int h){
		if(w * h <1){//长或宽为0?重置为默认长宽.
			w =200;
			h =60;
		}
		Captcha captcha = new Captcha.Builder(w, h)
				.addText().addBackground(new GradiatedBackgroundProducer())
				.gimp(new FishEyeGimpyRenderer())
				.build();
		String text = captcha.getAnswer();
		session.setAttribute(Toolkit.captcha_attr, text);
		return captcha.getImage();
	/*raw代表RawView
	png是RawView中对image/png的缩写,是数据mime的描述
	返回值是BufferedImage,且这是image/png, 所以会转为图片显示. 
	还支持jpg/webp等格式,详情参考RawView的源码吧.
	Captcha有N多的组合和配置,自行选择啦.*/
	}
}

package net.wendal.nutzbook.quartz;


import java.util.Date;

import net.wendal.nutzbook.bean.User;
import net.wendal.nutzbook.bean.UserProfile;

import org.nutz.dao.Cnd;
import org.nutz.dao.Dao;
import org.nutz.dao.Sqls;
import org.nutz.dao.sql.Sql;
import org.nutz.ioc.loader.annotation.Inject;
import org.nutz.ioc.loader.annotation.IocBean;
import org.nutz.log.Log;
import org.nutz.log.Logs;
import org.quartz.Job;
import org.quartz.JobExecutionContext;

@IocBean
public class CleanNonActiveUserJob implements Job{
	private static final Log log=Logs.get();
	@Inject protected Dao dao;
	
	public void execute(JobExecutionContext context){
		log.debug("clean Non-Active User,start");
		Date deadtime = new Date(System.currentTimeMillis()-24*60*1000L);//一天 
		Cnd cnd = Cnd.where("userId",">",10).and("createTime","<",deadtime)
					 .and(Cnd.exps("emailChecked","=",false)
					 .or("email","IS",null));
		int deleted =dao.clear(UserProfile.class,cnd);
		log.debugf("delete %d UserProfile", deleted); 
		
		Sql sql =Sqls.create("delete from $user_table "
				+ "where id>10 and not exists "
				+ "(select 1 from $user_profile_table where $user_table.id=uid)"
				+ "and ct<@deadtime");
		sql.vars().set("user_table",dao.getEntity(User.class).getTableName());
		sql.vars().set("user_profile_table",dao.getEntity(UserProfile.class).getTableName());
		sql.params().set("deadtime", deadtime);
		dao.execute(sql);
		log.debugf("delete %d User", sql.getUpdateCount());
		
		log.debug("clean Non-Active User, Done");
		
		
	}
}

明明在呀.......

我的错 没有看见 job 为什么要加个job呀，，，，代码的路径哪里对应的job？？

看到了，，，谢谢兽哥

org.apache.commons.mail.EmailException: Sending the email to the following server failed : smtp.163.com:25
	at org.apache.commons.mail.Email.sendMimeMessage(Email.java:1410)
	at net.wendal.nutzbook.MainSetup.init(MainSetup.java:39)
	at org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:274)
	at org.nutz.mvc.impl.NutLoading.load(NutLoading.java:121)
	at org.nutz.mvc.ActionHandler.<init>(ActionHandler.java:19)
	at org.nutz.mvc.NutFilter._init(NutFilter.java:91)
	at org.nutz.mvc.NutFilter.init(NutFilter.java:69)
	at org.apache.catalina.core.ApplicationFilterConfig.initFilter(ApplicationFilterConfig.java:279)
	at org.apache.catalina.core.ApplicationFilterConfig.getFilter(ApplicationFilterConfig.java:260)
	at org.apache.catalina.core.ApplicationFilterConfig.<init>(ApplicationFilterConfig.java:105)
	at org.apache.catalina.core.StandardContext.filterStart(StandardContext.java:4659)
	at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5281)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
	at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:725)
	at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:701)
	at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:717)
	at org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.java:1101)
	at org.apache.catalina.startup.HostConfig$DeployDirectory.run(HostConfig.java:1813)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
Caused by: javax.mail.AuthenticationFailedException: 535 Error: authentication failed

	at com.sun.mail.smtp.SMTPTransport$Authenticator.authenticate(SMTPTransport.java:892)
	at com.sun.mail.smtp.SMTPTransport.authenticate(SMTPTransport.java:814)
	at com.sun.mail.smtp.SMTPTransport.protocolConnect(SMTPTransport.java:728)
	at javax.mail.Service.connect(Service.java:386)
	at javax.mail.Service.connect(Service.java:245)
	at javax.mail.Service.connect(Service.java:194)
	at javax.mail.Transport.send0(Transport.java:253)
	at javax.mail.Transport.send(Transport.java:124)
	at org.apache.commons.mail.Email.sendMimeMessage(Email.java:1400)
	... 22 more

现在还是报邮箱的错误

mail.HostName=smtp.163.com
mail.SmtpPort=25
mail.UserName=dessdesspk@163.com
mail.Password=dyh950309.
mail.SSLOnConnect=false
mail.From=dessdesspk@163.com
mail.charset=UTF-8

这样有问题吗 163的邮箱确实可以通过网易大师邮箱登录

嗯嗯 可能是163的邮箱有毛病 我换新浪的邮箱就好了 ~~~

可能还得请教一下兽哥，邮箱发送成功以后，邮箱并没有收到邮件 这是咋回事

九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server version:        Apache Tomcat/8.0.30
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server built:          Dec 1 2015 22:30:46 UTC
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server number:         8.0.30.0
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: OS Name:               Windows 7
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: OS Version:            6.1
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Architecture:          amd64
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Java Home:             C:\Program Files\Java\jdk1.7.0_79\jre
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: JVM Version:           1.7.0_79-b15
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: JVM Vendor:            Oracle Corporation
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: CATALINA_BASE:         D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: CATALINA_HOME:         D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dcatalina.home=D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dcatalina.base=D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Djava.endorsed.dirs=D:\MyEclipse\apache-tomcat-8.0.30/common/endorsed
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Djava.io.tmpdir=D:\MyEclipse\apache-tomcat-8.0.30\temp
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Djava.library.path=C:\Program Files\Java\jdk1.7.0_79\bin;D:\MyEclipse\apache-tomcat-8.0.30\bin
九月 12, 2017 3:21:30 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dsun.io.useCanonCaches=false
九月 12, 2017 3:21:30 下午 org.apache.catalina.core.AprLifecycleListener lifecycleEvent
信息: Loaded APR based Apache Tomcat Native library 1.1.33 using APR version 1.5.1.
九月 12, 2017 3:21:30 下午 org.apache.catalina.core.AprLifecycleListener lifecycleEvent
信息: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
九月 12, 2017 3:21:30 下午 org.apache.catalina.core.AprLifecycleListener initializeSSL
信息: OpenSSL successfully initialized (OpenSSL 1.0.1m 19 Mar 2015)
九月 12, 2017 3:21:31 下午 org.apache.coyote.AbstractProtocol init
信息: Initializing ProtocolHandler ["http-apr-8081"]
九月 12, 2017 3:21:31 下午 org.apache.coyote.AbstractProtocol init
信息: Initializing ProtocolHandler ["ajp-apr-8009"]
九月 12, 2017 3:21:31 下午 org.apache.catalina.startup.Catalina load
信息: Initialization processed in 1327 ms
九月 12, 2017 3:21:31 下午 org.apache.catalina.core.StandardService startInternal
信息: Starting service Catalina
九月 12, 2017 3:21:31 下午 org.apache.catalina.core.StandardEngine startInternal
信息: Starting Servlet Engine: Apache Tomcat/8.0.30
九月 12, 2017 3:21:31 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\docs
九月 12, 2017 3:21:32 下午 org.apache.catalina.util.SessionIdGeneratorBase createSecureRandom
信息: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [778] milliseconds.
九月 12, 2017 3:21:32 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\docs has finished in 1,217 ms
九月 12, 2017 3:21:32 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\examples
九月 12, 2017 3:21:32 下午 org.apache.catalina.core.ApplicationContext log
信息: ContextListener: contextInitialized()
九月 12, 2017 3:21:32 下午 org.apache.catalina.core.ApplicationContext log
信息: SessionListener: contextInitialized()
九月 12, 2017 3:21:32 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\examples has finished in 446 ms
九月 12, 2017 3:21:32 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\host-manager
九月 12, 2017 3:21:32 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\host-manager has finished in 34 ms
九月 12, 2017 3:21:32 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\manager
九月 12, 2017 3:21:32 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\manager has finished in 64 ms
九月 12, 2017 3:21:32 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\nutzbook
九月 12, 2017 3:21:33 下午 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.
九月 12, 2017 3:21:34 下午 org.apache.catalina.core.ApplicationContext log
信息: Initializing Shiro environment
2017-09-12 15:21:34,109 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:128) INFO  - Starting Shiro environment initialization.
2017-09-12 15:21:34,132 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:76) DEBUG - Checking any specified config locations.
2017-09-12 15:21:34,132 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:81) DEBUG - No INI instance or config locations specified.  Trying default config locations.
2017-09-12 15:21:34,139 org.apache.shiro.io.ResourceUtils.loadFromClassPath(ResourceUtils.java:159) DEBUG - Opening resource from class path [shiro.ini]
2017-09-12 15:21:34,148 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [main]
2017-09-12 15:21:34,148 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [urls]
2017-09-12 15:21:34,150 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-12 15:21:34,155 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=urls]
2017-09-12 15:21:34,382 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=urls]
2017-09-12 15:21:34,385 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/*] from String definition [anon]
2017-09-12 15:21:34,385 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/*] to filter [anon] with config [null]
2017-09-12 15:21:34,387 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-12 15:21:34,387 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:141) INFO  - Shiro environment initialized in 274 ms.
2017-09-12 15:21:34,413 org.nutz.mvc.NutFilter._init(NutFilter.java:85) INFO  - NutFilter[nutz] starting ...
2017-09-12 15:21:34,443 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=5 time use 14ms
2017-09-12 15:21:34,458 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=26 time use 15ms
2017-09-12 15:21:34,527 org.nutz.castor.Castors.reload(Castors.java:115) DEBUG - Using 95 castor for Castors
2017-09-12 15:21:34,552 org.nutz.mvc.config.AbstractNutConfig.createLoading(AbstractNutConfig.java:59) DEBUG - Loading by class org.nutz.mvc.impl.NutLoading
2017-09-12 15:21:34,554 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:55) INFO  - Nutz Version : 1.r.62 
2017-09-12 15:21:34,554 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:56) INFO  - Nutz.Mvc[nutz] is initializing ...
2017-09-12 15:21:34,554 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:60) DEBUG - Web Container Information:
2017-09-12 15:21:34,555 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:61) DEBUG -  - Default Charset : GBK
2017-09-12 15:21:34,556 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:62) DEBUG -  - Current . path  : D:\MyEclipse\apache-tomcat-8.0.30\bin\.
2017-09-12 15:21:34,556 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:63) DEBUG -  - Java Version    : 1.7.0_79
2017-09-12 15:21:34,556 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:64) DEBUG -  - File separator  : \
2017-09-12 15:21:34,556 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:65) DEBUG -  - Timezone        : Asia/Shanghai
2017-09-12 15:21:34,556 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:66) DEBUG -  - OS              : Windows 7 amd64
2017-09-12 15:21:34,556 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:67) DEBUG -  - ServerInfo      : Apache Tomcat/8.0.30
2017-09-12 15:21:34,556 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:68) DEBUG -  - Servlet API     : 3.1
2017-09-12 15:21:34,557 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:73) DEBUG -  - ContextPath     : /nutzbook
2017-09-12 15:21:34,557 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:74) DEBUG -  - context.tempdir : D:\MyEclipse\apache-tomcat-8.0.30\work\Catalina\localhost\nutzbook
2017-09-12 15:21:34,557 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:75) DEBUG -  - MainModule      : net.wendal.nutzbook.MainModule
2017-09-12 15:21:34,558 org.nutz.mvc.impl.NutLoading.createContext(NutLoading.java:235) DEBUG - >> app.root = D:/MyEclipse/apache-tomcat-8.0.30/webapps/nutzbook
2017-09-12 15:21:34,562 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", "*quartz"],init=[])
2017-09-12 15:21:34,626 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 2 resource by src( ioc/ ) , regex( ^(.+[.])(js|json)$ )
2017-09-12 15:21:34,627 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [dao.js]
2017-09-12 15:21:34,634 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [mail.js]
2017-09-12 15:21:34,635 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 5 bean define from path=[ioc/] --> [htmlEmail, dataSource, dao, conf, emailAuthenticator]
2017-09-12 15:21:34,651 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 14 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-12 15:21:34,676 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.CaptchaModule
2017-09-12 15:21:34,686 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserModule
2017-09-12 15:21:34,694 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserProfileModule
2017-09-12 15:21:34,707 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2017-09-12 15:21:34,710 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.EmailServiceImpl
2017-09-12 15:21:34,714 org.nutz.ioc.loader.annotation.AnnotationIocLoader.<init>(AnnotationIocLoader.java:52) INFO  - Found 5 classes in 1 base-packages!
beans = ["captchaModule", "cleanNonActiveUserJob", "userProfileModule", "emailService", "userModule"]
2017-09-12 15:21:34,722 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:40) DEBUG - Loaded 5 bean define from reader --
[txREPEATABLE_READ, txREAD_COMMITTED, txNONE, txSERIALIZABLE, txREAD_UNCOMMITTED]
2017-09-12 15:21:34,726 org.nutz.ioc.loader.combo.ComboIocLoader.createIocLoader(ComboIocLoader.java:110) DEBUG - found quartz -- org.nutz.integration.quartz.QuartzIocLoader
2017-09-12 15:21:34,732 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 0 bean define from path=[] --> []
2017-09-12 15:21:34,736 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:98) INFO  - NutIoc init begin ...
2017-09-12 15:21:34,738 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:115) INFO  - ... NutIoc init complete
2017-09-12 15:21:34,741 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:159) INFO  - Build URL mapping by org.nutz.mvc.impl.UrlMappingImpl ...
2017-09-12 15:21:34,744 org.nutz.mvc.impl.NutLoading.createViewMakers(NutLoading.java:366) DEBUG - @Views(DefaultViewMaker.class)
2017-09-12 15:21:34,756 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( mvc/nutzbook-mvc-chain.js ) , regex( ^(.+[.])(js|json)$ )
2017-09-12 15:21:34,762 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-12 15:21:34,762 org.nutz.mvc.impl.NutLoading.createChainMaker(NutLoading.java:263) DEBUG - @ChainBy(org.nutz.mvc.impl.NutActionChainMaker)
2017-09-12 15:21:34,765 org.nutz.mvc.impl.Loadings.scanModules(Loadings.java:154) DEBUG - module class location 'file:/D:/MyEclipse/apache-tomcat-8.0.30/webapps/nutzbook/WEB-INF/classes/'
2017-09-12 15:21:34,766 org.nutz.mvc.impl.Loadings.scanModuleInPackage(Loadings.java:184) DEBUG -  > scan 'net.wendal.nutzbook'
2017-09-12 15:21:34,769 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 14 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-12 15:21:34,770 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.CaptchaModule'
2017-09-12 15:21:34,771 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserModule'
2017-09-12 15:21:34,771 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserProfileModule'
2017-09-12 15:21:34,858 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/get'         >> (UserProfileModule.java:54).get       : UserProfile | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:34,859 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/'            >> (UserProfileModule.java:152).index    : UserProfile | @Ok(jsp:jsp.user.profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:34,868 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/update'      >> (UserProfileModule.java:72).update    : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:34,883 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:23) INFO  - Init file-pool by: D:/MyEclipse/apache-tomcat-8.0.30/webapps/nutzbook/WEB-INF/tmp/user_avatar [20000]
2017-09-12 15:21:34,885 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:37) DEBUG - file-pool.home: 'D:\MyEclipse\apache-tomcat-8.0.30\webapps\nutzbook\WEB-INF\tmp\user_avatar'
2017-09-12 15:21:34,886 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:66) INFO  - file-pool.cursor: 0
2017-09-12 15:21:34,891 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:106).uploadAvatar : void       | @Ok(>>:/user/profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:34,894 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:138).readAvatar : Object     | @Ok(raw:jpg) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:34,896 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:159).activeMail : Object     | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:34,898 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:187).activeMailCallback : String     | @Ok(raw  ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:34,899 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/captcha/next'             >> (CaptchaModule.java:26).next          : BufferedImage | @Ok(raw:png) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:34,999 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/add'                 >> (UserModule.java:83).add              : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:35,000 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/count'               >> (UserModule.java:46).count            : int        | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:35,001 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/'                    >> (UserModule.java:139).index           : void       | @Ok(jsp:jsp.user.list) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:35,003 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/delete'              >> (UserModule.java:113).delete          : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:35,005 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/update'              >> (UserModule.java:96).update           : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:35,014 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/query'               >> (UserModule.java:124).query           : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:35,015 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/login'               >> (UserModule.java:57).login            : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:35,017 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/logout'              >> (UserModule.java:76).logout           : void       | @Ok(>>:/ ) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 15:21:35,017 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:217) INFO  - Found 16 module methods
2017-09-12 15:21:35,018 org.nutz.mvc.impl.NutLoading.evalLocalization(NutLoading.java:331) DEBUG - @Localization not define
2017-09-12 15:21:35,018 org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:271) INFO  - Setup application...
2017-09-12 15:21:35,021 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-12 15:21:35,023 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-12 15:21:35,023 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dao
2017-09-12 15:21:35,024 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dao
2017-09-12 15:21:35,029 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dao) in JsonLoader(paths=[ioc/])
2017-09-12 15:21:35,029 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dao'<interface org.nutz.dao.Dao>
2017-09-12 15:21:35,041 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.dao.impl.NutDao without AOP
2017-09-12 15:21:35,042 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dao' to [app] 
2017-09-12 15:21:35,044 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2017-09-12 15:21:35,045 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dataSource
2017-09-12 15:21:35,045 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dataSource
2017-09-12 15:21:35,058 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dataSource) in JsonLoader(paths=[ioc/])
2017-09-12 15:21:35,058 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dataSource'<>
2017-09-12 15:21:35,076 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class com.alibaba.druid.pool.DruidDataSource without AOP
2017-09-12 15:21:35,076 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dataSource' to [app] 
2017-09-12 15:21:35,370 com.alibaba.druid.pool.DruidDataSource.init(DruidDataSource.java:669) INFO  - {dataSource-1} inited
2017-09-12 15:21:35,371 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2017-09-12 15:21:35,608 org.nutz.dao.jdbc.Jdbcs.<clinit>(Jdbcs.java:90) DEBUG - Jdbcs init complete
2017-09-12 15:21:35,609 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
2017-09-12 15:21:35,821 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:188) DEBUG - select expert : org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert
2017-09-12 15:21:35,827 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:199) DEBUG - JDBC Driver --> mysql-connector-java-5.1.34 ( Revision: jess.balint@oracle.com-20141014163213-wqbwpf1ok2kvo1om )
2017-09-12 15:21:35,827 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:200) DEBUG - JDBC Name   --> MySQL Connector Java
2017-09-12 15:21:35,827 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:202) DEBUG - JDBC URL    --> jdbc:mysql://127.0.0.1:3306/nutzbook
2017-09-12 15:21:35,837 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_client=utf8
2017-09-12 15:21:35,837 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_connection=utf8
2017-09-12 15:21:35,837 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_database=utf8
2017-09-12 15:21:35,837 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_filesystem=binary
2017-09-12 15:21:35,837 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_results=
2017-09-12 15:21:35,838 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_server=utf8
2017-09-12 15:21:35,838 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_system=utf8
2017-09-12 15:21:35,838 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-12 15:21:35,840 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:213) DEBUG - Mysql : binlog_format=ROW
2017-09-12 15:21:35,841 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:220) DEBUG - Mysql : database=nutzbook
2017-09-12 15:21:35,841 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:226) DEBUG - Mysql : user=root@localhost
2017-09-12 15:21:35,854 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:221) DEBUG - Database info --> MYSQL:[MySQL - 5.7.17-log]
2017-09-12 15:21:35,861 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 14 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-12 15:21:35,907 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT COUNT(*) FROM t_user 
2017-09-12 15:21:35,909 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'nutQuartzCronJobFactory'<class org.nutz.integration.quartz.NutQuartzCronJobFactory>
2017-09-12 15:21:35,909 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=nutQuartzCronJobFactory
2017-09-12 15:21:35,909 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=nutQuartzCronJobFactory
2017-09-12 15:21:35,909 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(nutQuartzCronJobFactory) in QuartzIocLoader@1017023675
2017-09-12 15:21:35,910 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'nutQuartzCronJobFactory'<class org.nutz.integration.quartz.NutQuartzCronJobFactory>
2017-09-12 15:21:35,911 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.integration.quartz.NutQuartzCronJobFactory without AOP
2017-09-12 15:21:35,911 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'nutQuartzCronJobFactory' to [app] 
2017-09-12 15:21:35,917 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'scheduler'<>
2017-09-12 15:21:35,917 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=scheduler
2017-09-12 15:21:35,917 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=scheduler
2017-09-12 15:21:35,918 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(scheduler) in QuartzIocLoader@1017023675
2017-09-12 15:21:35,918 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'scheduler'<>
2017-09-12 15:21:35,918 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'scheduler' to [app] 
2017-09-12 15:21:35,968 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1172) INFO  - Using default implementation for ThreadExecutor
2017-09-12 15:21:35,987 org.quartz.core.SchedulerSignalerImpl.<init>(SchedulerSignalerImpl.java:61) INFO  - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2017-09-12 15:21:35,987 org.quartz.core.QuartzScheduler.<init>(QuartzScheduler.java:240) INFO  - Quartz Scheduler v.2.2.3 created.
2017-09-12 15:21:35,988 org.quartz.simpl.RAMJobStore.initialize(RAMJobStore.java:155) INFO  - RAMJobStore initialized.
2017-09-12 15:21:35,988 org.quartz.core.QuartzScheduler.initialize(QuartzScheduler.java:305) INFO  - Scheduler meta-data: Quartz Scheduler (v2.2.3) '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-12 15:21:35,988 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1327) INFO  - Quartz scheduler 'NutzbookScheduler' initialized from default resource file in Quartz package: 'quartz.properties'
2017-09-12 15:21:35,989 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1331) INFO  - Quartz scheduler version: 2.2.3
2017-09-12 15:21:35,989 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'jobFactory'<>
2017-09-12 15:21:35,989 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=jobFactory
2017-09-12 15:21:35,989 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=jobFactory
2017-09-12 15:21:35,990 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(jobFactory) in QuartzIocLoader@1017023675
2017-09-12 15:21:35,990 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'jobFactory'<>
2017-09-12 15:21:35,991 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.integration.quartz.NutQuartzJobFactory without AOP
2017-09-12 15:21:35,991 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'jobFactory' to [app] 
2017-09-12 15:21:36,041 org.quartz.core.QuartzScheduler.setJobFactory(QuartzScheduler.java:2311) INFO  - JobFactory set to: org.nutz.integration.quartz.NutQuartzJobFactory@5655be75
2017-09-12 15:21:36,041 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:21:36,042 org.quartz.core.QuartzScheduler.start(QuartzScheduler.java:575) INFO  - Scheduler NutzbookScheduler_$_NON_CLUSTERED started.
2017-09-12 15:21:36,045 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-12 15:21:36,045 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=conf
2017-09-12 15:21:36,045 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=conf
2017-09-12 15:21:36,055 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(conf) in JsonLoader(paths=[ioc/])
2017-09-12 15:21:36,055 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'conf'<>
2017-09-12 15:21:36,056 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.ioc.impl.PropertiesProxy without AOP
2017-09-12 15:21:36,056 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'conf' to [app] 
2017-09-12 15:21:36,118 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 3 resource by src( custom/ ) , regex( ^.+[.]properties$ )
2017-09-12 15:21:36,118 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[D:\MyEclipse\apache-tomcat-8.0.30\webapps\nutzbook\WEB-INF\classes\custom\cron.properties]
2017-09-12 15:21:36,119 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[D:\MyEclipse\apache-tomcat-8.0.30\webapps\nutzbook\WEB-INF\classes\custom\db.properties]
2017-09-12 15:21:36,119 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[D:\MyEclipse\apache-tomcat-8.0.30\webapps\nutzbook\WEB-INF\classes\custom\mail.properties]
2017-09-12 15:21:36,120 org.nutz.integration.quartz.NutQuartzCronJobFactory.init(NutQuartzCronJobFactory.java:35) DEBUG - job define name=net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob cron=0 0/2 * * * ?
2017-09-12 15:21:36,134 org.nutz.integration.quartz.NutQuartzCronJobFactory.init(NutQuartzCronJobFactory.java:28) DEBUG - found cron job packages = net.wendal.nutzbook.quartz.job
2017-09-12 15:21:36,136 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( net/wendal/nutzbook/quartz/job/ ) , regex( ^.+[.]class$ )
2017-09-12 15:21:36,138 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 1 triggers
2017-09-12 15:21:36,141 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'htmlEmail'<class org.apache.commons.mail.HtmlEmail>
2017-09-12 15:21:36,142 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=htmlEmail
2017-09-12 15:21:36,142 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=htmlEmail
2017-09-12 15:21:36,144 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(htmlEmail) in JsonLoader(paths=[ioc/])
2017-09-12 15:21:36,144 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'htmlEmail'<class org.apache.commons.mail.HtmlEmail>
2017-09-12 15:21:36,155 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.apache.commons.mail.ImageHtmlEmail without AOP
2017-09-12 15:21:36,261 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-12 15:21:36,269 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-12 15:21:36,270 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'emailAuthenticator'<>
2017-09-12 15:21:36,270 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=emailAuthenticator
2017-09-12 15:21:36,270 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=emailAuthenticator
2017-09-12 15:21:36,270 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(emailAuthenticator) in JsonLoader(paths=[ioc/])
2017-09-12 15:21:36,270 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'emailAuthenticator'<>
2017-09-12 15:21:36,271 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.apache.commons.mail.DefaultAuthenticator without AOP
2017-09-12 15:21:36,271 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'emailAuthenticator' to [app] 
2017-09-12 15:21:36,272 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-12 15:21:36,272 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-12 15:21:36,272 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-12 15:21:36,272 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-12 15:21:36,274 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-12 15:21:36,275 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-12 15:21:36,279 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-12 15:21:37,252 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:141) INFO  - Nutz.Mvc[nutz] is up in 2695ms
九月 12, 2017 3:21:37 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\nutzbook has finished in 4,438 ms
九月 12, 2017 3:21:37 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\ROOT
九月 12, 2017 3:21:37 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\ROOT has finished in 20 ms
九月 12, 2017 3:21:37 下午 org.apache.coyote.AbstractProtocol start
信息: Starting ProtocolHandler ["http-apr-8081"]
九月 12, 2017 3:21:37 下午 org.apache.coyote.AbstractProtocol start
信息: Starting ProtocolHandler ["ajp-apr-8009"]
九月 12, 2017 3:21:37 下午 org.apache.catalina.startup.Catalina start
信息: Server startup in 6288 ms
2017-09-12 15:22:00,004 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cleanNonActiveUserJob'<class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob>
2017-09-12 15:22:00,004 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=cleanNonActiveUserJob
2017-09-12 15:22:00,004 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(cleanNonActiveUserJob) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-12 15:22:00,004 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'cleanNonActiveUserJob'<class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob>
2017-09-12 15:22:00,004 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob without AOP
2017-09-12 15:22:00,005 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'cleanNonActiveUserJob' to [app] 
2017-09-12 15:22:00,011 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-12 15:22:00,012 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:22:00,012 org.quartz.core.JobRunShell.run(JobRunShell.java:201) DEBUG - Calling execute on job DEFAULT.net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2017-09-12 15:22:00,012 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:26) DEBUG - clean Non-Active User,start
2017-09-12 15:22:00,031 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - DELETE FROM t_user_profile WHERE uid>? AND ct<? AND (email_checked=? OR email IS NULL )
    |  1 |                   2 |     3 |
    |----|---------------------|-------|
    | 10 | 2017-09-12 14:58:00 | false |
  For example:> "DELETE FROM t_user_profile WHERE uid>10 AND ct<'2017-09-12 14:58:00' AND (email_checked=false OR email IS NULL )"
2017-09-12 15:22:00,036 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:32) DEBUG - delete 0 UserProfile
2017-09-12 15:22:00,092 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - delete from t_user where id>10 and not exists (select 1 from t_user_profile where t_user.id=uid)and ct<?
    |                   1 |
    |---------------------|
    | 2017-09-12 14:58:00 |
  For example:> "delete from t_user where id>10 and not exists (select 1 from t_user_profile where t_user.id=uid)and ct<'2017-09-12 14:58:00'"
2017-09-12 15:22:00,094 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:42) DEBUG - delete 0 User
2017-09-12 15:22:00,094 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:44) DEBUG - clean Non-Active User, Done
2017-09-12 15:22:29,478 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:22:59,022 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:23:22,107 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:23:49,202 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 1 triggers
2017-09-12 15:24:00,003 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cleanNonActiveUserJob'<class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob>
2017-09-12 15:24:00,003 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:24:00,005 org.quartz.core.JobRunShell.run(JobRunShell.java:201) DEBUG - Calling execute on job DEFAULT.net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2017-09-12 15:24:00,005 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:26) DEBUG - clean Non-Active User,start
2017-09-12 15:24:00,020 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - DELETE FROM t_user_profile WHERE uid>? AND ct<? AND (email_checked=? OR email IS NULL )
    |  1 |                   2 |     3 |
    |----|---------------------|-------|
    | 10 | 2017-09-12 15:00:00 | false |
  For example:> "DELETE FROM t_user_profile WHERE uid>10 AND ct<'2017-09-12 15:00:00' AND (email_checked=false OR email IS NULL )"
2017-09-12 15:24:00,023 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:32) DEBUG - delete 0 UserProfile
2017-09-12 15:24:00,024 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - delete from t_user where id>10 and not exists (select 1 from t_user_profile where t_user.id=uid)and ct<?
    |                   1 |
    |---------------------|
    | 2017-09-12 15:00:00 |
  For example:> "delete from t_user where id>10 and not exists (select 1 from t_user_profile where t_user.id=uid)and ct<'2017-09-12 15:00:00'"
2017-09-12 15:24:00,025 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:42) DEBUG - delete 0 User
2017-09-12 15:24:00,026 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:44) DEBUG - clean Non-Active User, Done
2017-09-12 15:24:28,214 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:24:38,222 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/captcha/next : CaptchaModule.next(CaptchaModule.java:26)
2017-09-12 15:24:38,232 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-12 15:24:38,232 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=captchaModule
2017-09-12 15:24:38,233 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(captchaModule) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-12 15:24:38,233 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-12 15:24:38,234 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.module.CaptchaModule without AOP
2017-09-12 15:24:38,235 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'captchaModule' to [app] 
2017-09-12 15:24:56,714 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:25:20,417 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:25:49,210 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 1 triggers
2017-09-12 15:26:00,002 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cleanNonActiveUserJob'<class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob>
2017-09-12 15:26:00,002 org.quartz.core.JobRunShell.run(JobRunShell.java:201) DEBUG - Calling execute on job DEFAULT.net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2017-09-12 15:26:00,003 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:26) DEBUG - clean Non-Active User,start
2017-09-12 15:26:00,003 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:26:00,004 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - DELETE FROM t_user_profile WHERE uid>? AND ct<? AND (email_checked=? OR email IS NULL )
    |  1 |                   2 |     3 |
    |----|---------------------|-------|
    | 10 | 2017-09-12 15:02:00 | false |
  For example:> "DELETE FROM t_user_profile WHERE uid>10 AND ct<'2017-09-12 15:02:00' AND (email_checked=false OR email IS NULL )"
2017-09-12 15:26:00,007 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:32) DEBUG - delete 0 UserProfile
2017-09-12 15:26:00,008 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - delete from t_user where id>10 and not exists (select 1 from t_user_profile where t_user.id=uid)and ct<?
    |                   1 |
    |---------------------|
    | 2017-09-12 15:02:00 |
  For example:> "delete from t_user where id>10 and not exists (select 1 from t_user_profile where t_user.id=uid)and ct<'2017-09-12 15:02:00'"
2017-09-12 15:26:00,016 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:42) DEBUG - delete 0 User
2017-09-12 15:26:00,016 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:44) DEBUG - clean Non-Active User, Done
2017-09-12 15:26:23,384 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:26:50,839 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:27:08,940 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [POST] path=/user/login : UserModule.login(UserModule.java:57)
2017-09-12 15:27:08,941 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userModule'<class net.wendal.nutzbook.module.UserModule>
2017-09-12 15:27:08,941 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=userModule
2017-09-12 15:27:08,941 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(userModule) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-12 15:27:08,941 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'userModule'<class net.wendal.nutzbook.module.UserModule>
2017-09-12 15:27:08,942 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'txREAD_COMMITTED'<interface org.nutz.aop.MethodInterceptor>
2017-09-12 15:27:08,942 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=txREAD_COMMITTED
2017-09-12 15:27:08,943 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=txREAD_COMMITTED
2017-09-12 15:27:08,945 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(txREAD_COMMITTED) in TransIocLoader@12831682
2017-09-12 15:27:08,945 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'txREAD_COMMITTED'<interface org.nutz.aop.MethodInterceptor>
2017-09-12 15:27:08,945 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'txREAD_COMMITTED' to [app] 
2017-09-12 15:27:08,957 org.nutz.aop.asm.AsmClassAgent.<clinit>(AsmClassAgent.java:29) DEBUG - AsmClassAgent will define class in Version 50
2017-09-12 15:27:08,967 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'userModule' to [app] 
2017-09-12 15:27:08,977 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-12 15:27:08,977 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'emailService'<interface net.wendal.nutzbook.service.EmailService>
2017-09-12 15:27:08,977 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=emailService
2017-09-12 15:27:08,977 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(emailService) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-12 15:27:08,978 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'emailService'<interface net.wendal.nutzbook.service.EmailService>
2017-09-12 15:27:08,978 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.service.EmailServiceImpl without AOP
2017-09-12 15:27:08,978 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'emailService' to [app] 
2017-09-12 15:27:12,222 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [POST] path=/user/login : UserModule.login(UserModule.java:57)
2017-09-12 15:27:12,223 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userModule'<class net.wendal.nutzbook.module.UserModule>
2017-09-12 15:27:13,840 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:27:25,908 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/captcha/next : CaptchaModule.next(CaptchaModule.java:26)
2017-09-12 15:27:25,909 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-12 15:27:26,397 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/captcha/next : CaptchaModule.next(CaptchaModule.java:26)
2017-09-12 15:27:26,397 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-12 15:27:26,576 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/captcha/next : CaptchaModule.next(CaptchaModule.java:26)
2017-09-12 15:27:26,576 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-12 15:27:29,431 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:21) DEBUG - [ GET]URI=/nutzbook/captcha/next 3033ms
2017-09-12 15:27:29,436 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:21) DEBUG - [ GET]URI=/nutzbook/captcha/next 3528ms
2017-09-12 15:27:29,521 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/captcha/next : CaptchaModule.next(CaptchaModule.java:26)
2017-09-12 15:27:29,521 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-12 15:27:29,716 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/captcha/next : CaptchaModule.next(CaptchaModule.java:26)
2017-09-12 15:27:29,717 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-12 15:27:36,126 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [POST] path=/user/login : UserModule.login(UserModule.java:57)
2017-09-12 15:27:36,127 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userModule'<class net.wendal.nutzbook.module.UserModule>
2017-09-12 15:27:36,133 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM t_user  WHERE name=? AND passwd=? LIMIT 0, 1 
    |     1 |      2 |
    |-------|--------|
    | admin | 123456 |
  For example:> "SELECT * FROM t_user  WHERE name='admin' AND passwd='123456' LIMIT 0, 1 "
2017-09-12 15:27:37,301 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 1 triggers
2017-09-12 15:27:58,092 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/captcha/next : CaptchaModule.next(CaptchaModule.java:26)
2017-09-12 15:27:58,093 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'captchaModule'<class net.wendal.nutzbook.module.CaptchaModule>
2017-09-12 15:28:00,001 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cleanNonActiveUserJob'<class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob>
2017-09-12 15:28:00,001 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:28:00,002 org.quartz.core.JobRunShell.run(JobRunShell.java:201) DEBUG - Calling execute on job DEFAULT.net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2017-09-12 15:28:00,002 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:26) DEBUG - clean Non-Active User,start
2017-09-12 15:28:00,003 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - DELETE FROM t_user_profile WHERE uid>? AND ct<? AND (email_checked=? OR email IS NULL )
    |  1 |                   2 |     3 |
    |----|---------------------|-------|
    | 10 | 2017-09-12 15:04:00 | false |
  For example:> "DELETE FROM t_user_profile WHERE uid>10 AND ct<'2017-09-12 15:04:00' AND (email_checked=false OR email IS NULL )"
2017-09-12 15:28:00,006 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:32) DEBUG - delete 0 UserProfile
2017-09-12 15:28:00,007 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - delete from t_user where id>10 and not exists (select 1 from t_user_profile where t_user.id=uid)and ct<?
    |                   1 |
    |---------------------|
    | 2017-09-12 15:04:00 |
  For example:> "delete from t_user where id>10 and not exists (select 1 from t_user_profile where t_user.id=uid)and ct<'2017-09-12 15:04:00'"
2017-09-12 15:28:00,010 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:42) DEBUG - delete 0 User
2017-09-12 15:28:00,010 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:44) DEBUG - clean Non-Active User, Done
2017-09-12 15:28:24,419 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:28:38,440 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/user/profile/ : UserProfileModule.index(UserProfileModule.java:152)
2017-09-12 15:28:38,441 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userProfileModule'<class net.wendal.nutzbook.module.UserProfileModule>
2017-09-12 15:28:38,441 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=userProfileModule
2017-09-12 15:28:38,442 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(userProfileModule) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-12 15:28:38,442 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'userProfileModule'<class net.wendal.nutzbook.module.UserProfileModule>
2017-09-12 15:28:38,446 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.module.UserProfileModule without AOP
2017-09-12 15:28:38,446 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'userProfileModule' to [app] 
2017-09-12 15:28:38,462 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-12 15:28:38,463 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'emailService'<interface net.wendal.nutzbook.service.EmailService>
2017-09-12 15:28:38,477 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT uid,nickname,email,email_checked,gender,dt,ioc,ct,ut FROM t_user_profile  WHERE uid=?
    | 1 |
    |---|
    | 1 |
  For example:> "SELECT uid,nickname,email,email_checked,gender,dt,ioc,ct,ut FROM t_user_profile  WHERE uid=1"
2017-09-12 15:28:38,985 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/user/profile/avatar : UserProfileModule.readAvatar(UserProfileModule.java:138)
2017-09-12 15:28:38,985 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userProfileModule'<class net.wendal.nutzbook.module.UserProfileModule>
2017-09-12 15:28:38,987 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:21) DEBUG - [ GET]URI=/nutzbook/user/profile/avatar 2ms
2017-09-12 15:28:39,030 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [GET] path=/user/profile/avatar : UserProfileModule.readAvatar(UserProfileModule.java:138)
2017-09-12 15:28:39,031 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userProfileModule'<class net.wendal.nutzbook.module.UserProfileModule>
2017-09-12 15:28:39,032 net.wendal.nutzbook.mvc.LogTimeProcessor.process(LogTimeProcessor.java:21) DEBUG - [ GET]URI=/nutzbook/user/profile/avatar 0ms
2017-09-12 15:28:52,986 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:29:01,088 org.nutz.mvc.impl.UrlMappingImpl.get(UrlMappingImpl.java:101) DEBUG - Found mapping for [POST] path=/user/profile/active/mail : UserProfileModule.activeMail(UserProfileModule.java:159)
2017-09-12 15:29:01,090 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userProfileModule'<class net.wendal.nutzbook.module.UserProfileModule>
2017-09-12 15:29:01,093 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT uid,nickname,email,email_checked,gender,dt,ioc,ct,ut FROM t_user_profile  WHERE uid=?
    | 1 |
    |---|
    | 1 |
  For example:> "SELECT uid,nickname,email,email_checked,gender,dt,ioc,ct,ut FROM t_user_profile  WHERE uid=1"
2017-09-12 15:29:01,160 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'htmlEmail'<class org.apache.commons.mail.HtmlEmail>
2017-09-12 15:29:01,160 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=htmlEmail
2017-09-12 15:29:01,161 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=htmlEmail
2017-09-12 15:29:01,161 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(htmlEmail) in JsonLoader(paths=[ioc/])
2017-09-12 15:29:01,161 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'htmlEmail'<class org.apache.commons.mail.HtmlEmail>
2017-09-12 15:29:01,161 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.apache.commons.mail.ImageHtmlEmail without AOP
2017-09-12 15:29:01,162 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-12 15:29:01,162 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-12 15:29:01,163 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'emailAuthenticator'<>
2017-09-12 15:29:01,163 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-12 15:29:01,164 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-12 15:29:01,164 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2017-09-12 15:29:21,809 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:29:46,050 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 1 triggers
2017-09-12 15:30:00,002 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cleanNonActiveUserJob'<class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob>
2017-09-12 15:30:00,002 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:30:00,003 org.quartz.core.JobRunShell.run(JobRunShell.java:201) DEBUG - Calling execute on job DEFAULT.net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2017-09-12 15:30:00,003 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:26) DEBUG - clean Non-Active User,start
2017-09-12 15:30:00,004 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - DELETE FROM t_user_profile WHERE uid>? AND ct<? AND (email_checked=? OR email IS NULL )
    |  1 |                   2 |     3 |
    |----|---------------------|-------|
    | 10 | 2017-09-12 15:06:00 | false |
  For example:> "DELETE FROM t_user_profile WHERE uid>10 AND ct<'2017-09-12 15:06:00' AND (email_checked=false OR email IS NULL )"
2017-09-12 15:30:00,010 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:32) DEBUG - delete 0 UserProfile
2017-09-12 15:30:00,012 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - delete from t_user where id>10 and not exists (select 1 from t_user_profile where t_user.id=uid)and ct<?
    |                   1 |
    |---------------------|
    | 2017-09-12 15:06:00 |
  For example:> "delete from t_user where id>10 and not exists (select 1 from t_user_profile where t_user.id=uid)and ct<'2017-09-12 15:06:00'"
2017-09-12 15:30:00,016 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:42) DEBUG - delete 0 User
2017-09-12 15:30:00,016 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:44) DEBUG - clean Non-Active User, Done
2017-09-12 15:30:26,473 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:30:53,451 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:31:22,799 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:31:47,623 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 1 triggers
2017-09-12 15:32:00,002 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cleanNonActiveUserJob'<class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob>
2017-09-12 15:32:00,002 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2017-09-12 15:32:00,002 org.quartz.core.JobRunShell.run(JobRunShell.java:201) DEBUG - Calling execute on job DEFAULT.net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2017-09-12 15:32:00,002 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:26) DEBUG - clean Non-Active User,start
2017-09-12 15:32:00,003 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - DELETE FROM t_user_profile WHERE uid>? AND ct<? AND (email_checked=? OR email IS NULL )
    |  1 |                   2 |     3 |
    |----|---------------------|-------|
    | 10 | 2017-09-12 15:08:00 | false |
  For example:> "DELETE FROM t_user_profile WHERE uid>10 AND ct<'2017-09-12 15:08:00' AND (email_checked=false OR email IS NULL )"
2017-09-12 15:32:00,005 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:32) DEBUG - delete 0 UserProfile
2017-09-12 15:32:00,006 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - delete from t_user where id>10 and not exists (select 1 from t_user_profile where t_user.id=uid)and ct<?
    |                   1 |
    |---------------------|
    | 2017-09-12 15:08:00 |
  For example:> "delete from t_user where id>10 and not exists (select 1 from t_user_profile where t_user.id=uid)and ct<'2017-09-12 15:08:00'"
2017-09-12 15:32:00,008 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:42) DEBUG - delete 0 User
2017-09-12 15:32:00,008 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:44) DEBUG - clean Non-Active User, Done

然后五分钟以后收到系统退信
尊敬的用户，

我们很遗憾的通知您，您发的邮件中有一个或多个接收人没有投递成功。

退回的邮件在附件中，请查看附件了解详情。

被退回邮件信息：

服务器：112.90.83.115

退信原因：501 Bad address syntax. http://service.mail.qq.com/cgi-bin/help?subtype=1&&id=20022&&no=1000730

收件人：741303103!@qq.com

退信原因查询：http://help.sina.com.cn/i/90/152_2.htm

然后收到了个附件
如果无法点击我，请拷贝一下链接到浏览器中打开
验证链接 http://127.0.0.1:8081/nutzbook/user/profile/active/mail?token=401ef4eceec2985ecb56898dd76c1bb2870af11244bf59487d40be07fc082f0c184d0ad3922cd22a

兽哥：
可能之前尝试的时候多打的 在之后修改过了 数据库可能没更新上
还有一个历史遗留问题 就是更新头像的时候 点击更新头像button 后 用户头像还是没有变

好的 那我试试

九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server version:        Apache Tomcat/8.0.30
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server built:          Dec 1 2015 22:30:46 UTC
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server number:         8.0.30.0
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: OS Name:               Windows 7
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: OS Version:            6.1
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Architecture:          amd64
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Java Home:             C:\Program Files\Java\jdk1.7.0_79\jre
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: JVM Version:           1.7.0_79-b15
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: JVM Vendor:            Oracle Corporation
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: CATALINA_BASE:         D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: CATALINA_HOME:         D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dcatalina.home=D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dcatalina.base=D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Djava.endorsed.dirs=D:\MyEclipse\apache-tomcat-8.0.30/common/endorsed
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Djava.io.tmpdir=D:\MyEclipse\apache-tomcat-8.0.30\temp
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Djava.library.path=C:\Program Files\Java\jdk1.7.0_79\bin;D:\MyEclipse\apache-tomcat-8.0.30\bin
九月 12, 2017 5:39:15 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dsun.io.useCanonCaches=false
九月 12, 2017 5:39:15 下午 org.apache.catalina.core.AprLifecycleListener lifecycleEvent
信息: Loaded APR based Apache Tomcat Native library 1.1.33 using APR version 1.5.1.
九月 12, 2017 5:39:15 下午 org.apache.catalina.core.AprLifecycleListener lifecycleEvent
信息: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
九月 12, 2017 5:39:16 下午 org.apache.catalina.core.AprLifecycleListener initializeSSL
信息: OpenSSL successfully initialized (OpenSSL 1.0.1m 19 Mar 2015)
九月 12, 2017 5:39:16 下午 org.apache.coyote.AbstractProtocol init
信息: Initializing ProtocolHandler ["http-apr-8081"]
九月 12, 2017 5:39:16 下午 org.apache.coyote.AbstractProtocol init
信息: Initializing ProtocolHandler ["ajp-apr-8009"]
九月 12, 2017 5:39:16 下午 org.apache.catalina.startup.Catalina load
信息: Initialization processed in 1272 ms
九月 12, 2017 5:39:16 下午 org.apache.catalina.core.StandardService startInternal
信息: Starting service Catalina
九月 12, 2017 5:39:16 下午 org.apache.catalina.core.StandardEngine startInternal
信息: Starting Servlet Engine: Apache Tomcat/8.0.30
九月 12, 2017 5:39:16 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\docs
九月 12, 2017 5:39:17 下午 org.apache.catalina.util.SessionIdGeneratorBase createSecureRandom
信息: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [790] milliseconds.
九月 12, 2017 5:39:17 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\docs has finished in 1,179 ms
九月 12, 2017 5:39:17 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\examples
九月 12, 2017 5:39:18 下午 org.apache.catalina.core.ApplicationContext log
信息: ContextListener: contextInitialized()
九月 12, 2017 5:39:18 下午 org.apache.catalina.core.ApplicationContext log
信息: SessionListener: contextInitialized()
九月 12, 2017 5:39:18 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\examples has finished in 391 ms
九月 12, 2017 5:39:18 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\host-manager
九月 12, 2017 5:39:18 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\host-manager has finished in 35 ms
九月 12, 2017 5:39:18 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\manager
九月 12, 2017 5:39:18 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\manager has finished in 35 ms
九月 12, 2017 5:39:18 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\nutzbook
九月 12, 2017 5:39:19 下午 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.
九月 12, 2017 5:39:19 下午 org.apache.catalina.core.ApplicationContext log
信息: Initializing Shiro environment
2017-09-12 17:39:19,564 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:128) INFO  - Starting Shiro environment initialization.
2017-09-12 17:39:19,582 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:76) DEBUG - Checking any specified config locations.
2017-09-12 17:39:19,582 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:81) DEBUG - No INI instance or config locations specified.  Trying default config locations.
2017-09-12 17:39:19,586 org.apache.shiro.io.ResourceUtils.loadFromClassPath(ResourceUtils.java:159) DEBUG - Opening resource from class path [shiro.ini]
2017-09-12 17:39:19,592 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [main]
2017-09-12 17:39:19,592 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [urls]
2017-09-12 17:39:19,594 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-12 17:39:19,597 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=urls]
2017-09-12 17:39:19,816 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=urls]
2017-09-12 17:39:19,820 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/*] from String definition [anon]
2017-09-12 17:39:19,820 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/*] to filter [anon] with config [null]
2017-09-12 17:39:19,822 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-12 17:39:19,822 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:141) INFO  - Shiro environment initialized in 254 ms.
2017-09-12 17:39:19,856 org.nutz.mvc.NutFilter._init(NutFilter.java:85) INFO  - NutFilter[nutz] starting ...
2017-09-12 17:39:19,877 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=5 time use 9ms
2017-09-12 17:39:19,894 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=26 time use 16ms
2017-09-12 17:39:19,967 org.nutz.castor.Castors.reload(Castors.java:115) DEBUG - Using 95 castor for Castors
2017-09-12 17:39:19,993 org.nutz.mvc.config.AbstractNutConfig.createLoading(AbstractNutConfig.java:59) DEBUG - Loading by class org.nutz.mvc.impl.NutLoading
2017-09-12 17:39:19,996 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:55) INFO  - Nutz Version : 1.r.62 
2017-09-12 17:39:19,996 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:56) INFO  - Nutz.Mvc[nutz] is initializing ...
2017-09-12 17:39:19,996 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:60) DEBUG - Web Container Information:
2017-09-12 17:39:19,998 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:61) DEBUG -  - Default Charset : GBK
2017-09-12 17:39:19,998 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:62) DEBUG -  - Current . path  : D:\MyEclipse\apache-tomcat-8.0.30\bin\.
2017-09-12 17:39:19,998 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:63) DEBUG -  - Java Version    : 1.7.0_79
2017-09-12 17:39:19,998 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:64) DEBUG -  - File separator  : \
2017-09-12 17:39:19,999 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:65) DEBUG -  - Timezone        : Asia/Shanghai
2017-09-12 17:39:19,999 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:66) DEBUG -  - OS              : Windows 7 amd64
2017-09-12 17:39:19,999 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:67) DEBUG -  - ServerInfo      : Apache Tomcat/8.0.30
2017-09-12 17:39:19,999 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:68) DEBUG -  - Servlet API     : 3.1
2017-09-12 17:39:19,999 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:73) DEBUG -  - ContextPath     : /nutzbook
2017-09-12 17:39:20,000 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:74) DEBUG -  - context.tempdir : D:\MyEclipse\apache-tomcat-8.0.30\work\Catalina\localhost\nutzbook
2017-09-12 17:39:20,000 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:75) DEBUG -  - MainModule      : net.wendal.nutzbook.MainModule
2017-09-12 17:39:20,001 org.nutz.mvc.impl.NutLoading.createContext(NutLoading.java:235) DEBUG - >> app.root = D:/MyEclipse/apache-tomcat-8.0.30/webapps/nutzbook
2017-09-12 17:39:20,005 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", "*quartz"],init=[])
2017-09-12 17:39:20,074 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 2 resource by src( ioc/ ) , regex( ^(.+[.])(js|json)$ )
2017-09-12 17:39:20,074 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [dao.js]
2017-09-12 17:39:20,084 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [mail.js]
2017-09-12 17:39:20,085 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 5 bean define from path=[ioc/] --> [htmlEmail, dataSource, dao, conf, emailAuthenticator]
2017-09-12 17:39:20,100 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 17 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-12 17:39:20,135 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.CaptchaModule
2017-09-12 17:39:20,148 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserModule
2017-09-12 17:39:20,157 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserProfileModule
2017-09-12 17:39:20,169 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2017-09-12 17:39:20,172 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.EmailServiceImpl
2017-09-12 17:39:20,174 org.nutz.ioc.loader.annotation.AnnotationIocLoader.<init>(AnnotationIocLoader.java:52) INFO  - Found 5 classes in 1 base-packages!
beans = ["captchaModule", "cleanNonActiveUserJob", "userProfileModule", "emailService", "userModule"]
2017-09-12 17:39:20,180 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:40) DEBUG - Loaded 5 bean define from reader --
[txREPEATABLE_READ, txREAD_COMMITTED, txNONE, txSERIALIZABLE, txREAD_UNCOMMITTED]
2017-09-12 17:39:20,183 org.nutz.ioc.loader.combo.ComboIocLoader.createIocLoader(ComboIocLoader.java:110) DEBUG - found quartz -- org.nutz.integration.quartz.QuartzIocLoader
2017-09-12 17:39:20,187 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 0 bean define from path=[] --> []
2017-09-12 17:39:20,193 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:98) INFO  - NutIoc init begin ...
2017-09-12 17:39:20,195 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:115) INFO  - ... NutIoc init complete
2017-09-12 17:39:20,198 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:159) INFO  - Build URL mapping by org.nutz.mvc.impl.UrlMappingImpl ...
2017-09-12 17:39:20,201 org.nutz.mvc.impl.NutLoading.createViewMakers(NutLoading.java:366) DEBUG - @Views(DefaultViewMaker.class)
2017-09-12 17:39:20,213 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( mvc/nutzbook-mvc-chain.js ) , regex( ^(.+[.])(js|json)$ )
2017-09-12 17:39:20,221 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-12 17:39:20,221 org.nutz.mvc.impl.NutLoading.createChainMaker(NutLoading.java:263) DEBUG - @ChainBy(org.nutz.mvc.impl.NutActionChainMaker)
2017-09-12 17:39:20,226 org.nutz.mvc.impl.Loadings.scanModules(Loadings.java:154) DEBUG - module class location 'file:/D:/MyEclipse/apache-tomcat-8.0.30/webapps/nutzbook/WEB-INF/classes/'
2017-09-12 17:39:20,226 org.nutz.mvc.impl.Loadings.scanModuleInPackage(Loadings.java:184) DEBUG -  > scan 'net.wendal.nutzbook'
2017-09-12 17:39:20,232 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 17 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-12 17:39:20,235 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.CaptchaModule'
2017-09-12 17:39:20,235 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserModule'
2017-09-12 17:39:20,235 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserProfileModule'
2017-09-12 17:39:20,315 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/captcha/next'             >> (CaptchaModule.java:26).next          : BufferedImage | @Ok(raw:png) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,328 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/get'         >> (UserProfileModule.java:54).get       : UserProfile | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,330 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/'            >> (UserProfileModule.java:152).index    : UserProfile | @Ok(jsp:jsp.user.profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,336 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/update'      >> (UserProfileModule.java:72).update    : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,354 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:23) INFO  - Init file-pool by: D:/MyEclipse/apache-tomcat-8.0.30/webapps/nutzbook/WEB-INF/tmp/user_avatar [20000]
2017-09-12 17:39:20,358 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:37) DEBUG - file-pool.home: 'D:\MyEclipse\apache-tomcat-8.0.30\webapps\nutzbook\WEB-INF\tmp\user_avatar'
2017-09-12 17:39:20,359 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:66) INFO  - file-pool.cursor: 0
2017-09-12 17:39:20,363 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:106).uploadAvatar : void       | @Ok(>>:/user/profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,366 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:138).readAvatar : Object     | @Ok(raw:jpg) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,367 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:159).activeMail : Object     | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,368 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:187).activeMailCallback : String     | @Ok(raw  ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,443 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/add'                 >> (UserModule.java:90).add              : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,445 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/count'               >> (UserModule.java:49).count            : int        | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,446 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/'                    >> (UserModule.java:140).index           : void       | @Ok(jsp:jsp.user.list) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,448 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/delete'              >> (UserModule.java:114).delete          : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,450 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/query'               >> (UserModule.java:125).query           : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,451 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/update'              >> (UserModule.java:103).update          : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,453 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/login'               >> (UserModule.java:62).login            : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,454 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/logout'              >> (UserModule.java:83).logout           : void       | @Ok(>>:/ ) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:39:20,454 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:217) INFO  - Found 16 module methods
2017-09-12 17:39:20,455 org.nutz.mvc.impl.NutLoading.evalLocalization(NutLoading.java:331) DEBUG - @Localization not define
2017-09-12 17:39:20,459 org.nutz.mvc.impl.NutLoading.createSessionProvider(NutLoading.java:410) INFO  - SessionBy --> org.nutz.integration.shiro.ShiroSessionProvider@484f8660
2017-09-12 17:39:20,459 org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:271) INFO  - Setup application...
2017-09-12 17:39:20,462 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-12 17:39:20,464 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-12 17:39:20,465 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dao
2017-09-12 17:39:20,465 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dao
2017-09-12 17:39:20,469 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dao) in JsonLoader(paths=[ioc/])
2017-09-12 17:39:20,469 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dao'<interface org.nutz.dao.Dao>
2017-09-12 17:39:20,481 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.dao.impl.NutDao without AOP
2017-09-12 17:39:20,482 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dao' to [app] 
2017-09-12 17:39:20,484 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2017-09-12 17:39:20,484 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dataSource
2017-09-12 17:39:20,484 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dataSource
2017-09-12 17:39:20,496 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dataSource) in JsonLoader(paths=[ioc/])
2017-09-12 17:39:20,496 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dataSource'<>
2017-09-12 17:39:20,512 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class com.alibaba.druid.pool.DruidDataSource without AOP
2017-09-12 17:39:20,512 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dataSource' to [app] 
2017-09-12 17:39:20,803 com.alibaba.druid.pool.DruidDataSource.init(DruidDataSource.java:669) INFO  - {dataSource-1} inited
2017-09-12 17:39:20,804 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2017-09-12 17:39:21,021 org.nutz.dao.jdbc.Jdbcs.<clinit>(Jdbcs.java:90) DEBUG - Jdbcs init complete
2017-09-12 17:39:21,022 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
2017-09-12 17:39:21,218 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:188) DEBUG - select expert : org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert
2017-09-12 17:39:21,224 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:199) DEBUG - JDBC Driver --> mysql-connector-java-5.1.34 ( Revision: jess.balint@oracle.com-20141014163213-wqbwpf1ok2kvo1om )
2017-09-12 17:39:21,224 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:200) DEBUG - JDBC Name   --> MySQL Connector Java
2017-09-12 17:39:21,225 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:202) DEBUG - JDBC URL    --> jdbc:mysql://127.0.0.1:3306/nutzbook
2017-09-12 17:39:21,236 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_client=utf8
2017-09-12 17:39:21,236 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_connection=utf8
2017-09-12 17:39:21,236 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_database=utf8
2017-09-12 17:39:21,236 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_filesystem=binary
2017-09-12 17:39:21,237 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_results=
2017-09-12 17:39:21,237 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_server=utf8
2017-09-12 17:39:21,237 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_system=utf8
2017-09-12 17:39:21,237 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-12 17:39:21,240 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:213) DEBUG - Mysql : binlog_format=ROW
2017-09-12 17:39:21,241 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:220) DEBUG - Mysql : database=nutzbook
2017-09-12 17:39:21,241 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:226) DEBUG - Mysql : user=root@localhost
2017-09-12 17:39:21,255 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:221) DEBUG - Database info --> MYSQL:[MySQL - 5.7.17-log]
2017-09-12 17:39:21,262 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 17 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-12 17:39:21,332 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT COUNT(*) FROM t_user 
2017-09-12 17:39:21,335 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userService'<class net.wendal.nutzbook.service.UserService>
2017-09-12 17:39:21,335 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=userService
2017-09-12 17:39:21,336 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:125) ERROR - Error happend during start serivce!
org.nutz.ioc.IocException: IocBean[userService] For object [userService] - type:[class net.wendal.nutzbook.service.UserService]
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:218)
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:239)
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:146)
	at net.wendal.nutzbook.MainSetup.init(MainSetup.java:23)
	at org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:274)
	at org.nutz.mvc.impl.NutLoading.load(NutLoading.java:121)
	at org.nutz.mvc.ActionHandler.<init>(ActionHandler.java:19)
	at org.nutz.mvc.NutFilter._init(NutFilter.java:91)
	at org.nutz.mvc.NutFilter.init(NutFilter.java:69)
	at org.apache.catalina.core.ApplicationFilterConfig.initFilter(ApplicationFilterConfig.java:279)
	at org.apache.catalina.core.ApplicationFilterConfig.getFilter(ApplicationFilterConfig.java:260)
	at org.apache.catalina.core.ApplicationFilterConfig.<init>(ApplicationFilterConfig.java:105)
	at org.apache.catalina.core.StandardContext.filterStart(StandardContext.java:4659)
	at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5281)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
	at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:725)
	at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:701)
	at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:717)
	at org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.java:1101)
	at org.apache.catalina.startup.HostConfig$DeployDirectory.run(HostConfig.java:1813)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.nutz.ioc.ObjectLoadException: Object 'userService' without define!
	at org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:166)
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:180)
	... 24 more
2017-09-12 17:39:21,338 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:127) ERROR - try to depose ioc
2017-09-12 17:39:21,341 org.nutz.ioc.impl.NutIoc.depose(NutIoc.java:255) INFO  - org.nutz.ioc.impl.NutIoc@740719219 is closing. startup date [17-09-12 17:39:20.193]
2017-09-12 17:39:21,341 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'dao' ...
2017-09-12 17:39:21,341 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:113) DEBUG - Depose object 'dataSource' ...
2017-09-12 17:39:21,345 com.alibaba.druid.pool.DruidDataSource.close(DruidDataSource.java:1385) INFO  - {dataSource-1} closed
2017-09-12 17:39:21,345 org.nutz.ioc.impl.NutIoc.depose(NutIoc.java:262) INFO  - org.nutz.ioc.impl.NutIoc@740719219 is deposed. startup date [17-09-12 17:39:20.193]
九月 12, 2017 5:39:21 下午 org.apache.catalina.core.StandardContext filterStart
严重: Exception starting filter nutz
org.nutz.mvc.LoadingException: org.nutz.ioc.IocException: IocBean[userService] For object [userService] - type:[class net.wendal.nutzbook.service.UserService]
	at org.nutz.mvc.LoadingException$FC$9a86caf9ff5d3b587784fcdf555a4a7d.invoke(LoadingException.java)
	at org.nutz.lang.born.AbstractConstructorBorning.call(AbstractConstructorBorning.java:25)
	at org.nutz.lang.born.ConstructorBorning.born(ConstructorBorning.java:19)
	at org.nutz.lang.born.BornContext.doBorn(BornContext.java:60)
	at org.nutz.lang.Mirror.born(Mirror.java:990)
	at org.nutz.lang.Lang.wrapThrow(Lang.java:200)
	at org.nutz.mvc.impl.NutLoading.load(NutLoading.java:135)
	at org.nutz.mvc.ActionHandler.<init>(ActionHandler.java:19)
	at org.nutz.mvc.NutFilter._init(NutFilter.java:91)
	at org.nutz.mvc.NutFilter.init(NutFilter.java:69)
	at org.apache.catalina.core.ApplicationFilterConfig.initFilter(ApplicationFilterConfig.java:279)
	at org.apache.catalina.core.ApplicationFilterConfig.getFilter(ApplicationFilterConfig.java:260)
	at org.apache.catalina.core.ApplicationFilterConfig.<init>(ApplicationFilterConfig.java:105)
	at org.apache.catalina.core.StandardContext.filterStart(StandardContext.java:4659)
	at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5281)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
	at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:725)
	at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:701)
	at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:717)
	at org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.java:1101)
	at org.apache.catalina.startup.HostConfig$DeployDirectory.run(HostConfig.java:1813)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.nutz.ioc.IocException: IocBean[userService] For object [userService] - type:[class net.wendal.nutzbook.service.UserService]
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:218)
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:239)
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:146)
	at net.wendal.nutzbook.MainSetup.init(MainSetup.java:23)
	at org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:274)
	at org.nutz.mvc.impl.NutLoading.load(NutLoading.java:121)
	... 19 more
Caused by: org.nutz.ioc.ObjectLoadException: Object 'userService' without define!
	at org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:166)
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:180)
	... 24 more
九月 12, 2017 5:39:21 下午 org.apache.catalina.core.StandardContext startInternal
严重: One or more Filters failed to start. Full details will be found in the appropriate container log file
九月 12, 2017 5:39:21 下午 org.apache.catalina.core.StandardContext startInternal
严重: Context [/nutzbook] startup failed due to previous errors
九月 12, 2017 5:39:21 下午 org.apache.catalina.core.ApplicationContext log
信息: Cleaning up Shiro Environment
九月 12, 2017 5:39:21 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesJdbc
警告: The web application [nutzbook] registered the JDBC driver [com.alibaba.druid.proxy.DruidDriver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
九月 12, 2017 5:39:21 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesJdbc
警告: The web application [nutzbook] registered the JDBC driver [com.mysql.jdbc.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
九月 12, 2017 5:39:21 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
警告: The web application [nutzbook] appears to have started a thread named [Abandoned connection cleanup thread] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 java.lang.Object.wait(Native Method)
 java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
 com.mysql.jdbc.AbandonedConnectionCleanupThread.run(AbandonedConnectionCleanupThread.java:43)
九月 12, 2017 5:39:21 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\nutzbook has finished in 3,015 ms
九月 12, 2017 5:39:21 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\ROOT
九月 12, 2017 5:39:21 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\ROOT has finished in 22 ms
九月 12, 2017 5:39:21 下午 org.apache.coyote.AbstractProtocol start
信息: Starting ProtocolHandler ["http-apr-8081"]
九月 12, 2017 5:39:21 下午 org.apache.coyote.AbstractProtocol start
信息: Starting ProtocolHandler ["ajp-apr-8009"]
九月 12, 2017 5:39:21 下午 org.apache.catalina.startup.Catalina start
信息: Server startup in 4753 ms

@wendal w

是哪个class没有加呢？请问这怎么从日志里看出来呢

九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server version: Apache Tomcat/8.0.30
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server built: Dec 1 2015 22:30:46 UTC
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server number: 8.0.30.0
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: OS Name: Windows 7
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: OS Version: 6.1
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Architecture: amd64
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Java Home: C:\Program Files\Java\jdk1.7.0_79\jre
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: JVM Version: 1.7.0_79-b15
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: JVM Vendor: Oracle Corporation
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: CATALINA_BASE: D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: CATALINA_HOME: D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dcatalina.home=D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dcatalina.base=D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Djava.endorsed.dirs=D:\MyEclipse\apache-tomcat-8.0.30/common/endorsed
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Djava.io.tmpdir=D:\MyEclipse\apache-tomcat-8.0.30\temp
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Djava.library.path=C:\Program Files\Java\jdk1.7.0_79\bin;D:\MyEclipse\apache-tomcat-8.0.30\bin
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dsun.io.useCanonCaches=false
九月 12, 2017 5:49:39 下午 org.apache.catalina.core.AprLifecycleListener lifecycleEvent
信息: Loaded APR based Apache Tomcat Native library 1.1.33 using APR version 1.5.1.
九月 12, 2017 5:49:39 下午 org.apache.catalina.core.AprLifecycleListener lifecycleEvent
信息: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
九月 12, 2017 5:49:39 下午 org.apache.catalina.core.AprLifecycleListener initializeSSL
信息: OpenSSL successfully initialized (OpenSSL 1.0.1m 19 Mar 2015)
九月 12, 2017 5:49:40 下午 org.apache.coyote.AbstractProtocol init
信息: Initializing ProtocolHandler ["http-apr-8081"]
九月 12, 2017 5:49:40 下午 org.apache.coyote.AbstractProtocol init
信息: Initializing ProtocolHandler ["ajp-apr-8009"]
九月 12, 2017 5:49:40 下午 org.apache.catalina.startup.Catalina load
信息: Initialization processed in 1406 ms
九月 12, 2017 5:49:40 下午 org.apache.catalina.core.StandardService startInternal
信息: Starting service Catalina
九月 12, 2017 5:49:40 下午 org.apache.catalina.core.StandardEngine startInternal
信息: Starting Servlet Engine: Apache Tomcat/8.0.30
九月 12, 2017 5:49:40 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\docs
九月 12, 2017 5:49:41 下午 org.apache.catalina.util.SessionIdGeneratorBase createSecureRandom
信息: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [794] milliseconds.
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\docs has finished in 1,246 ms
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\examples
九月 12, 2017 5:49:41 下午 org.apache.catalina.core.ApplicationContext log
信息: ContextListener: contextInitialized()
九月 12, 2017 5:49:41 下午 org.apache.catalina.core.ApplicationContext log
信息: SessionListener: contextInitialized()
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\examples has finished in 423 ms
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\host-manager
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\host-manager has finished in 34 ms
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\manager
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\manager has finished in 41 ms
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\nutzbook
九月 12, 2017 5:49:42 下午 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.
九月 12, 2017 5:49:43 下午 org.apache.catalina.core.ApplicationContext log
信息: Initializing Shiro environment
2017-09-12 17:49:43,074 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:128) INFO - Starting Shiro environment initialization.
2017-09-12 17:49:43,097 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:76) DEBUG - Checking any specified config locations.
2017-09-12 17:49:43,097 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:81) DEBUG - No INI instance or config locations specified. Trying default config locations.
2017-09-12 17:49:43,104 org.apache.shiro.io.ResourceUtils.loadFromClassPath(ResourceUtils.java:159) DEBUG - Opening resource from class path [shiro.ini]
2017-09-12 17:49:43,111 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [main]
2017-09-12 17:49:43,112 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [urls]
2017-09-12 17:49:43,114 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-12 17:49:43,119 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=urls]
2017-09-12 17:49:43,343 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=urls]
2017-09-12 17:49:43,347 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/*] from String definition [anon]
2017-09-12 17:49:43,348 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/*] to filter [anon] with config [null]
2017-09-12 17:49:43,350 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-12 17:49:43,350 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:141) INFO - Shiro environment initialized in 272 ms.
2017-09-12 17:49:43,387 org.nutz.mvc.NutFilter._init(NutFilter.java:85) INFO - NutFilter[nutz] starting ...
2017-09-12 17:49:43,407 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=5 time use 9ms
2017-09-12 17:49:43,425 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=26 time use 18ms
2017-09-12 17:49:43,503 org.nutz.castor.Castors.reload(Castors.java:115) DEBUG - Using 95 castor for Castors
2017-09-12 17:49:43,535 org.nutz.mvc.config.AbstractNutConfig.createLoading(AbstractNutConfig.java:59) DEBUG - Loading by class org.nutz.mvc.impl.NutLoading
2017-09-12 17:49:43,538 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:55) INFO - Nutz Version : 1.r.62
2017-09-12 17:49:43,538 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:56) INFO - Nutz.Mvc[nutz] is initializing ...
2017-09-12 17:49:43,538 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:60) DEBUG - Web Container Information:
2017-09-12 17:49:43,540 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:61) DEBUG - - Default Charset : GBK
2017-09-12 17:49:43,540 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:62) DEBUG - - Current . path : D:\MyEclipse\apache-tomcat-8.0.30\bin.
2017-09-12 17:49:43,540 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:63) DEBUG - - Java Version : 1.7.0_79
2017-09-12 17:49:43,540 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:64) DEBUG - - File separator : \
2017-09-12 17:49:43,540 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:65) DEBUG - - Timezone : Asia/Shanghai
2017-09-12 17:49:43,540 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:66) DEBUG - - OS : Windows 7 amd64
2017-09-12 17:49:43,540 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:67) DEBUG - - ServerInfo : Apache Tomcat/8.0.30
2017-09-12 17:49:43,541 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:68) DEBUG - - Servlet API : 3.1
2017-09-12 17:49:43,541 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:73) DEBUG - - ContextPath : /nutzbook
2017-09-12 17:49:43,541 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:74) DEBUG - - context.tempdir : D:\MyEclipse\apache-tomcat-8.0.30\work\Catalina\localhost\nutzbook
2017-09-12 17:49:43,541 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:75) DEBUG - - MainModule : net.wendal.nutzbook.MainModule
2017-09-12 17:49:43,542 org.nutz.mvc.impl.NutLoading.createContext(NutLoading.java:235) DEBUG - >> app.root = D:/MyEclipse/apache-tomcat-8.0.30/webapps/nutzbook
2017-09-12 17:49:43,545 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", "*quartz"],init=[])
2017-09-12 17:49:43,612 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 2 resource by src( ioc/ ) , regex( ^(.+[.])(js|json)$ )
2017-09-12 17:49:43,612 org.nutz.ioc.loader.json.JsonLoader.(JsonLoader.java:49) DEBUG - loading [dao.js]
2017-09-12 17:49:43,621 org.nutz.ioc.loader.json.JsonLoader.(JsonLoader.java:49) DEBUG - loading [mail.js]
2017-09-12 17:49:43,621 org.nutz.ioc.loader.json.JsonLoader.(JsonLoader.java:57) DEBUG - Loaded 5 bean define from path=[ioc/] --> [htmlEmail, dataSource, dao, conf, emailAuthenticator]
2017-09-12 17:49:43,650 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 17 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-12 17:49:43,681 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.bean.Role
2017-09-12 17:49:43,702 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.MainModule
2017-09-12 17:49:43,706 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.CaptchaModule
2017-09-12 17:49:43,716 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserModule
2017-09-12 17:49:43,729 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserProfileModule
2017-09-12 17:49:43,744 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2017-09-12 17:49:43,748 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.EmailServiceImpl
2017-09-12 17:49:43,754 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.UserService
2017-09-12 17:49:43,761 org.nutz.ioc.loader.annotation.AnnotationIocLoader.(AnnotationIocLoader.java:52) INFO - Found 8 classes in 1 base-packages!
beans = ["captchaModule", "cleanNonActiveUserJob", "userProfileModule", "userService", "role", "mainModule", "emailService", "userModule"]
2017-09-12 17:49:43,767 org.nutz.ioc.loader.json.JsonLoader.(JsonLoader.java:40) DEBUG - Loaded 5 bean define from reader --
[txREPEATABLE_READ, txREAD_COMMITTED, txNONE, txSERIALIZABLE, txREAD_UNCOMMITTED]
2017-09-12 17:49:43,772 org.nutz.ioc.loader.combo.ComboIocLoader.createIocLoader(ComboIocLoader.java:110) DEBUG - found quartz -- org.nutz.integration.quartz.QuartzIocLoader
2017-09-12 17:49:43,778 org.nutz.ioc.loader.json.JsonLoader.(JsonLoader.java:57) DEBUG - Loaded 0 bean define from path=[] --> []
2017-09-12 17:49:43,785 org.nutz.ioc.impl.NutIoc.(NutIoc.java:98) INFO - NutIoc init begin ...
2017-09-12 17:49:43,789 org.nutz.ioc.impl.NutIoc.(NutIoc.java:115) INFO - ... NutIoc init complete
2017-09-12 17:49:43,795 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:159) INFO - Build URL mapping by org.nutz.mvc.impl.UrlMappingImpl ...
2017-09-12 17:49:43,798 org.nutz.mvc.impl.NutLoading.createViewMakers(NutLoading.java:366) DEBUG - @Views(DefaultViewMaker.class)
2017-09-12 17:49:43,817 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( mvc/nutzbook-mvc-chain.js ) , regex( ^(.+[.])(js|json)$ )
2017-09-12 17:49:43,829 org.nutz.mvc.impl.chainconfig.JsonActionChainMakerConfiguretion.(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-12 17:49:43,830 org.nutz.mvc.impl.NutLoading.createChainMaker(NutLoading.java:263) DEBUG - @ChainBy(org.nutz.mvc.impl.NutActionChainMaker)
2017-09-12 17:49:43,837 org.nutz.mvc.impl.Loadings.scanModules(Loadings.java:154) DEBUG - module class location 'file:/D:/MyEclipse/apache-tomcat-8.0.30/webapps/nutzbook/WEB-INF/classes/'
2017-09-12 17:49:43,838 org.nutz.mvc.impl.Loadings.scanModuleInPackage(Loadings.java:184) DEBUG - > scan 'net.wendal.nutzbook'
2017-09-12 17:49:43,844 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 17 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-12 17:49:43,847 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG - >> add 'net.wendal.nutzbook.module.CaptchaModule'
2017-09-12 17:49:43,848 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG - >> add 'net.wendal.nutzbook.module.UserModule'
2017-09-12 17:49:43,848 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG - >> add 'net.wendal.nutzbook.module.UserProfileModule'
2017-09-12 17:49:44,034 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/user/add' >> (UserModule.java:90).add : Object | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,035 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/user/count' >> (UserModule.java:49).count : int | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,038 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/user/' >> (UserModule.java:140).index : void | @Ok(jsp:jsp.user.list) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,043 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/user/delete' >> (UserModule.java:114).delete : Object | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,044 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/user/query' >> (UserModule.java:125).query : Object | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,046 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/user/update' >> (UserModule.java:103).update : Object | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,048 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/user/login' >> (UserModule.java:62).login : Object | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,050 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/user/logout' >> (UserModule.java:83).logout : void | @Ok(>>:/ ) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,053 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/user/profile/get' >> (UserProfileModule.java:54).get : UserProfile | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,054 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/user/profile/' >> (UserProfileModule.java:152).index : UserProfile | @Ok(jsp:jsp.user.profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,059 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/user/profile/update' >> (UserProfileModule.java:72).update : void | @Ok(void ) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,075 org.nutz.filepool.NutFilePool.(NutFilePool.java:23) INFO - Init file-pool by: D:/MyEclipse/apache-tomcat-8.0.30/webapps/nutzbook/WEB-INF/tmp/user_avatar [20000]
2017-09-12 17:49:44,077 org.nutz.filepool.NutFilePool.(NutFilePool.java:37) DEBUG - file-pool.home: 'D:\MyEclipse\apache-tomcat-8.0.30\webapps\nutzbook\WEB-INF\tmp\user_avatar'
2017-09-12 17:49:44,078 org.nutz.filepool.NutFilePool.(NutFilePool.java:66) INFO - file-pool.cursor: 0
2017-09-12 17:49:44,082 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/user/profile/avatar' >> (UserProfileModule.java:106).uploadAvatar : void | @Ok(>>:/user/profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,085 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/user/profile/avatar' >> (UserProfileModule.java:138).readAvatar : Object | @Ok(raw:jpg) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,087 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/user/profile/active/mail' >> (UserProfileModule.java:159).activeMail : Object | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,088 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/user/profile/active/mail' >> (UserProfileModule.java:187).activeMailCallback : String | @Ok(raw ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,089 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG - '/captcha/next' >> (CaptchaModule.java:26).next : BufferedImage | @Ok(raw:png) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,090 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:217) INFO - Found 16 module methods
2017-09-12 17:49:44,090 org.nutz.mvc.impl.NutLoading.evalLocalization(NutLoading.java:331) DEBUG - @Localization not define
2017-09-12 17:49:44,094 org.nutz.mvc.impl.NutLoading.createSessionProvider(NutLoading.java:410) INFO - SessionBy --> org.nutz.integration.shiro.ShiroSessionProvider@5b5b6746
2017-09-12 17:49:44,094 org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:271) INFO - Setup application...
2017-09-12 17:49:44,097 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-12 17:49:44,099 org.nutz.ioc.aop.SimpleAopMaker.(SimpleAopMaker.java:79) DEBUG - Load AopConfigure for anno=org.nutz.ioc.aop.Aop by type=org.nutz.ioc.aop.config.impl.AnnotationAopConfigration
2017-09-12 17:49:44,100 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - >> Load definition name=dao
2017-09-12 17:49:44,100 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dao
2017-09-12 17:49:44,104 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dao) in JsonLoader(paths=[ioc/])
2017-09-12 17:49:44,104 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - >> Make...'dao'<interface org.nutz.dao.Dao>
2017-09-12 17:49:44,115 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.dao.impl.NutDao without AOP
2017-09-12 17:49:44,116 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dao' to [app]
2017-09-12 17:49:44,118 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2017-09-12 17:49:44,118 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - >> Load definition name=dataSource
2017-09-12 17:49:44,118 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dataSource
2017-09-12 17:49:44,130 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dataSource) in JsonLoader(paths=[ioc/])
2017-09-12 17:49:44,130 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - >> Make...'dataSource'<>
2017-09-12 17:49:44,149 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class com.alibaba.druid.pool.DruidDataSource without AOP
2017-09-12 17:49:44,149 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dataSource' to [app]
2017-09-12 17:49:44,459 com.alibaba.druid.pool.DruidDataSource.init(DruidDataSource.java:669) INFO - {dataSource-1} inited
2017-09-12 17:49:44,460 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2017-09-12 17:49:44,685 org.nutz.dao.jdbc.Jdbcs.(Jdbcs.java:90) DEBUG - Jdbcs init complete
2017-09-12 17:49:44,685 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
2017-09-12 17:49:44,894 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:188) DEBUG - select expert : org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert
2017-09-12 17:49:44,901 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:199) DEBUG - JDBC Driver --> mysql-connector-java-5.1.34 ( Revision: jess.balint@oracle.com-20141014163213-wqbwpf1ok2kvo1om )
2017-09-12 17:49:44,901 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:200) DEBUG - JDBC Name --> MySQL Connector Java
2017-09-12 17:49:44,901 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:202) DEBUG - JDBC URL --> jdbc:mysql://127.0.0.1:3306/nutzbook
2017-09-12 17:49:44,912 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_client=utf8
2017-09-12 17:49:44,913 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_connection=utf8
2017-09-12 17:49:44,913 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_database=utf8
2017-09-12 17:49:44,913 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_filesystem=binary
2017-09-12 17:49:44,913 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_results=
2017-09-12 17:49:44,914 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_server=utf8
2017-09-12 17:49:44,914 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_system=utf8
2017-09-12 17:49:44,914 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-12 17:49:44,917 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:213) DEBUG - Mysql : binlog_format=ROW
2017-09-12 17:49:44,917 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:220) DEBUG - Mysql : database=nutzbook
2017-09-12 17:49:44,918 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:226) DEBUG - Mysql : user=root@localhost
2017-09-12 17:49:44,932 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:221) DEBUG - Database info --> MYSQL:[MySQL - 5.7.17-log]
2017-09-12 17:49:44,939 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 17 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-12 17:49:44,997 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT COUNT(*) FROM t_user
2017-09-12 17:49:44,998 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userService'<class net.wendal.nutzbook.service.UserService>
2017-09-12 17:49:44,998 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - >> Load definition name=userService
2017-09-12 17:49:44,999 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(userService) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-12 17:49:44,999 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - >> Make...'userService'<class net.wendal.nutzbook.service.UserService>
2017-09-12 17:49:44,999 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.service.UserService without AOP
2017-09-12 17:49:44,999 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'userService' to [app]
2017-09-12 17:49:45,092 org.nutz.service.EntityService.(EntityService.java:41) DEBUG - Get TypeParams for self : net.wendal.nutzbook.bean.User
2017-09-12 17:49:45,107 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:125) ERROR - Error happend during start serivce!
java.lang.NullPointerException
at net.wendal.nutzbook.service.UserService.add(UserService.java:20)
at net.wendal.nutzbook.MainSetup.init(MainSetup.java:24)
at org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:274)
at org.nutz.mvc.impl.NutLoading.load(NutLoading.java:121)
at org.nutz.mvc.ActionHandler.(ActionHandler.java:19)
at org.nutz.mvc.NutFilter._init(NutFilter.java:91)
at org.nutz.mvc.NutFilter.init(NutFilter.java:69)
at org.apache.catalina.core.ApplicationFilterConfig.initFilter(ApplicationFilterConfig.java:279)
at org.apache.catalina.core.ApplicationFilterConfig.getFilter(ApplicationFilterConfig.java:260)
at org.apache.catalina.core.ApplicationFilterConfig.(ApplicationFilterConfig.java:105)
at org.apache.catalina.core.StandardContext.filterStart(StandardContext.java:4659)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5281)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:725)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:701)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:717)
at org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.java:1101)
at org.apache.catalina.startup.HostConfig$DeployDirectory.run(HostConfig.java:1813)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2017-09-12 17:49:45,109 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:127) ERROR - try to depose ioc
2017-09-12 17:49:45,114 org.nutz.ioc.impl.NutIoc.depose(NutIoc.java:255) INFO - org.nutz.ioc.impl.NutIoc@1774394865 is closing. startup date [17-09-12 17:49:43.785]
2017-09-12 17:49:45,114 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'userService' ...
2017-09-12 17:49:45,115 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'dao' ...
2017-09-12 17:49:45,115 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:113) DEBUG - Depose object 'dataSource' ...
2017-09-12 17:49:45,121 com.alibaba.druid.pool.DruidDataSource.close(DruidDataSource.java:1385) INFO - {dataSource-1} closed
2017-09-12 17:49:45,122 org.nutz.ioc.impl.NutIoc.depose(NutIoc.java:262) INFO - org.nutz.ioc.impl.NutIoc@1774394865 is deposed. startup date [17-09-12 17:49:43.785]
九月 12, 2017 5:49:45 下午 org.apache.catalina.core.StandardContext filterStart
严重: Exception starting filter nutz
org.nutz.mvc.LoadingException: java.lang.NullPointerException
at org.nutz.mvc.LoadingException$FC$9a86caf9ff5d3b587784fcdf555a4a7d.invoke(LoadingException.java)
at org.nutz.lang.born.AbstractConstructorBorning.call(AbstractConstructorBorning.java:25)
at org.nutz.lang.born.ConstructorBorning.born(ConstructorBorning.java:19)
at org.nutz.lang.born.BornContext.doBorn(BornContext.java:60)
at org.nutz.lang.Mirror.born(Mirror.java:990)
at org.nutz.lang.Lang.wrapThrow(Lang.java:200)
at org.nutz.mvc.impl.NutLoading.load(NutLoading.java:135)
at org.nutz.mvc.ActionHandler.(ActionHandler.java:19)
at org.nutz.mvc.NutFilter._init(NutFilter.java:91)
at org.nutz.mvc.NutFilter.init(NutFilter.java:69)
at org.apache.catalina.core.ApplicationFilterConfig.initFilter(ApplicationFilterConfig.java:279)
at org.apache.catalina.core.ApplicationFilterConfig.getFilter(ApplicationFilterConfig.java:260)
at org.apache.catalina.core.ApplicationFilterConfig.(ApplicationFilterConfig.java:105)
at org.apache.catalina.core.StandardContext.filterStart(StandardContext.java:4659)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5281)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:725)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:701)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:717)
at org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.java:1101)
at org.apache.catalina.startup.HostConfig$DeployDirectory.run(HostConfig.java:1813)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NullPointerException
at net.wendal.nutzbook.service.UserService.add(UserService.java:20)
at net.wendal.nutzbook.MainSetup.init(MainSetup.java:24)
at org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:274)
at org.nutz.mvc.impl.NutLoading.load(NutLoading.java:121)
... 19 more
九月 12, 2017 5:49:45 下午 org.apache.catalina.core.StandardContext startInternal
严重: One or more Filters failed to start. Full details will be found in the appropriate container log file
九月 12, 2017 5:49:45 下午 org.apache.catalina.core.StandardContext startInternal
严重: Context [/nutzbook] startup failed due to previous errors
九月 12, 2017 5:49:45 下午 org.apache.catalina.core.ApplicationContext log
信息: Cleaning up Shiro Environment
九月 12, 2017 5:49:45 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesJdbc
警告: The web application [nutzbook] registered the JDBC driver [com.alibaba.druid.proxy.DruidDriver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
九月 12, 2017 5:49:45 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesJdbc
警告: The web application [nutzbook] registered the JDBC driver [com.mysql.jdbc.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
九月 12, 2017 5:49:45 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
警告: The web application [nutzbook] appears to have started a thread named [Abandoned connection cleanup thread] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
java.lang.Object.wait(Native Method)
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
com.mysql.jdbc.AbandonedConnectionCleanupThread.run(AbandonedConnectionCleanupThread.java:43)
九月 12, 2017 5:49:45 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\nutzbook has finished in 3,315 ms
九月 12, 2017 5:49:45 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\ROOT
九月 12, 2017 5:49:45 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\ROOT has finished in 24 ms
九月 12, 2017 5:49:45 下午 org.apache.coyote.AbstractProtocol start
信息: Starting ProtocolHandler ["http-apr-8081"]
九月 12, 2017 5:49:45 下午 org.apache.coyote.AbstractProtocol start
信息: Starting ProtocolHandler ["ajp-apr-8009"]
九月 12, 2017 5:49:45 下午 org.apache.catalina.startup.Catalina start
信息: Server startup in 5140 ms
加了@iocbean以后报空指针异常？

九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server version:        Apache Tomcat/8.0.30
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server built:          Dec 1 2015 22:30:46 UTC
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server number:         8.0.30.0
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: OS Name:               Windows 7
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: OS Version:            6.1
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Architecture:          amd64
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Java Home:             C:\Program Files\Java\jdk1.7.0_79\jre
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: JVM Version:           1.7.0_79-b15
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: JVM Vendor:            Oracle Corporation
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: CATALINA_BASE:         D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: CATALINA_HOME:         D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dcatalina.home=D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dcatalina.base=D:\MyEclipse\apache-tomcat-8.0.30
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Djava.endorsed.dirs=D:\MyEclipse\apache-tomcat-8.0.30/common/endorsed
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Djava.io.tmpdir=D:\MyEclipse\apache-tomcat-8.0.30\temp
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Djava.library.path=C:\Program Files\Java\jdk1.7.0_79\bin;D:\MyEclipse\apache-tomcat-8.0.30\bin
九月 12, 2017 5:49:39 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dsun.io.useCanonCaches=false
九月 12, 2017 5:49:39 下午 org.apache.catalina.core.AprLifecycleListener lifecycleEvent
信息: Loaded APR based Apache Tomcat Native library 1.1.33 using APR version 1.5.1.
九月 12, 2017 5:49:39 下午 org.apache.catalina.core.AprLifecycleListener lifecycleEvent
信息: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
九月 12, 2017 5:49:39 下午 org.apache.catalina.core.AprLifecycleListener initializeSSL
信息: OpenSSL successfully initialized (OpenSSL 1.0.1m 19 Mar 2015)
九月 12, 2017 5:49:40 下午 org.apache.coyote.AbstractProtocol init
信息: Initializing ProtocolHandler ["http-apr-8081"]
九月 12, 2017 5:49:40 下午 org.apache.coyote.AbstractProtocol init
信息: Initializing ProtocolHandler ["ajp-apr-8009"]
九月 12, 2017 5:49:40 下午 org.apache.catalina.startup.Catalina load
信息: Initialization processed in 1406 ms
九月 12, 2017 5:49:40 下午 org.apache.catalina.core.StandardService startInternal
信息: Starting service Catalina
九月 12, 2017 5:49:40 下午 org.apache.catalina.core.StandardEngine startInternal
信息: Starting Servlet Engine: Apache Tomcat/8.0.30
九月 12, 2017 5:49:40 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\docs
九月 12, 2017 5:49:41 下午 org.apache.catalina.util.SessionIdGeneratorBase createSecureRandom
信息: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [794] milliseconds.
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\docs has finished in 1,246 ms
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\examples
九月 12, 2017 5:49:41 下午 org.apache.catalina.core.ApplicationContext log
信息: ContextListener: contextInitialized()
九月 12, 2017 5:49:41 下午 org.apache.catalina.core.ApplicationContext log
信息: SessionListener: contextInitialized()
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\examples has finished in 423 ms
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\host-manager
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\host-manager has finished in 34 ms
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\manager
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\manager has finished in 41 ms
九月 12, 2017 5:49:41 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\nutzbook
九月 12, 2017 5:49:42 下午 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.
九月 12, 2017 5:49:43 下午 org.apache.catalina.core.ApplicationContext log
信息: Initializing Shiro environment
2017-09-12 17:49:43,074 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:128) INFO  - Starting Shiro environment initialization.
2017-09-12 17:49:43,097 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:76) DEBUG - Checking any specified config locations.
2017-09-12 17:49:43,097 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:81) DEBUG - No INI instance or config locations specified.  Trying default config locations.
2017-09-12 17:49:43,104 org.apache.shiro.io.ResourceUtils.loadFromClassPath(ResourceUtils.java:159) DEBUG - Opening resource from class path [shiro.ini]
2017-09-12 17:49:43,111 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [main]
2017-09-12 17:49:43,112 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [urls]
2017-09-12 17:49:43,114 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-12 17:49:43,119 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=urls]
2017-09-12 17:49:43,343 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=urls]
2017-09-12 17:49:43,347 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/*] from String definition [anon]
2017-09-12 17:49:43,348 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/*] to filter [anon] with config [null]
2017-09-12 17:49:43,350 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-12 17:49:43,350 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:141) INFO  - Shiro environment initialized in 272 ms.
2017-09-12 17:49:43,387 org.nutz.mvc.NutFilter._init(NutFilter.java:85) INFO  - NutFilter[nutz] starting ...
2017-09-12 17:49:43,407 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=5 time use 9ms
2017-09-12 17:49:43,425 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=26 time use 18ms
2017-09-12 17:49:43,503 org.nutz.castor.Castors.reload(Castors.java:115) DEBUG - Using 95 castor for Castors
2017-09-12 17:49:43,535 org.nutz.mvc.config.AbstractNutConfig.createLoading(AbstractNutConfig.java:59) DEBUG - Loading by class org.nutz.mvc.impl.NutLoading
2017-09-12 17:49:43,538 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:55) INFO  - Nutz Version : 1.r.62 
2017-09-12 17:49:43,538 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:56) INFO  - Nutz.Mvc[nutz] is initializing ...
2017-09-12 17:49:43,538 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:60) DEBUG - Web Container Information:
2017-09-12 17:49:43,540 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:61) DEBUG -  - Default Charset : GBK
2017-09-12 17:49:43,540 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:62) DEBUG -  - Current . path  : D:\MyEclipse\apache-tomcat-8.0.30\bin\.
2017-09-12 17:49:43,540 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:63) DEBUG -  - Java Version    : 1.7.0_79
2017-09-12 17:49:43,540 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:64) DEBUG -  - File separator  : \
2017-09-12 17:49:43,540 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:65) DEBUG -  - Timezone        : Asia/Shanghai
2017-09-12 17:49:43,540 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:66) DEBUG -  - OS              : Windows 7 amd64
2017-09-12 17:49:43,540 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:67) DEBUG -  - ServerInfo      : Apache Tomcat/8.0.30
2017-09-12 17:49:43,541 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:68) DEBUG -  - Servlet API     : 3.1
2017-09-12 17:49:43,541 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:73) DEBUG -  - ContextPath     : /nutzbook
2017-09-12 17:49:43,541 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:74) DEBUG -  - context.tempdir : D:\MyEclipse\apache-tomcat-8.0.30\work\Catalina\localhost\nutzbook
2017-09-12 17:49:43,541 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:75) DEBUG -  - MainModule      : net.wendal.nutzbook.MainModule
2017-09-12 17:49:43,542 org.nutz.mvc.impl.NutLoading.createContext(NutLoading.java:235) DEBUG - >> app.root = D:/MyEclipse/apache-tomcat-8.0.30/webapps/nutzbook
2017-09-12 17:49:43,545 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", "*quartz"],init=[])
2017-09-12 17:49:43,612 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 2 resource by src( ioc/ ) , regex( ^(.+[.])(js|json)$ )
2017-09-12 17:49:43,612 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [dao.js]
2017-09-12 17:49:43,621 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [mail.js]
2017-09-12 17:49:43,621 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 5 bean define from path=[ioc/] --> [htmlEmail, dataSource, dao, conf, emailAuthenticator]
2017-09-12 17:49:43,650 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 17 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-12 17:49:43,681 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.bean.Role
2017-09-12 17:49:43,702 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.MainModule
2017-09-12 17:49:43,706 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.CaptchaModule
2017-09-12 17:49:43,716 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserModule
2017-09-12 17:49:43,729 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserProfileModule
2017-09-12 17:49:43,744 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2017-09-12 17:49:43,748 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.EmailServiceImpl
2017-09-12 17:49:43,754 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.UserService
2017-09-12 17:49:43,761 org.nutz.ioc.loader.annotation.AnnotationIocLoader.<init>(AnnotationIocLoader.java:52) INFO  - Found 8 classes in 1 base-packages!
beans = ["captchaModule", "cleanNonActiveUserJob", "userProfileModule", "userService", "role", "mainModule", "emailService", "userModule"]
2017-09-12 17:49:43,767 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:40) DEBUG - Loaded 5 bean define from reader --
[txREPEATABLE_READ, txREAD_COMMITTED, txNONE, txSERIALIZABLE, txREAD_UNCOMMITTED]
2017-09-12 17:49:43,772 org.nutz.ioc.loader.combo.ComboIocLoader.createIocLoader(ComboIocLoader.java:110) DEBUG - found quartz -- org.nutz.integration.quartz.QuartzIocLoader
2017-09-12 17:49:43,778 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 0 bean define from path=[] --> []
2017-09-12 17:49:43,785 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:98) INFO  - NutIoc init begin ...
2017-09-12 17:49:43,789 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:115) INFO  - ... NutIoc init complete
2017-09-12 17:49:43,795 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:159) INFO  - Build URL mapping by org.nutz.mvc.impl.UrlMappingImpl ...
2017-09-12 17:49:43,798 org.nutz.mvc.impl.NutLoading.createViewMakers(NutLoading.java:366) DEBUG - @Views(DefaultViewMaker.class)
2017-09-12 17:49:43,817 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( mvc/nutzbook-mvc-chain.js ) , regex( ^(.+[.])(js|json)$ )
2017-09-12 17:49:43,829 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-12 17:49:43,830 org.nutz.mvc.impl.NutLoading.createChainMaker(NutLoading.java:263) DEBUG - @ChainBy(org.nutz.mvc.impl.NutActionChainMaker)
2017-09-12 17:49:43,837 org.nutz.mvc.impl.Loadings.scanModules(Loadings.java:154) DEBUG - module class location 'file:/D:/MyEclipse/apache-tomcat-8.0.30/webapps/nutzbook/WEB-INF/classes/'
2017-09-12 17:49:43,838 org.nutz.mvc.impl.Loadings.scanModuleInPackage(Loadings.java:184) DEBUG -  > scan 'net.wendal.nutzbook'
2017-09-12 17:49:43,844 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 17 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-12 17:49:43,847 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.CaptchaModule'
2017-09-12 17:49:43,848 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserModule'
2017-09-12 17:49:43,848 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserProfileModule'
2017-09-12 17:49:44,034 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/add'                 >> (UserModule.java:90).add              : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,035 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/count'               >> (UserModule.java:49).count            : int        | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,038 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/'                    >> (UserModule.java:140).index           : void       | @Ok(jsp:jsp.user.list) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,043 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/delete'              >> (UserModule.java:114).delete          : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,044 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/query'               >> (UserModule.java:125).query           : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,046 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/update'              >> (UserModule.java:103).update          : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,048 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/login'               >> (UserModule.java:62).login            : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,050 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/logout'              >> (UserModule.java:83).logout           : void       | @Ok(>>:/ ) @Fail(http:500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,053 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/get'         >> (UserProfileModule.java:54).get       : UserProfile | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,054 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/'            >> (UserProfileModule.java:152).index    : UserProfile | @Ok(jsp:jsp.user.profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,059 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/update'      >> (UserProfileModule.java:72).update    : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,075 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:23) INFO  - Init file-pool by: D:/MyEclipse/apache-tomcat-8.0.30/webapps/nutzbook/WEB-INF/tmp/user_avatar [20000]
2017-09-12 17:49:44,077 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:37) DEBUG - file-pool.home: 'D:\MyEclipse\apache-tomcat-8.0.30\webapps\nutzbook\WEB-INF\tmp\user_avatar'
2017-09-12 17:49:44,078 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:66) INFO  - file-pool.cursor: 0
2017-09-12 17:49:44,082 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:106).uploadAvatar : void       | @Ok(>>:/user/profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,085 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:138).readAvatar : Object     | @Ok(raw:jpg) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,087 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:159).activeMail : Object     | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,088 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:187).activeMailCallback : String     | @Ok(raw  ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,089 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/captcha/next'             >> (CaptchaModule.java:26).next          : BufferedImage | @Ok(raw:png) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2017-09-12 17:49:44,090 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:217) INFO  - Found 16 module methods
2017-09-12 17:49:44,090 org.nutz.mvc.impl.NutLoading.evalLocalization(NutLoading.java:331) DEBUG - @Localization not define
2017-09-12 17:49:44,094 org.nutz.mvc.impl.NutLoading.createSessionProvider(NutLoading.java:410) INFO  - SessionBy --> org.nutz.integration.shiro.ShiroSessionProvider@5b5b6746
2017-09-12 17:49:44,094 org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:271) INFO  - Setup application...
2017-09-12 17:49:44,097 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2017-09-12 17:49:44,099 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-12 17:49:44,100 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dao
2017-09-12 17:49:44,100 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dao
2017-09-12 17:49:44,104 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dao) in JsonLoader(paths=[ioc/])
2017-09-12 17:49:44,104 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dao'<interface org.nutz.dao.Dao>
2017-09-12 17:49:44,115 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.dao.impl.NutDao without AOP
2017-09-12 17:49:44,116 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dao' to [app] 
2017-09-12 17:49:44,118 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2017-09-12 17:49:44,118 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dataSource
2017-09-12 17:49:44,118 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dataSource
2017-09-12 17:49:44,130 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dataSource) in JsonLoader(paths=[ioc/])
2017-09-12 17:49:44,130 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dataSource'<>
2017-09-12 17:49:44,149 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class com.alibaba.druid.pool.DruidDataSource without AOP
2017-09-12 17:49:44,149 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dataSource' to [app] 
2017-09-12 17:49:44,459 com.alibaba.druid.pool.DruidDataSource.init(DruidDataSource.java:669) INFO  - {dataSource-1} inited
2017-09-12 17:49:44,460 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2017-09-12 17:49:44,685 org.nutz.dao.jdbc.Jdbcs.<clinit>(Jdbcs.java:90) DEBUG - Jdbcs init complete
2017-09-12 17:49:44,685 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
2017-09-12 17:49:44,894 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:188) DEBUG - select expert : org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert
2017-09-12 17:49:44,901 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:199) DEBUG - JDBC Driver --> mysql-connector-java-5.1.34 ( Revision: jess.balint@oracle.com-20141014163213-wqbwpf1ok2kvo1om )
2017-09-12 17:49:44,901 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:200) DEBUG - JDBC Name   --> MySQL Connector Java
2017-09-12 17:49:44,901 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:202) DEBUG - JDBC URL    --> jdbc:mysql://127.0.0.1:3306/nutzbook
2017-09-12 17:49:44,912 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_client=utf8
2017-09-12 17:49:44,913 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_connection=utf8
2017-09-12 17:49:44,913 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_database=utf8
2017-09-12 17:49:44,913 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_filesystem=binary
2017-09-12 17:49:44,913 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_results=
2017-09-12 17:49:44,914 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_server=utf8
2017-09-12 17:49:44,914 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:206) DEBUG - Mysql : character_set_system=utf8
2017-09-12 17:49:44,914 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-12 17:49:44,917 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:213) DEBUG - Mysql : binlog_format=ROW
2017-09-12 17:49:44,917 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:220) DEBUG - Mysql : database=nutzbook
2017-09-12 17:49:44,918 org.nutz.dao.impl.jdbc.mysql.MysqlJdbcExpert.checkDataSource(MysqlJdbcExpert.java:226) DEBUG - Mysql : user=root@localhost
2017-09-12 17:49:44,932 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:221) DEBUG - Database info --> MYSQL:[MySQL - 5.7.17-log]
2017-09-12 17:49:44,939 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 17 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2017-09-12 17:49:44,997 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT COUNT(*) FROM t_user 
2017-09-12 17:49:44,998 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'userService'<class net.wendal.nutzbook.service.UserService>
2017-09-12 17:49:44,998 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=userService
2017-09-12 17:49:44,999 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(userService) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2017-09-12 17:49:44,999 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'userService'<class net.wendal.nutzbook.service.UserService>
2017-09-12 17:49:44,999 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.service.UserService without AOP
2017-09-12 17:49:44,999 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'userService' to [app] 
2017-09-12 17:49:45,092 org.nutz.service.EntityService.<init>(EntityService.java:41) DEBUG - Get TypeParams for self : net.wendal.nutzbook.bean.User
2017-09-12 17:49:45,107 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:125) ERROR - Error happend during start serivce!
java.lang.NullPointerException
	at net.wendal.nutzbook.service.UserService.add(UserService.java:20)
	at net.wendal.nutzbook.MainSetup.init(MainSetup.java:24)
	at org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:274)
	at org.nutz.mvc.impl.NutLoading.load(NutLoading.java:121)
	at org.nutz.mvc.ActionHandler.<init>(ActionHandler.java:19)
	at org.nutz.mvc.NutFilter._init(NutFilter.java:91)
	at org.nutz.mvc.NutFilter.init(NutFilter.java:69)
	at org.apache.catalina.core.ApplicationFilterConfig.initFilter(ApplicationFilterConfig.java:279)
	at org.apache.catalina.core.ApplicationFilterConfig.getFilter(ApplicationFilterConfig.java:260)
	at org.apache.catalina.core.ApplicationFilterConfig.<init>(ApplicationFilterConfig.java:105)
	at org.apache.catalina.core.StandardContext.filterStart(StandardContext.java:4659)
	at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5281)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
	at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:725)
	at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:701)
	at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:717)
	at org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.java:1101)
	at org.apache.catalina.startup.HostConfig$DeployDirectory.run(HostConfig.java:1813)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
2017-09-12 17:49:45,109 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:127) ERROR - try to depose ioc
2017-09-12 17:49:45,114 org.nutz.ioc.impl.NutIoc.depose(NutIoc.java:255) INFO  - org.nutz.ioc.impl.NutIoc@1774394865 is closing. startup date [17-09-12 17:49:43.785]
2017-09-12 17:49:45,114 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'userService' ...
2017-09-12 17:49:45,115 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'dao' ...
2017-09-12 17:49:45,115 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:113) DEBUG - Depose object 'dataSource' ...
2017-09-12 17:49:45,121 com.alibaba.druid.pool.DruidDataSource.close(DruidDataSource.java:1385) INFO  - {dataSource-1} closed
2017-09-12 17:49:45,122 org.nutz.ioc.impl.NutIoc.depose(NutIoc.java:262) INFO  - org.nutz.ioc.impl.NutIoc@1774394865 is deposed. startup date [17-09-12 17:49:43.785]
九月 12, 2017 5:49:45 下午 org.apache.catalina.core.StandardContext filterStart
严重: Exception starting filter nutz
org.nutz.mvc.LoadingException: java.lang.NullPointerException
	at org.nutz.mvc.LoadingException$FC$9a86caf9ff5d3b587784fcdf555a4a7d.invoke(LoadingException.java)
	at org.nutz.lang.born.AbstractConstructorBorning.call(AbstractConstructorBorning.java:25)
	at org.nutz.lang.born.ConstructorBorning.born(ConstructorBorning.java:19)
	at org.nutz.lang.born.BornContext.doBorn(BornContext.java:60)
	at org.nutz.lang.Mirror.born(Mirror.java:990)
	at org.nutz.lang.Lang.wrapThrow(Lang.java:200)
	at org.nutz.mvc.impl.NutLoading.load(NutLoading.java:135)
	at org.nutz.mvc.ActionHandler.<init>(ActionHandler.java:19)
	at org.nutz.mvc.NutFilter._init(NutFilter.java:91)
	at org.nutz.mvc.NutFilter.init(NutFilter.java:69)
	at org.apache.catalina.core.ApplicationFilterConfig.initFilter(ApplicationFilterConfig.java:279)
	at org.apache.catalina.core.ApplicationFilterConfig.getFilter(ApplicationFilterConfig.java:260)
	at org.apache.catalina.core.ApplicationFilterConfig.<init>(ApplicationFilterConfig.java:105)
	at org.apache.catalina.core.StandardContext.filterStart(StandardContext.java:4659)
	at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5281)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
	at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:725)
	at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:701)
	at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:717)
	at org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.java:1101)
	at org.apache.catalina.startup.HostConfig$DeployDirectory.run(HostConfig.java:1813)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NullPointerException
	at net.wendal.nutzbook.service.UserService.add(UserService.java:20)
	at net.wendal.nutzbook.MainSetup.init(MainSetup.java:24)
	at org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:274)
	at org.nutz.mvc.impl.NutLoading.load(NutLoading.java:121)
	... 19 more
九月 12, 2017 5:49:45 下午 org.apache.catalina.core.StandardContext startInternal
严重: One or more Filters failed to start. Full details will be found in the appropriate container log file
九月 12, 2017 5:49:45 下午 org.apache.catalina.core.StandardContext startInternal
严重: Context [/nutzbook] startup failed due to previous errors
九月 12, 2017 5:49:45 下午 org.apache.catalina.core.ApplicationContext log
信息: Cleaning up Shiro Environment
九月 12, 2017 5:49:45 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesJdbc
警告: The web application [nutzbook] registered the JDBC driver [com.alibaba.druid.proxy.DruidDriver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
九月 12, 2017 5:49:45 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesJdbc
警告: The web application [nutzbook] registered the JDBC driver [com.mysql.jdbc.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
九月 12, 2017 5:49:45 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
警告: The web application [nutzbook] appears to have started a thread named [Abandoned connection cleanup thread] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 java.lang.Object.wait(Native Method)
 java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
 com.mysql.jdbc.AbandonedConnectionCleanupThread.run(AbandonedConnectionCleanupThread.java:43)
九月 12, 2017 5:49:45 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\nutzbook has finished in 3,315 ms
九月 12, 2017 5:49:45 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\ROOT
九月 12, 2017 5:49:45 下午 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deployment of web application directory D:\MyEclipse\apache-tomcat-8.0.30\webapps\ROOT has finished in 24 ms
九月 12, 2017 5:49:45 下午 org.apache.coyote.AbstractProtocol start
信息: Starting ProtocolHandler ["http-apr-8081"]
九月 12, 2017 5:49:45 下午 org.apache.coyote.AbstractProtocol start
信息: Starting ProtocolHandler ["ajp-apr-8009"]
九月 12, 2017 5:49:45 下午 org.apache.catalina.startup.Catalina start
信息: Server startup in 5140 ms

加了@iocbean以后报空指针异常？

兽哥 这又是怎么看出来的呀

是UserModule没有加吗

嗯嗯 在UserService里面加了dao的注入就好了

谢谢兽哥 下班啦