UserModule.java代码

package net.wendal.nutzbook.module;

import javax.servlet.http.HttpSession;

import org.apache.shiro.SecurityUtils;
import org.apache.shiro.authz.annotation.RequiresPermissions;
import org.apache.shiro.authz.annotation.RequiresUser;
import org.nutz.aop.interceptor.ioc.TransAop;
import org.nutz.dao.Cnd;
import org.nutz.dao.QueryResult;
import org.nutz.dao.pager.Pager;
import org.nutz.integration.shiro.SimpleShiroToken;
import org.nutz.ioc.aop.Aop;
import org.nutz.ioc.loader.annotation.Inject;
import org.nutz.ioc.loader.annotation.IocBean;
import org.nutz.lang.Strings;
import org.nutz.lang.util.NutMap;
import org.nutz.mvc.Scope;
import org.nutz.mvc.annotation.At;
import org.nutz.mvc.annotation.Attr;
import org.nutz.mvc.annotation.Fail;
import org.nutz.mvc.annotation.GET;
import org.nutz.mvc.annotation.Ok;
import org.nutz.mvc.annotation.POST;
import org.nutz.mvc.annotation.Param;

import net.wendal.nutzbook.bean.User;
import net.wendal.nutzbook.bean.UserProfile;
import net.wendal.nutzbook.service.UserService;
import net.wendal.nutzbook.util.Toolkit;

@IocBean // 声明为Ioc容器中的一个Bean

@At("/user") // 整个模块的路径前缀
@Ok("json:{locked:'password|salt',ignoreNull:true}") // 忽略password和salt属性,忽略空属性的json输出
@Fail("http:500") // 抛出异常的话,就走500页面

public class UserModule extends BaseModule {
	@Inject
	protected UserService userService;

	@At
	public int count() { // 统计用户数的方法,算是个测试点
		return dao.count(User.class);
	}

	@At

	@POST
	public Object login(@Param("username") String username, @Param("password") String password,
			@Param("captcha") String captcha, @Attr(scope = Scope.SESSION, value = "nutz_captcha") String _captcha,
			HttpSession session) {
		NutMap re = new NutMap();
		if (!Toolkit.checkCaptcha(_captcha, captcha)) {
			return re.setv("ok", false).setv("msg", "验证码错误");
		}
		int userId = userService.fetch(username, password);
		if (userId < 0) {
			return re.setv("ok", false).setv("msg", "用户名或密码错误");
		} else {
			session.setAttribute("me", userId);
			// 完成nutdao_realm后启用.
			SecurityUtils.getSubject().login(new SimpleShiroToken(userId));
			return re.setv("ok", true);
		}
	}

	@At
	@Ok(">>:/") // 跟其他方法不同,这个方法完成后就跳转首页了
	public void logout(HttpSession session) {
		session.invalidate();
	}

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

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

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

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

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

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

	@At
	@Fail("jsp:jsp.500")
	public void error() {
		throw new RuntimeException();
	}

	@GET
	@At("/login")

	@Ok("jsp:jsp.user.login") // 降内部重定向到登录jsp
	public void loginPage() {
	}
}

AuthorityServiceImpl.java代码

package net.wendal.nutzbook.service;

import java.util.List;

import org.nutz.dao.Chain;
import org.nutz.dao.Cnd;
import org.nutz.dao.Dao;
import org.nutz.dao.entity.Record;
import org.nutz.ioc.loader.annotation.Inject;

import net.wendal.nutzbook.bean.Permission;
import net.wendal.nutzbook.bean.Role;
import net.wendal.nutzbook.bean.User;

public class AuthorityServiceImpl implements AuthorityService {
	@Inject
	protected Dao dao;

	@Override
	public void checkBasicRoles(User admin) {
		// 检查一下admin的权限
		Role adminRole = dao.fetch(Role.class, "admin");
		if (adminRole == null) {
			adminRole = addRole("admin");
		}
		// admin账号必须存在与admin组
		if (0 == dao.count("t_user_role",
				Cnd.where("u_id", "=", admin.getId()).and("role_id", "=", adminRole.getId()))) {
			dao.insert("t_user_role", Chain.make("u_id", admin.getId()).add("role_id", adminRole.getId()));
		}
		// admin组必须有authority:* 也就是权限管理相关的权限
		List<Record> res = dao.query("t_role_permission", Cnd.where("role_id", "=", adminRole.getId()));
		OUT: for (Permission permission : dao.query(Permission.class,
				Cnd.where("name", "like", "authority:%").or("name", "like", "user:%"), null)) {
			for (Record re : res) {
				if (re.getInt("permission_id") == permission.getId())
					continue OUT;
			}
			dao.insert("t_role_permission",
					Chain.make("role_id", adminRole.getId()).add("permission_id", permission.getId()));
		}
		;
	}

	@Override
	public void initFormPackage(String pkg) {
		// TODO Auto-generated method stub

	}

	@Override
	public void addPermission(String permission) {
		// TODO Auto-generated method stub

	}

	@Override
	public Role addRole(String role) {
		// TODO Auto-generated method stub
		return null;
	}
}

@管理员(admin)
UserModule是说的这个里面么 加上了

MainSetup.java 代码

其他的都是复制粘贴的 ，在 入口方法的权限管理--页面测试 这一步的时候一切正常

package net.wendal.nutzbook;

import org.nutz.dao.Dao;
import org.nutz.dao.util.Daos;
import org.nutz.integration.quartz.NutQuartzCronJobFactory;
import org.nutz.ioc.Ioc;
import org.nutz.mvc.NutConfig;
import org.nutz.mvc.Setup;

import net.wendal.nutzbook.bean.User;
import net.wendal.nutzbook.service.AuthorityService;
import net.wendal.nutzbook.service.UserService;

public class MainSetup implements Setup {

  // 注意是init方法,不是destroy方法
    public void init(NutConfig nc) {
        Ioc ioc = nc.getIoc();
        Dao dao = ioc.get(Dao.class);
        // 如果提示没有createTablesInPackage方法,请确认用了最新版的nutz,且老版本的nutz已经删除干净
        Daos.createTablesInPackage(dao, "net.wendal.nutzbook", false);
        Daos.migration(dao, User.class, true, false, false);

        
        // 初始化默认根用户
        if (dao.count(User.class) == 0) {
            UserService us = ioc.get(UserService.class);
            us.add("admin", "123456");
        }
        // 获取NutQuartzCronJobFactory从而触发计划任务的初始化与启动
        ioc.get(NutQuartzCronJobFactory.class);
        // 测试发送邮件
//      try {
//          HtmlEmail email = ioc.get(HtmlEmail.class);
//          email.setSubject("测试NutzBook");
//          email.setMsg("This is a test mail ... :-)" + System.currentTimeMillis());
//          email.addTo("vt400@qq.com");//请务必改成您自己的邮箱啊!!!
//          email.buildMimeMessage();
//          email.sendMimeMessage();
//      } catch (Exception e) {
//          e.printStackTrace();
//      }
        
        AuthorityService as = ioc.get(AuthorityService.class);
        as.initFormPackage("net.wendal.nutzbook");
        as.checkBasicRoles(dao.fetch(User.class, "admin"));

    }

    public void destroy(NutConfig nc) {
         // webapp销毁之前执行的逻辑
         // 这个时候依然可以从nc取出ioc, 然后取出需要的ioc 对象进行操作
    }
    // 测试发送邮件
   
}

@管理员(admin)
加上了之后仍然报错
感谢解答

一月 26, 2018 4:02:46 下午 org.apache.tomcat.util.digester.SetPropertiesRule begin
警告: [SetPropertiesRule]{Server/Service/Engine/Host/Context} Setting property 'source' to 'org.eclipse.jst.jee.server:demo' did not find a matching property.
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server version:        Apache Tomcat/8.0.36
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server built:          Jun 9 2016 13:55:50 UTC
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server number:         8.0.36.0
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: OS Name:               Windows 7
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: OS Version:            6.1
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Architecture:          amd64
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Java Home:             C:\Program Files\Java\jre1.8.0_151
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: JVM Version:           1.8.0_151-b12
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: JVM Vendor:            Oracle Corporation
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: CATALINA_BASE:         D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: CATALINA_HOME:         D:\soft
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -agentlib:jdwp=transport=dt_socket,suspend=y,address=localhost:54423
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dcatalina.base=D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dcatalina.home=D:\soft
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dwtp.deploy=D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Djava.endorsed.dirs=D:\soft\endorsed
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dfile.encoding=UTF-8
一月 26, 2018 4:02:46 下午 org.apache.catalina.core.AprLifecycleListener lifecycleEvent
信息: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: C:\Program Files\Java\jre1.8.0_151\bin;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;C:/Program Files/Java/jre1.8.0_151/bin/server;C:/Program Files/Java/jre1.8.0_151/bin;C:/Program Files/Java/jre1.8.0_151/lib/amd64;C:\ProgramData\Oracle\Java\javapath;E:\orcl\product\11.2.0\dbhome_1\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\java\jdk1.8.0_151\bin;C:\java\jdk1.8.0_151\jre\bin;C:\Program Files\TortoiseSVN\bin;D:\soft\apache-maven-3.5.2-bin\apache-maven-3.5.2\bin;C:\Users\Administrator\Downloads\mysql-5.7.20-winx64\mysql-5.7.20-winx64\bin;D:\software\tortoiseGit\bin;C:\Users\Administrator\Desktop;;.
一月 26, 2018 4:02:46 下午 org.apache.coyote.AbstractProtocol init
信息: Initializing ProtocolHandler ["http-nio-8080"]
一月 26, 2018 4:02:46 下午 org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
信息: Using a shared selector for servlet write/read
一月 26, 2018 4:02:46 下午 org.apache.coyote.AbstractProtocol init
信息: Initializing ProtocolHandler ["ajp-nio-8009"]
一月 26, 2018 4:02:46 下午 org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
信息: Using a shared selector for servlet write/read
一月 26, 2018 4:02:46 下午 org.apache.catalina.startup.Catalina load
信息: Initialization processed in 879 ms
一月 26, 2018 4:02:46 下午 org.apache.catalina.core.StandardService startInternal
信息: Starting service Catalina
一月 26, 2018 4:02:46 下午 org.apache.catalina.core.StandardEngine startInternal
信息: Starting Servlet Engine: Apache Tomcat/8.0.36
一月 26, 2018 4:02:48 下午 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.
一月 26, 2018 4:02:51 下午 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.
一月 26, 2018 4:02:51 下午 org.apache.catalina.core.ApplicationContext log
信息: Initializing Shiro environment
2018-01-26 16:02:51,665 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:128) INFO  - Starting Shiro environment initialization.
2018-01-26 16:02:51,686 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:76) DEBUG - Checking any specified config locations.
2018-01-26 16:02:51,687 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:81) DEBUG - No INI instance or config locations specified.  Trying default config locations.
2018-01-26 16:02:51,691 org.apache.shiro.io.ResourceUtils.loadFromClassPath(ResourceUtils.java:159) DEBUG - Opening resource from class path [shiro.ini]
2018-01-26 16:02:51,696 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [main]
2018-01-26 16:02:51,697 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [urls]
2018-01-26 16:02:51,698 org.apache.shiro.web.env.IniWebEnvironment.getDefaultIni(IniWebEnvironment.java:136) DEBUG - Discovered non-empty INI configuration at location 'classpath:shiro.ini'.  Using for configuration.
2018-01-26 16:02:51,709 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=main,urls]
2018-01-26 16:02:51,955 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:234) DEBUG - No authorizationCache instance set.  Checking for a cacheManager...
2018-01-26 16:02:51,956 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:248) DEBUG - No cache or cacheManager properties have been set.  Authorization cache cannot be obtained.
2018-01-26 16:02:51,956 org.apache.shiro.config.ReflectionBuilder.createNewInstance(ReflectionBuilder.java:296) INFO  - An instance with name 'authc' already exists.  Redefining this object as a new instance of type org.nutz.integration.shiro.SimpleAuthenticationFilter
2018-01-26 16:02:51,983 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: false
2018-01-26 16:02:51,983 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Boolean' value 'false' to type 'Boolean'
2018-01-26 16:02:51,984 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Boolean
2018-01-26 16:02:51,986 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:02:51,986 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Byte'
2018-01-26 16:02:51,987 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Byte value '0'
2018-01-26 16:02:51,988 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value:  
2018-01-26 16:02:51,989 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Character' value ' ' to type 'Character'
2018-01-26 16:02:51,989 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Character
2018-01-26 16:02:51,990 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:02:51,990 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Double'
2018-01-26 16:02:51,990 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Double value '0.0'
2018-01-26 16:02:51,991 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:02:51,991 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Float'
2018-01-26 16:02:51,991 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Float value '0.0'
2018-01-26 16:02:51,992 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:02:51,992 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Integer'
2018-01-26 16:02:51,992 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Integer
2018-01-26 16:02:51,993 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:02:51,993 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Long'
2018-01-26 16:02:51,993 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Long value '0'
2018-01-26 16:02:51,994 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:02:51,995 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Short'
2018-01-26 16:02:51,995 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Short value '0'
2018-01-26 16:02:51,996 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0.0
2018-01-26 16:02:51,997 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigDecimal' value '0.0' to type 'BigDecimal'
2018-01-26 16:02:51,997 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigDecimal
2018-01-26 16:02:51,997 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:02:51,998 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigInteger' value '0' to type 'BigInteger'
2018-01-26 16:02:51,998 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigInteger
2018-01-26 16:02:51,998 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: false
2018-01-26 16:02:51,998 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Boolean' value 'false' to type 'Boolean'
2018-01-26 16:02:51,998 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Boolean
2018-01-26 16:02:51,998 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:02:51,999 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Byte'
2018-01-26 16:02:51,999 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Byte value '0'
2018-01-26 16:02:51,999 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value:  
2018-01-26 16:02:51,999 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Character' value ' ' to type 'Character'
2018-01-26 16:02:51,999 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Character
2018-01-26 16:02:51,999 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:02:51,999 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Double'
2018-01-26 16:02:52,000 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Double value '0.0'
2018-01-26 16:02:52,000 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:02:52,000 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Float'
2018-01-26 16:02:52,000 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Float value '0.0'
2018-01-26 16:02:52,000 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:02:52,000 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Integer'
2018-01-26 16:02:52,000 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Integer
2018-01-26 16:02:52,001 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:02:52,001 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Long'
2018-01-26 16:02:52,001 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Long value '0'
2018-01-26 16:02:52,001 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:02:52,001 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Short'
2018-01-26 16:02:52,002 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Short value '0'
2018-01-26 16:02:52,003 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 
2018-01-26 16:02:52,003 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value '' to type 'String'
2018-01-26 16:02:52,010 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Z@592a7d40
2018-01-26 16:02:52,010 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'boolean[]' value '[Z@592a7d40' to type 'boolean[]'
2018-01-26 16:02:52,010 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a boolean[]
2018-01-26 16:02:52,010 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [B@419723a7
2018-01-26 16:02:52,011 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'byte[]' value '[B@419723a7' to type 'byte[]'
2018-01-26 16:02:52,011 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a byte[]
2018-01-26 16:02:52,013 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [C@2958ce3a
2018-01-26 16:02:52,013 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'char[]' value '[C@2958ce3a' to type 'char[]'
2018-01-26 16:02:52,013 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a char[]
2018-01-26 16:02:52,014 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [D@20ff1518
2018-01-26 16:02:52,014 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'double[]' value '[D@20ff1518' to type 'double[]'
2018-01-26 16:02:52,014 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a double[]
2018-01-26 16:02:52,014 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [F@2ab5bc3a
2018-01-26 16:02:52,014 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'float[]' value '[F@2ab5bc3a' to type 'float[]'
2018-01-26 16:02:52,014 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a float[]
2018-01-26 16:02:52,014 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [I@52c728d0
2018-01-26 16:02:52,014 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'int[]' value '[I@52c728d0' to type 'int[]'
2018-01-26 16:02:52,015 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a int[]
2018-01-26 16:02:52,015 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [J@3d8105ac
2018-01-26 16:02:52,015 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'long[]' value '[J@3d8105ac' to type 'long[]'
2018-01-26 16:02:52,015 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a long[]
2018-01-26 16:02:52,016 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [S@658e90d1
2018-01-26 16:02:52,016 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'short[]' value '[S@658e90d1' to type 'short[]'
2018-01-26 16:02:52,016 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a short[]
2018-01-26 16:02:52,016 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.math.BigDecimal;@625db436
2018-01-26 16:02:52,016 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigDecimal[]' value '[Ljava.math.BigDecimal;@625db436' to type 'BigDecimal[]'
2018-01-26 16:02:52,016 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigDecimal[]
2018-01-26 16:02:52,016 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.math.BigInteger;@3c2e49ea
2018-01-26 16:02:52,016 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigInteger[]' value '[Ljava.math.BigInteger;@3c2e49ea' to type 'BigInteger[]'
2018-01-26 16:02:52,017 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigInteger[]
2018-01-26 16:02:52,017 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Boolean;@2db75ea6
2018-01-26 16:02:52,017 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Boolean[]' value '[Ljava.lang.Boolean;@2db75ea6' to type 'Boolean[]'
2018-01-26 16:02:52,018 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Boolean[]
2018-01-26 16:02:52,018 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Byte;@22c4b322
2018-01-26 16:02:52,018 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Byte[]' value '[Ljava.lang.Byte;@22c4b322' to type 'Byte[]'
2018-01-26 16:02:52,018 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Byte[]
2018-01-26 16:02:52,018 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Character;@174eb1c6
2018-01-26 16:02:52,019 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Character[]' value '[Ljava.lang.Character;@174eb1c6' to type 'Character[]'
2018-01-26 16:02:52,019 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Character[]
2018-01-26 16:02:52,019 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Double;@5961cbdc
2018-01-26 16:02:52,019 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Double[]' value '[Ljava.lang.Double;@5961cbdc' to type 'Double[]'
2018-01-26 16:02:52,019 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Double[]
2018-01-26 16:02:52,019 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Float;@496e1b7f
2018-01-26 16:02:52,020 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Float[]' value '[Ljava.lang.Float;@496e1b7f' to type 'Float[]'
2018-01-26 16:02:52,020 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Float[]
2018-01-26 16:02:52,020 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Integer;@7ca4429b
2018-01-26 16:02:52,020 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer[]' value '[Ljava.lang.Integer;@7ca4429b' to type 'Integer[]'
2018-01-26 16:02:52,020 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Integer[]
2018-01-26 16:02:52,020 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Long;@1518341b
2018-01-26 16:02:52,020 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Long[]' value '[Ljava.lang.Long;@1518341b' to type 'Long[]'
2018-01-26 16:02:52,020 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Long[]
2018-01-26 16:02:52,021 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Short;@2c947024
2018-01-26 16:02:52,023 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Short[]' value '[Ljava.lang.Short;@2c947024' to type 'Short[]'
2018-01-26 16:02:52,024 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Short[]
2018-01-26 16:02:52,024 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.String;@6589ca58
2018-01-26 16:02:52,024 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String[]' value '[Ljava.lang.String;@6589ca58' to type 'String[]'
2018-01-26 16:02:52,024 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a String[]
2018-01-26 16:02:52,024 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Class;@3b67fce8
2018-01-26 16:02:52,025 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Class[]' value '[Ljava.lang.Class;@3b67fce8' to type 'Class[]'
2018-01-26 16:02:52,025 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Class[]
2018-01-26 16:02:52,025 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.util.Date;@6f8bbf73
2018-01-26 16:02:52,026 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Date[]' value '[Ljava.util.Date;@6f8bbf73' to type 'Date[]'
2018-01-26 16:02:52,027 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Date[]
2018-01-26 16:02:52,027 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.util.Calendar;@4be12ab6
2018-01-26 16:02:52,027 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Calendar[]' value '[Ljava.util.Calendar;@4be12ab6' to type 'Calendar[]'
2018-01-26 16:02:52,027 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Calendar[]
2018-01-26 16:02:52,028 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.io.File;@7d275136
2018-01-26 16:02:52,028 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.io.File[]' value '[Ljava.io.File;@7d275136' to type 'java.io.File[]'
2018-01-26 16:02:52,028 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.io.File[]
2018-01-26 16:02:52,028 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.sql.Date;@12e6a733
2018-01-26 16:02:52,028 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.sql.Date[]' value '[Ljava.sql.Date;@12e6a733' to type 'java.sql.Date[]'
2018-01-26 16:02:52,028 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.sql.Date[]
2018-01-26 16:02:52,029 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.sql.Time;@37ee7730
2018-01-26 16:02:52,029 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.sql.Time[]' value '[Ljava.sql.Time;@37ee7730' to type 'java.sql.Time[]'
2018-01-26 16:02:52,029 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.sql.Time[]
2018-01-26 16:02:52,029 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.sql.Timestamp;@57ffd016
2018-01-26 16:02:52,029 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.sql.Timestamp[]' value '[Ljava.sql.Timestamp;@57ffd016' to type 'java.sql.Timestamp[]'
2018-01-26 16:02:52,029 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.sql.Timestamp[]
2018-01-26 16:02:52,029 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.net.URL;@47f2b392
2018-01-26 16:02:52,029 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.net.URL[]' value '[Ljava.net.URL;@47f2b392' to type 'java.net.URL[]'
2018-01-26 16:02:52,029 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.net.URL[]
2018-01-26 16:02:52,058 org.apache.commons.beanutils.ConvertUtilsBean.convert(ConvertUtilsBean.java:481) DEBUG - Convert string '/user/login' to class 'java.lang.String'
2018-01-26 16:02:52,058 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value '/user/login' to type 'String'
2018-01-26 16:02:52,078 org.apache.commons.beanutils.ConvertUtilsBean.convert(ConvertUtilsBean.java:481) DEBUG - Convert string '/user/login' to class 'java.lang.String'
2018-01-26 16:02:52,078 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value '/user/login' to type 'String'
2018-01-26 16:02:52,078 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:234) DEBUG - No authorizationCache instance set.  Checking for a cacheManager...
2018-01-26 16:02:52,078 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:248) DEBUG - No cache or cacheManager properties have been set.  Authorization cache cannot be obtained.
2018-01-26 16:02:52,081 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=main,urls]
2018-01-26 16:02:52,084 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/rs/*] from String definition [anon]
2018-01-26 16:02:52,085 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/rs/*] to filter [anon] with config [null]
2018-01-26 16:02:52,086 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/logout] from String definition [logout]
2018-01-26 16:02:52,086 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/logout] to filter [logout] with config [null]
2018-01-26 16:02:52,086 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/error] from String definition [anon]
2018-01-26 16:02:52,086 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/error] to filter [anon] with config [null]
2018-01-26 16:02:52,086 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/login] from String definition [anon]
2018-01-26 16:02:52,086 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/login] to filter [anon] with config [null]
2018-01-26 16:02:52,086 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/profile/active/mail] from String definition [anon]
2018-01-26 16:02:52,086 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/profile/active/mail] to filter [anon] with config [null]
2018-01-26 16:02:52,088 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]
2018-01-26 16:02:52,088 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:141) INFO  - Shiro environment initialized in 413 ms.
2018-01-26 16:02:52,127 org.nutz.mvc.NutFilter._init(NutFilter.java:85) INFO  - NutFilter[nutz] starting ...
2018-01-26 16:02:52,157 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=10 time use 20ms
2018-01-26 16:02:52,166 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=30 time use 9ms
2018-01-26 16:02:52,232 org.nutz.castor.Castors.reload(Castors.java:115) DEBUG - Using 95 castor for Castors
2018-01-26 16:02:52,258 org.nutz.mvc.config.AbstractNutConfig.createLoading(AbstractNutConfig.java:59) DEBUG - Loading by class org.nutz.mvc.impl.NutLoading
2018-01-26 16:02:52,260 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:55) INFO  - Nutz Version : 1.r.62 
2018-01-26 16:02:52,260 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:56) INFO  - Nutz.Mvc[nutz] is initializing ...
2018-01-26 16:02:52,261 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:60) DEBUG - Web Container Information:
2018-01-26 16:02:52,262 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:61) DEBUG -  - Default Charset : UTF-8
2018-01-26 16:02:52,262 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:62) DEBUG -  - Current . path  : C:\Users\Administrator\Desktop\.
2018-01-26 16:02:52,262 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:63) DEBUG -  - Java Version    : 1.8.0_151
2018-01-26 16:02:52,262 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:64) DEBUG -  - File separator  : \
2018-01-26 16:02:52,262 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:65) DEBUG -  - Timezone        : Asia/Shanghai
2018-01-26 16:02:52,263 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:66) DEBUG -  - OS              : Windows 7 amd64
2018-01-26 16:02:52,263 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:67) DEBUG -  - ServerInfo      : Apache Tomcat/8.0.36
2018-01-26 16:02:52,264 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:68) DEBUG -  - Servlet API     : 3.1
2018-01-26 16:02:52,264 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:73) DEBUG -  - ContextPath     : /demo
2018-01-26 16:02:52,264 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:74) DEBUG -  - context.tempdir : D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\work\Catalina\localhost\demo
2018-01-26 16:02:52,264 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:75) DEBUG -  - MainModule      : net.wendal.nutzbook.MainModule
2018-01-26 16:02:52,265 org.nutz.mvc.impl.NutLoading.createContext(NutLoading.java:235) DEBUG - >> app.root = D:/workspace/.metadata/.plugins/org.eclipse.wst.server.core/tmp1/wtpwebapps/demo
2018-01-26 16:02:52,270 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=[])
2018-01-26 16:02:52,346 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 2 resource by src( ioc/ ) , regex( ^(.+[.])(js|json)$ )
2018-01-26 16:02:52,346 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [dao.js]
2018-01-26 16:02:52,359 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [mail.js]
2018-01-26 16:02:52,361 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 5 bean define from path=[ioc/] --> [conf, dao, emailAuthenticator, dataSource, htmlEmail]
2018-01-26 16:02:52,408 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 21 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2018-01-26 16:02:52,425 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.AuthorityModule
2018-01-26 16:02:52,439 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.CaptchaModule
2018-01-26 16:02:52,441 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserModule
2018-01-26 16:02:52,448 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserProfileModule
2018-01-26 16:02:52,458 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2018-01-26 16:02:52,461 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.AuthorityServiceImpl
2018-01-26 16:02:52,461 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.EmailServiceImpl
2018-01-26 16:02:52,462 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.UserService
2018-01-26 16:02:52,467 org.nutz.ioc.loader.annotation.AnnotationIocLoader.<init>(AnnotationIocLoader.java:52) INFO  - Found 8 classes in 1 base-packages!
beans = ["cleanNonActiveUserJob", "authorityServiceImpl", "userProfileModule", "captchaModule", "authorityModule", "userModule", "emailService", "userService"]
2018-01-26 16:02:52,475 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:40) DEBUG - Loaded 5 bean define from reader --
[txREPEATABLE_READ, txSERIALIZABLE, txNONE, txREAD_UNCOMMITTED, txREAD_COMMITTED]
2018-01-26 16:02:52,478 org.nutz.ioc.loader.combo.ComboIocLoader.createIocLoader(ComboIocLoader.java:110) DEBUG - found quartz -- org.nutz.integration.quartz.QuartzIocLoader
2018-01-26 16:02:52,482 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 0 bean define from path=[] --> []
2018-01-26 16:02:52,486 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:98) INFO  - NutIoc init begin ...
2018-01-26 16:02:52,488 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:115) INFO  - ... NutIoc init complete
2018-01-26 16:02:52,491 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:159) INFO  - Build URL mapping by org.nutz.mvc.impl.UrlMappingImpl ...
2018-01-26 16:02:52,494 org.nutz.mvc.impl.NutLoading.createViewMakers(NutLoading.java:366) DEBUG - @Views(DefaultViewMaker.class)
2018-01-26 16:02:52,510 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( mvc/nutzbook-mvc-chain.js ) , regex( ^(.+[.])(js|json)$ )
2018-01-26 16:02:52,515 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"
   }
}
2018-01-26 16:02:52,515 org.nutz.mvc.impl.NutLoading.createChainMaker(NutLoading.java:263) DEBUG - @ChainBy(org.nutz.mvc.impl.NutActionChainMaker)
2018-01-26 16:02:52,533 org.nutz.mvc.impl.Loadings.scanModules(Loadings.java:154) DEBUG - module class location 'file:/D:/workspace/.metadata/.plugins/org.eclipse.wst.server.core/tmp1/wtpwebapps/demo/WEB-INF/classes/'
2018-01-26 16:02:52,533 org.nutz.mvc.impl.Loadings.scanModuleInPackage(Loadings.java:184) DEBUG -  > scan 'net.wendal.nutzbook'
2018-01-26 16:02:52,544 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 21 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2018-01-26 16:02:52,545 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.AuthorityModule'
2018-01-26 16:02:52,545 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.CaptchaModule'
2018-01-26 16:02:52,545 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserModule'
2018-01-26 16:02:52,545 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserProfileModule'
2018-01-26 16:02:52,634 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/captcha/next'             >> (CaptchaModule.java:23).next          : BufferedImage | @Ok(raw:png) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,645 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/'                    >> (UserModule.java:122).index           : void       | @Ok(jsp:jsp.user.list) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,742 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/add'                 >> (UserModule.java:77).add              : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,745 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/count'               >> (UserModule.java:44).count            : int        | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,750 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/update'              >> (UserModule.java:89).update           : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,752 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/delete'              >> (UserModule.java:99).delete           : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,768 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/query'               >> (UserModule.java:110).query           : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,769 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/error'               >> (UserModule.java:158).error           : void       | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,773 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/login'               >> (UserModule.java:166).loginPage       : void       | @Ok(jsp:jsp.user.login) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,776 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/login'               >> (UserModule.java:53).login            : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,778 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/logout'              >> (UserModule.java:71).logout           : void       | @Ok(>>:/ ) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,785 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/user/update' >> (AuthorityModule.java:37).updateUser  : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,789 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/'            >> (UserProfileModule.java:139).index    : UserProfile | @Ok(jsp:jsp.user.profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,790 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/get'         >> (UserProfileModule.java:85).get       : UserProfile | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,792 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/update'      >> (UserProfileModule.java:100).update   : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,793 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:173).activeMailCallback : String     | @Ok(raw  ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,812 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:23) INFO  - Init file-pool by: D:/workspace/.metadata/.plugins/org.eclipse.wst.server.core/tmp1/wtpwebapps/demo/WEB-INF/tmp/user_avatar [20000]
2018-01-26 16:02:52,814 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:37) DEBUG - file-pool.home: 'D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps\demo\WEB-INF\tmp\user_avatar'
2018-01-26 16:02:52,815 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:66) INFO  - file-pool.cursor: 0
2018-01-26 16:02:52,819 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:57).uploadAvatar : void       | @Ok(>>:/user/profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,822 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:128).readAvatar : Object     | @Ok(raw:jpg) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,823 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:146).activeMail : Object     | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:02:52,824 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:217) INFO  - Found 19 module methods
2018-01-26 16:02:52,824 org.nutz.mvc.impl.NutLoading.evalLocalization(NutLoading.java:303) DEBUG - Localization: org.nutz.mvc.impl.NutMessageLoader('msg/')  dft<zh-CN>
2018-01-26 16:02:52,829 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( msg/ ) , regex( ^.+[.]properties$ )
2018-01-26 16:02:52,830 org.nutz.mvc.impl.NutMessageLoader.load(NutMessageLoader.java:27) DEBUG - Load Messages in 1 resource : [[File[D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps\demo\WEB-INF\classes\msg\zh-CN\user.properties]]]
2018-01-26 16:02:52,831 org.nutz.mvc.impl.NutMessageLoader.load(NutMessageLoader.java:95) DEBUG - Message Loaded, size = 2
2018-01-26 16:02:52,836 org.nutz.mvc.impl.NutLoading.createSessionProvider(NutLoading.java:410) INFO  - SessionBy --> org.nutz.integration.shiro.ShiroSessionProvider@52b3da5f
2018-01-26 16:02:52,836 org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:271) INFO  - Setup application...
2018-01-26 16:02:52,840 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2018-01-26 16:02:52,842 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
2018-01-26 16:02:52,843 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dao
2018-01-26 16:02:52,844 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dao
2018-01-26 16:02:52,847 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dao) in JsonLoader(paths=[ioc/])
2018-01-26 16:02:52,847 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dao'<interface org.nutz.dao.Dao>
2018-01-26 16:02:52,858 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.dao.impl.NutDao without AOP
2018-01-26 16:02:52,860 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dao' to [app] 
2018-01-26 16:02:52,869 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2018-01-26 16:02:52,869 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dataSource
2018-01-26 16:02:52,869 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dataSource
2018-01-26 16:02:52,881 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dataSource) in JsonLoader(paths=[ioc/])
2018-01-26 16:02:52,881 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dataSource'<>
2018-01-26 16:02:52,903 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class com.alibaba.druid.pool.DruidDataSource without AOP
2018-01-26 16:02:52,903 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dataSource' to [app] 
2018-01-26 16:02:52,906 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2018-01-26 16:02:52,906 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=conf
2018-01-26 16:02:52,906 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=conf
2018-01-26 16:02:52,929 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(conf) in JsonLoader(paths=[ioc/])
2018-01-26 16:02:52,929 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'conf'<>
2018-01-26 16:02:52,930 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.ioc.impl.PropertiesProxy without AOP
2018-01-26 16:02:52,930 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'conf' to [app] 
2018-01-26 16:02:52,992 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 3 resource by src( custom/ ) , regex( ^.+[.]properties$ )
2018-01-26 16:02:52,992 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps\demo\WEB-INF\classes\custom\cron.properties]
2018-01-26 16:02:52,994 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps\demo\WEB-INF\classes\custom\db.properties]
2018-01-26 16:02:52,994 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps\demo\WEB-INF\classes\custom\mail.properties]
2018-01-26 16:02:53,461 com.alibaba.druid.pool.DruidDataSource.init(DruidDataSource.java:715) INFO  - {dataSource-1} inited
2018-01-26 16:02:53,462 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2018-01-26 16:02:53,713 org.nutz.dao.jdbc.Jdbcs.<clinit>(Jdbcs.java:90) DEBUG - Jdbcs init complete
2018-01-26 16:02:53,713 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
2018-01-26 16:02:54,064 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:188) DEBUG - select expert : org.nutz.dao.impl.jdbc.oracle.OracleJdbcExpert
2018-01-26 16:02:54,069 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:199) DEBUG - JDBC Driver --> 11.2.0.4.0
2018-01-26 16:02:54,069 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:200) DEBUG - JDBC Name   --> Oracle JDBC driver
2018-01-26 16:02:54,069 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:202) DEBUG - JDBC URL    --> jdbc:oracle:thin:@127.0.0.1:1521/NUTZBOOK
2018-01-26 16:02:54,069 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:221) DEBUG - Database info --> ORACLE:[Oracle - Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options]
2018-01-26 16:02:54,076 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 21 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2018-01-26 16:02:54,187 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT COUNT(*) FROM atf_user 
2018-01-26 16:02:54,193 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'nutQuartzCronJobFactory'<class org.nutz.integration.quartz.NutQuartzCronJobFactory>
2018-01-26 16:02:54,193 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=nutQuartzCronJobFactory
2018-01-26 16:02:54,193 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=nutQuartzCronJobFactory
2018-01-26 16:02:54,193 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(nutQuartzCronJobFactory) in QuartzIocLoader@1141410362
2018-01-26 16:02:54,193 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'nutQuartzCronJobFactory'<class org.nutz.integration.quartz.NutQuartzCronJobFactory>
2018-01-26 16:02:54,194 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.integration.quartz.NutQuartzCronJobFactory without AOP
2018-01-26 16:02:54,194 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'nutQuartzCronJobFactory' to [app] 
2018-01-26 16:02:54,199 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'scheduler'<>
2018-01-26 16:02:54,199 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=scheduler
2018-01-26 16:02:54,199 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=scheduler
2018-01-26 16:02:54,200 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(scheduler) in QuartzIocLoader@1141410362
2018-01-26 16:02:54,200 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'scheduler'<>
2018-01-26 16:02:54,200 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'scheduler' to [app] 
2018-01-26 16:02:54,249 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1172) INFO  - Using default implementation for ThreadExecutor
2018-01-26 16:02:54,266 org.quartz.core.SchedulerSignalerImpl.<init>(SchedulerSignalerImpl.java:61) INFO  - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2018-01-26 16:02:54,266 org.quartz.core.QuartzScheduler.<init>(QuartzScheduler.java:240) INFO  - Quartz Scheduler v.2.2.3 created.
2018-01-26 16:02:54,267 org.quartz.simpl.RAMJobStore.initialize(RAMJobStore.java:155) INFO  - RAMJobStore initialized.
2018-01-26 16:02:54,267 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.

2018-01-26 16:02:54,267 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1327) INFO  - Quartz scheduler 'NutzbookScheduler' initialized from default resource file in Quartz package: 'quartz.properties'
2018-01-26 16:02:54,267 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1331) INFO  - Quartz scheduler version: 2.2.3
2018-01-26 16:02:54,268 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'jobFactory'<>
2018-01-26 16:02:54,268 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=jobFactory
2018-01-26 16:02:54,268 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=jobFactory
2018-01-26 16:02:54,268 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(jobFactory) in QuartzIocLoader@1141410362
2018-01-26 16:02:54,268 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'jobFactory'<>
2018-01-26 16:02:54,269 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.integration.quartz.NutQuartzJobFactory without AOP
2018-01-26 16:02:54,269 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'jobFactory' to [app] 
2018-01-26 16:02:54,324 org.quartz.core.QuartzScheduler.setJobFactory(QuartzScheduler.java:2311) INFO  - JobFactory set to: org.nutz.integration.quartz.NutQuartzJobFactory@44907b38
2018-01-26 16:02:54,325 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2018-01-26 16:02:54,326 org.quartz.core.QuartzScheduler.start(QuartzScheduler.java:575) INFO  - Scheduler NutzbookScheduler_$_NON_CLUSTERED started.
2018-01-26 16:02:54,327 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2018-01-26 16:02:54,327 org.nutz.integration.quartz.NutQuartzCronJobFactory.init(NutQuartzCronJobFactory.java:35) DEBUG - job define name=net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob cron=0 0/2 * * * ?
2018-01-26 16:02:54,339 org.nutz.integration.quartz.NutQuartzCronJobFactory.init(NutQuartzCronJobFactory.java:28) DEBUG - found cron job packages = net.wendal.nutzbook.quartz.job
2018-01-26 16:02:54,340 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( net/wendal/nutzbook/quartz/job/ ) , regex( ^.+[.]class$ )
2018-01-26 16:02:54,340 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'authorityService'<interface net.wendal.nutzbook.service.AuthorityService>
2018-01-26 16:02:54,341 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=authorityService
2018-01-26 16:02:54,342 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:125) ERROR - Error happend during start serivce!
org.nutz.ioc.IocException: IocBean[authorityService] For object [authorityService] - type:[interface net.wendal.nutzbook.service.AuthorityService]
	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:44)
	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:4689)
	at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5329)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1407)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1397)
	at java.util.concurrent.FutureTask.run(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)
Caused by: org.nutz.ioc.ObjectLoadException: Object 'authorityService' without define!
	at org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:166)
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:180)
	... 20 more
2018-01-26 16:02:54,347 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:127) ERROR - try to depose ioc
2018-01-26 16:02:54,344 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2018-01-26 16:02:54,350 org.nutz.ioc.impl.NutIoc.depose(NutIoc.java:255) INFO  - org.nutz.ioc.impl.NutIoc@2029341009 is closing. startup date [18-01-26 16:02:52.486]
2018-01-26 16:02:54,350 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'jobFactory' ...
2018-01-26 16:02:54,350 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'scheduler' ...
2018-01-26 16:02:54,350 org.quartz.core.QuartzScheduler.shutdown(QuartzScheduler.java:694) INFO  - Scheduler NutzbookScheduler_$_NON_CLUSTERED shutting down.
2018-01-26 16:02:54,350 org.quartz.core.QuartzScheduler.standby(QuartzScheduler.java:613) INFO  - Scheduler NutzbookScheduler_$_NON_CLUSTERED paused.
2018-01-26 16:02:54,351 org.quartz.simpl.SimpleThreadPool.shutdown(SimpleThreadPool.java:328) DEBUG - Shutting down threadpool...
2018-01-26 16:02:54,351 org.quartz.simpl.SimpleThreadPool.shutdown(SimpleThreadPool.java:395) DEBUG - Shutdown of threadpool complete.
2018-01-26 16:02:54,351 org.quartz.core.QuartzScheduler.shutdown(QuartzScheduler.java:771) INFO  - Scheduler NutzbookScheduler_$_NON_CLUSTERED shutdown complete.
2018-01-26 16:02:54,351 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'nutQuartzCronJobFactory' ...
2018-01-26 16:02:54,351 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'conf' ...
2018-01-26 16:02:54,351 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'dao' ...
2018-01-26 16:02:54,351 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:113) DEBUG - Depose object 'dataSource' ...
2018-01-26 16:02:54,361 com.alibaba.druid.pool.DruidDataSource.close(DruidDataSource.java:1444) INFO  - {dataSource-1} closed
2018-01-26 16:02:54,362 org.nutz.ioc.impl.NutIoc.depose(NutIoc.java:262) INFO  - org.nutz.ioc.impl.NutIoc@2029341009 is deposed. startup date [18-01-26 16:02:52.486]
一月 26, 2018 4:02:54 下午 org.apache.catalina.core.StandardContext filterStart
严重: Exception starting filter nutz
org.nutz.mvc.LoadingException: org.nutz.ioc.IocException: IocBean[authorityService] For object [authorityService] - type:[interface net.wendal.nutzbook.service.AuthorityService]
	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:4689)
	at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5329)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1407)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1397)
	at java.util.concurrent.FutureTask.run(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)
Caused by: org.nutz.ioc.IocException: IocBean[authorityService] For object [authorityService] - type:[interface net.wendal.nutzbook.service.AuthorityService]
	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:44)
	at org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:274)
	at org.nutz.mvc.impl.NutLoading.load(NutLoading.java:121)
	... 15 more
Caused by: org.nutz.ioc.ObjectLoadException: Object 'authorityService' without define!
	at org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:166)
	at org.nutz.ioc.impl.NutIoc.get(NutIoc.java:180)
	... 20 more

一月 26, 2018 4:02:54 下午 org.apache.catalina.core.StandardContext startInternal
严重: One or more Filters failed to start. Full details will be found in the appropriate container log file
一月 26, 2018 4:02:54 下午 org.apache.catalina.core.StandardContext startInternal
严重: Context [/demo] startup failed due to previous errors
一月 26, 2018 4:02:54 下午 org.apache.catalina.core.ApplicationContext log
信息: Cleaning up Shiro Environment
一月 26, 2018 4:02:54 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesJdbc
警告: The web application [demo] 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.
一月 26, 2018 4:02:54 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesJdbc
警告: The web application [demo] registered the JDBC driver [oracle.jdbc.OracleDriver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
一月 26, 2018 4:02:54 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
警告: The web application [demo] appears to have started a thread named [Druid-ConnectionPool-Create-907707082] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 sun.misc.Unsafe.park(Native Method)
 java.util.concurrent.locks.LockSupport.park(Unknown Source)
 java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(Unknown Source)
 java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(Unknown Source)
 java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Unknown Source)
 com.alibaba.druid.pool.DruidDataSource$CreateConnectionThread.run(DruidDataSource.java:1977)
一月 26, 2018 4:02:54 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
警告: The web application [demo] appears to have started a thread named [Druid-ConnectionPool-Destroy-907707082] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 java.lang.Thread.sleep(Native Method)
 com.alibaba.druid.pool.DruidDataSource$DestroyConnectionThread.run(DruidDataSource.java:2070)
一月 26, 2018 4:02:54 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
警告: The web application [demo] appears to have started a thread named [NutzbookScheduler_Worker-1] 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)
 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
一月 26, 2018 4:02:54 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
警告: The web application [demo] appears to have started a thread named [NutzbookScheduler_Worker-2] 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)
 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
一月 26, 2018 4:02:54 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
警告: The web application [demo] appears to have started a thread named [NutzbookScheduler_Worker-3] 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)
 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
一月 26, 2018 4:02:54 下午 org.apache.coyote.AbstractProtocol start
信息: Starting ProtocolHandler ["http-nio-8080"]
一月 26, 2018 4:02:54 下午 org.apache.coyote.AbstractProtocol start
信息: Starting ProtocolHandler ["ajp-nio-8009"]
一月 26, 2018 4:02:54 下午 org.apache.catalina.startup.Catalina start
信息: Server startup in 7760 ms
2018-01-26 16:02:54,753 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:612) DEBUG - WorkerThread is shut down.
2018-01-26 16:02:54,754 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:612) DEBUG - WorkerThread is shut down.
2018-01-26 16:02:54,826 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:612) DEBUG - WorkerThread is shut down.

刚才没加name，加上之后错误变了
@管理员(admin)

一月 26, 2018 4:05:52 下午 org.apache.tomcat.util.digester.SetPropertiesRule begin
警告: [SetPropertiesRule]{Server/Service/Engine/Host/Context} Setting property 'source' to 'org.eclipse.jst.jee.server:demo' did not find a matching property.
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server version:        Apache Tomcat/8.0.36
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server built:          Jun 9 2016 13:55:50 UTC
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server number:         8.0.36.0
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: OS Name:               Windows 7
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: OS Version:            6.1
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Architecture:          amd64
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Java Home:             C:\Program Files\Java\jre1.8.0_151
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: JVM Version:           1.8.0_151-b12
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: JVM Vendor:            Oracle Corporation
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: CATALINA_BASE:         D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: CATALINA_HOME:         D:\soft
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -agentlib:jdwp=transport=dt_socket,suspend=y,address=localhost:54553
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dcatalina.base=D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dcatalina.home=D:\soft
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dwtp.deploy=D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Djava.endorsed.dirs=D:\soft\endorsed
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dfile.encoding=UTF-8
一月 26, 2018 4:05:52 下午 org.apache.catalina.core.AprLifecycleListener lifecycleEvent
信息: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: C:\Program Files\Java\jre1.8.0_151\bin;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;C:/Program Files/Java/jre1.8.0_151/bin/server;C:/Program Files/Java/jre1.8.0_151/bin;C:/Program Files/Java/jre1.8.0_151/lib/amd64;C:\ProgramData\Oracle\Java\javapath;E:\orcl\product\11.2.0\dbhome_1\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\java\jdk1.8.0_151\bin;C:\java\jdk1.8.0_151\jre\bin;C:\Program Files\TortoiseSVN\bin;D:\soft\apache-maven-3.5.2-bin\apache-maven-3.5.2\bin;C:\Users\Administrator\Downloads\mysql-5.7.20-winx64\mysql-5.7.20-winx64\bin;D:\software\tortoiseGit\bin;C:\Users\Administrator\Desktop;;.
一月 26, 2018 4:05:52 下午 org.apache.coyote.AbstractProtocol init
信息: Initializing ProtocolHandler ["http-nio-8080"]
一月 26, 2018 4:05:52 下午 org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
信息: Using a shared selector for servlet write/read
一月 26, 2018 4:05:52 下午 org.apache.coyote.AbstractProtocol init
信息: Initializing ProtocolHandler ["ajp-nio-8009"]
一月 26, 2018 4:05:52 下午 org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
信息: Using a shared selector for servlet write/read
一月 26, 2018 4:05:52 下午 org.apache.catalina.startup.Catalina load
信息: Initialization processed in 861 ms
一月 26, 2018 4:05:52 下午 org.apache.catalina.core.StandardService startInternal
信息: Starting service Catalina
一月 26, 2018 4:05:52 下午 org.apache.catalina.core.StandardEngine startInternal
信息: Starting Servlet Engine: Apache Tomcat/8.0.36
一月 26, 2018 4:05:55 下午 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.
一月 26, 2018 4:05:57 下午 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.
一月 26, 2018 4:05:57 下午 org.apache.catalina.core.ApplicationContext log
信息: Initializing Shiro environment
2018-01-26 16:05:57,897 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:128) INFO  - Starting Shiro environment initialization.
2018-01-26 16:05:57,912 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:76) DEBUG - Checking any specified config locations.
2018-01-26 16:05:57,927 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:81) DEBUG - No INI instance or config locations specified.  Trying default config locations.
2018-01-26 16:05:57,930 org.apache.shiro.io.ResourceUtils.loadFromClassPath(ResourceUtils.java:159) DEBUG - Opening resource from class path [shiro.ini]
2018-01-26 16:05:57,935 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [main]
2018-01-26 16:05:57,937 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [urls]
2018-01-26 16:05:57,940 org.apache.shiro.web.env.IniWebEnvironment.getDefaultIni(IniWebEnvironment.java:136) DEBUG - Discovered non-empty INI configuration at location 'classpath:shiro.ini'.  Using for configuration.
2018-01-26 16:05:57,943 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=main,urls]
2018-01-26 16:05:58,177 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:234) DEBUG - No authorizationCache instance set.  Checking for a cacheManager...
2018-01-26 16:05:58,177 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:248) DEBUG - No cache or cacheManager properties have been set.  Authorization cache cannot be obtained.
2018-01-26 16:05:58,178 org.apache.shiro.config.ReflectionBuilder.createNewInstance(ReflectionBuilder.java:296) INFO  - An instance with name 'authc' already exists.  Redefining this object as a new instance of type org.nutz.integration.shiro.SimpleAuthenticationFilter
2018-01-26 16:05:58,204 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: false
2018-01-26 16:05:58,204 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Boolean' value 'false' to type 'Boolean'
2018-01-26 16:05:58,204 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Boolean
2018-01-26 16:05:58,206 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:05:58,206 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Byte'
2018-01-26 16:05:58,207 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Byte value '0'
2018-01-26 16:05:58,208 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value:  
2018-01-26 16:05:58,208 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Character' value ' ' to type 'Character'
2018-01-26 16:05:58,208 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Character
2018-01-26 16:05:58,209 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:05:58,209 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Double'
2018-01-26 16:05:58,209 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Double value '0.0'
2018-01-26 16:05:58,209 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:05:58,210 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Float'
2018-01-26 16:05:58,210 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Float value '0.0'
2018-01-26 16:05:58,210 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:05:58,210 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Integer'
2018-01-26 16:05:58,211 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Integer
2018-01-26 16:05:58,211 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:05:58,211 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Long'
2018-01-26 16:05:58,211 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Long value '0'
2018-01-26 16:05:58,212 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:05:58,212 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Short'
2018-01-26 16:05:58,212 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Short value '0'
2018-01-26 16:05:58,214 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0.0
2018-01-26 16:05:58,214 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigDecimal' value '0.0' to type 'BigDecimal'
2018-01-26 16:05:58,214 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigDecimal
2018-01-26 16:05:58,215 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:05:58,215 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigInteger' value '0' to type 'BigInteger'
2018-01-26 16:05:58,215 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigInteger
2018-01-26 16:05:58,215 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: false
2018-01-26 16:05:58,215 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Boolean' value 'false' to type 'Boolean'
2018-01-26 16:05:58,215 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Boolean
2018-01-26 16:05:58,215 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:05:58,216 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Byte'
2018-01-26 16:05:58,216 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Byte value '0'
2018-01-26 16:05:58,216 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value:  
2018-01-26 16:05:58,216 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Character' value ' ' to type 'Character'
2018-01-26 16:05:58,216 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Character
2018-01-26 16:05:58,216 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:05:58,216 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Double'
2018-01-26 16:05:58,216 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Double value '0.0'
2018-01-26 16:05:58,216 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:05:58,217 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Float'
2018-01-26 16:05:58,217 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Float value '0.0'
2018-01-26 16:05:58,217 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:05:58,217 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Integer'
2018-01-26 16:05:58,217 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Integer
2018-01-26 16:05:58,217 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:05:58,217 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Long'
2018-01-26 16:05:58,218 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Long value '0'
2018-01-26 16:05:58,218 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:05:58,218 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Short'
2018-01-26 16:05:58,218 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Short value '0'
2018-01-26 16:05:58,219 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 
2018-01-26 16:05:58,219 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value '' to type 'String'
2018-01-26 16:05:58,225 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Z@7ffc39a9
2018-01-26 16:05:58,226 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'boolean[]' value '[Z@7ffc39a9' to type 'boolean[]'
2018-01-26 16:05:58,226 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a boolean[]
2018-01-26 16:05:58,226 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [B@125f188b
2018-01-26 16:05:58,226 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'byte[]' value '[B@125f188b' to type 'byte[]'
2018-01-26 16:05:58,226 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a byte[]
2018-01-26 16:05:58,226 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [C@4a53bbc3
2018-01-26 16:05:58,226 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'char[]' value '[C@4a53bbc3' to type 'char[]'
2018-01-26 16:05:58,226 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a char[]
2018-01-26 16:05:58,227 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [D@1ea523b9
2018-01-26 16:05:58,227 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'double[]' value '[D@1ea523b9' to type 'double[]'
2018-01-26 16:05:58,227 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a double[]
2018-01-26 16:05:58,227 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [F@a70b5
2018-01-26 16:05:58,227 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'float[]' value '[F@a70b5' to type 'float[]'
2018-01-26 16:05:58,227 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a float[]
2018-01-26 16:05:58,227 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [I@6afbab7f
2018-01-26 16:05:58,227 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'int[]' value '[I@6afbab7f' to type 'int[]'
2018-01-26 16:05:58,228 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a int[]
2018-01-26 16:05:58,228 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [J@3da18840
2018-01-26 16:05:58,228 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'long[]' value '[J@3da18840' to type 'long[]'
2018-01-26 16:05:58,228 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a long[]
2018-01-26 16:05:58,228 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [S@aaecca6
2018-01-26 16:05:58,228 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'short[]' value '[S@aaecca6' to type 'short[]'
2018-01-26 16:05:58,228 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a short[]
2018-01-26 16:05:58,228 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.math.BigDecimal;@59729a9e
2018-01-26 16:05:58,228 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigDecimal[]' value '[Ljava.math.BigDecimal;@59729a9e' to type 'BigDecimal[]'
2018-01-26 16:05:58,229 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigDecimal[]
2018-01-26 16:05:58,229 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.math.BigInteger;@5f371498
2018-01-26 16:05:58,229 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigInteger[]' value '[Ljava.math.BigInteger;@5f371498' to type 'BigInteger[]'
2018-01-26 16:05:58,229 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigInteger[]
2018-01-26 16:05:58,229 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Boolean;@23802824
2018-01-26 16:05:58,229 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Boolean[]' value '[Ljava.lang.Boolean;@23802824' to type 'Boolean[]'
2018-01-26 16:05:58,229 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Boolean[]
2018-01-26 16:05:58,229 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Byte;@6eebe0a0
2018-01-26 16:05:58,229 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Byte[]' value '[Ljava.lang.Byte;@6eebe0a0' to type 'Byte[]'
2018-01-26 16:05:58,230 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Byte[]
2018-01-26 16:05:58,230 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Character;@2b5f0e63
2018-01-26 16:05:58,230 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Character[]' value '[Ljava.lang.Character;@2b5f0e63' to type 'Character[]'
2018-01-26 16:05:58,230 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Character[]
2018-01-26 16:05:58,230 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Double;@4c2b4c44
2018-01-26 16:05:58,230 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Double[]' value '[Ljava.lang.Double;@4c2b4c44' to type 'Double[]'
2018-01-26 16:05:58,230 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Double[]
2018-01-26 16:05:58,231 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Float;@5f978f74
2018-01-26 16:05:58,231 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Float[]' value '[Ljava.lang.Float;@5f978f74' to type 'Float[]'
2018-01-26 16:05:58,231 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Float[]
2018-01-26 16:05:58,231 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Integer;@1ab78a56
2018-01-26 16:05:58,231 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer[]' value '[Ljava.lang.Integer;@1ab78a56' to type 'Integer[]'
2018-01-26 16:05:58,231 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Integer[]
2018-01-26 16:05:58,231 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Long;@30325219
2018-01-26 16:05:58,231 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Long[]' value '[Ljava.lang.Long;@30325219' to type 'Long[]'
2018-01-26 16:05:58,231 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Long[]
2018-01-26 16:05:58,231 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Short;@533d8744
2018-01-26 16:05:58,231 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Short[]' value '[Ljava.lang.Short;@533d8744' to type 'Short[]'
2018-01-26 16:05:58,232 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Short[]
2018-01-26 16:05:58,232 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.String;@1a6b34f6
2018-01-26 16:05:58,232 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String[]' value '[Ljava.lang.String;@1a6b34f6' to type 'String[]'
2018-01-26 16:05:58,233 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a String[]
2018-01-26 16:05:58,233 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Class;@3c28f8d7
2018-01-26 16:05:58,233 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Class[]' value '[Ljava.lang.Class;@3c28f8d7' to type 'Class[]'
2018-01-26 16:05:58,233 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Class[]
2018-01-26 16:05:58,233 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.util.Date;@1ea8c7d1
2018-01-26 16:05:58,233 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Date[]' value '[Ljava.util.Date;@1ea8c7d1' to type 'Date[]'
2018-01-26 16:05:58,233 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Date[]
2018-01-26 16:05:58,233 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.util.Calendar;@621f38b7
2018-01-26 16:05:58,233 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Calendar[]' value '[Ljava.util.Calendar;@621f38b7' to type 'Calendar[]'
2018-01-26 16:05:58,233 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Calendar[]
2018-01-26 16:05:58,234 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.io.File;@414440cc
2018-01-26 16:05:58,234 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.io.File[]' value '[Ljava.io.File;@414440cc' to type 'java.io.File[]'
2018-01-26 16:05:58,234 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.io.File[]
2018-01-26 16:05:58,234 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.sql.Date;@6351235f
2018-01-26 16:05:58,234 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.sql.Date[]' value '[Ljava.sql.Date;@6351235f' to type 'java.sql.Date[]'
2018-01-26 16:05:58,234 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.sql.Date[]
2018-01-26 16:05:58,234 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.sql.Time;@3504b1e1
2018-01-26 16:05:58,234 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.sql.Time[]' value '[Ljava.sql.Time;@3504b1e1' to type 'java.sql.Time[]'
2018-01-26 16:05:58,234 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.sql.Time[]
2018-01-26 16:05:58,235 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.sql.Timestamp;@3c844fed
2018-01-26 16:05:58,235 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.sql.Timestamp[]' value '[Ljava.sql.Timestamp;@3c844fed' to type 'java.sql.Timestamp[]'
2018-01-26 16:05:58,235 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.sql.Timestamp[]
2018-01-26 16:05:58,235 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.net.URL;@575cafaa
2018-01-26 16:05:58,235 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.net.URL[]' value '[Ljava.net.URL;@575cafaa' to type 'java.net.URL[]'
2018-01-26 16:05:58,235 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.net.URL[]
2018-01-26 16:05:58,261 org.apache.commons.beanutils.ConvertUtilsBean.convert(ConvertUtilsBean.java:481) DEBUG - Convert string '/user/login' to class 'java.lang.String'
2018-01-26 16:05:58,262 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value '/user/login' to type 'String'
2018-01-26 16:05:58,266 org.apache.commons.beanutils.ConvertUtilsBean.convert(ConvertUtilsBean.java:481) DEBUG - Convert string '/user/login' to class 'java.lang.String'
2018-01-26 16:05:58,267 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value '/user/login' to type 'String'
2018-01-26 16:05:58,267 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:234) DEBUG - No authorizationCache instance set.  Checking for a cacheManager...
2018-01-26 16:05:58,267 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:248) DEBUG - No cache or cacheManager properties have been set.  Authorization cache cannot be obtained.
2018-01-26 16:05:58,270 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=main,urls]
2018-01-26 16:05:58,273 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/rs/*] from String definition [anon]
2018-01-26 16:05:58,274 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/rs/*] to filter [anon] with config [null]
2018-01-26 16:05:58,275 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/logout] from String definition [logout]
2018-01-26 16:05:58,275 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/logout] to filter [logout] with config [null]
2018-01-26 16:05:58,275 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/error] from String definition [anon]
2018-01-26 16:05:58,275 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/error] to filter [anon] with config [null]
2018-01-26 16:05:58,275 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/login] from String definition [anon]
2018-01-26 16:05:58,275 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/login] to filter [anon] with config [null]
2018-01-26 16:05:58,276 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/profile/active/mail] from String definition [anon]
2018-01-26 16:05:58,276 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/profile/active/mail] to filter [anon] with config [null]
2018-01-26 16:05:58,276 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]
2018-01-26 16:05:58,276 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:141) INFO  - Shiro environment initialized in 376 ms.
2018-01-26 16:05:58,318 org.nutz.mvc.NutFilter._init(NutFilter.java:85) INFO  - NutFilter[nutz] starting ...
2018-01-26 16:05:58,348 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=10 time use 21ms
2018-01-26 16:05:58,360 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=30 time use 11ms
2018-01-26 16:05:58,472 org.nutz.castor.Castors.reload(Castors.java:115) DEBUG - Using 95 castor for Castors
2018-01-26 16:05:58,493 org.nutz.mvc.config.AbstractNutConfig.createLoading(AbstractNutConfig.java:59) DEBUG - Loading by class org.nutz.mvc.impl.NutLoading
2018-01-26 16:05:58,495 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:55) INFO  - Nutz Version : 1.r.62 
2018-01-26 16:05:58,495 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:56) INFO  - Nutz.Mvc[nutz] is initializing ...
2018-01-26 16:05:58,495 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:60) DEBUG - Web Container Information:
2018-01-26 16:05:58,496 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:61) DEBUG -  - Default Charset : UTF-8
2018-01-26 16:05:58,496 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:62) DEBUG -  - Current . path  : C:\Users\Administrator\Desktop\.
2018-01-26 16:05:58,497 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:63) DEBUG -  - Java Version    : 1.8.0_151
2018-01-26 16:05:58,497 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:64) DEBUG -  - File separator  : \
2018-01-26 16:05:58,497 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:65) DEBUG -  - Timezone        : Asia/Shanghai
2018-01-26 16:05:58,497 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:66) DEBUG -  - OS              : Windows 7 amd64
2018-01-26 16:05:58,497 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:67) DEBUG -  - ServerInfo      : Apache Tomcat/8.0.36
2018-01-26 16:05:58,498 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:68) DEBUG -  - Servlet API     : 3.1
2018-01-26 16:05:58,498 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:73) DEBUG -  - ContextPath     : /demo
2018-01-26 16:05:58,498 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:74) DEBUG -  - context.tempdir : D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\work\Catalina\localhost\demo
2018-01-26 16:05:58,498 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:75) DEBUG -  - MainModule      : net.wendal.nutzbook.MainModule
2018-01-26 16:05:58,499 org.nutz.mvc.impl.NutLoading.createContext(NutLoading.java:235) DEBUG - >> app.root = D:/workspace/.metadata/.plugins/org.eclipse.wst.server.core/tmp1/wtpwebapps/demo
2018-01-26 16:05:58,504 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=[])
2018-01-26 16:05:58,563 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 2 resource by src( ioc/ ) , regex( ^(.+[.])(js|json)$ )
2018-01-26 16:05:58,563 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [dao.js]
2018-01-26 16:05:58,568 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [mail.js]
2018-01-26 16:05:58,568 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 5 bean define from path=[ioc/] --> [conf, dao, emailAuthenticator, dataSource, htmlEmail]
2018-01-26 16:05:58,581 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 21 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2018-01-26 16:05:58,598 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.AuthorityModule
2018-01-26 16:05:58,611 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.CaptchaModule
2018-01-26 16:05:58,613 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserModule
2018-01-26 16:05:58,621 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserProfileModule
2018-01-26 16:05:58,625 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2018-01-26 16:05:58,628 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.AuthorityServiceImpl
2018-01-26 16:05:58,628 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.EmailServiceImpl
2018-01-26 16:05:58,629 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.UserService
2018-01-26 16:05:58,634 org.nutz.ioc.loader.annotation.AnnotationIocLoader.<init>(AnnotationIocLoader.java:52) INFO  - Found 8 classes in 1 base-packages!
beans = ["cleanNonActiveUserJob", "authorityService", "userProfileModule", "captchaModule", "authorityModule", "userModule", "emailService", "userService"]
2018-01-26 16:05:58,659 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:40) DEBUG - Loaded 5 bean define from reader --
[txREPEATABLE_READ, txSERIALIZABLE, txNONE, txREAD_UNCOMMITTED, txREAD_COMMITTED]
2018-01-26 16:05:58,665 org.nutz.ioc.loader.combo.ComboIocLoader.createIocLoader(ComboIocLoader.java:110) DEBUG - found quartz -- org.nutz.integration.quartz.QuartzIocLoader
2018-01-26 16:05:58,669 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 0 bean define from path=[] --> []
2018-01-26 16:05:58,673 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:98) INFO  - NutIoc init begin ...
2018-01-26 16:05:58,675 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:115) INFO  - ... NutIoc init complete
2018-01-26 16:05:58,678 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:159) INFO  - Build URL mapping by org.nutz.mvc.impl.UrlMappingImpl ...
2018-01-26 16:05:58,680 org.nutz.mvc.impl.NutLoading.createViewMakers(NutLoading.java:366) DEBUG - @Views(DefaultViewMaker.class)
2018-01-26 16:05:58,692 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( mvc/nutzbook-mvc-chain.js ) , regex( ^(.+[.])(js|json)$ )
2018-01-26 16:05:58,702 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"
   }
}
2018-01-26 16:05:58,702 org.nutz.mvc.impl.NutLoading.createChainMaker(NutLoading.java:263) DEBUG - @ChainBy(org.nutz.mvc.impl.NutActionChainMaker)
2018-01-26 16:05:58,706 org.nutz.mvc.impl.Loadings.scanModules(Loadings.java:154) DEBUG - module class location 'file:/D:/workspace/.metadata/.plugins/org.eclipse.wst.server.core/tmp1/wtpwebapps/demo/WEB-INF/classes/'
2018-01-26 16:05:58,706 org.nutz.mvc.impl.Loadings.scanModuleInPackage(Loadings.java:184) DEBUG -  > scan 'net.wendal.nutzbook'
2018-01-26 16:05:58,712 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 21 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2018-01-26 16:05:58,715 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.AuthorityModule'
2018-01-26 16:05:58,715 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.CaptchaModule'
2018-01-26 16:05:58,716 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserModule'
2018-01-26 16:05:58,716 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserProfileModule'
2018-01-26 16:05:58,787 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/'                    >> (UserModule.java:122).index           : void       | @Ok(jsp:jsp.user.list) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:58,992 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/add'                 >> (UserModule.java:77).add              : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:58,992 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/count'               >> (UserModule.java:44).count            : int        | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:58,996 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/update'              >> (UserModule.java:89).update           : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:58,997 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/delete'              >> (UserModule.java:99).delete           : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:59,004 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/query'               >> (UserModule.java:110).query           : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:59,006 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/error'               >> (UserModule.java:158).error           : void       | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:59,006 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/login'               >> (UserModule.java:166).loginPage       : void       | @Ok(jsp:jsp.user.login) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:59,008 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/login'               >> (UserModule.java:53).login            : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:59,009 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/logout'              >> (UserModule.java:71).logout           : void       | @Ok(>>:/ ) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:59,013 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/'            >> (UserProfileModule.java:139).index    : UserProfile | @Ok(jsp:jsp.user.profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:59,014 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/get'         >> (UserProfileModule.java:85).get       : UserProfile | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:59,026 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/update'      >> (UserProfileModule.java:100).update   : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:59,030 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:173).activeMailCallback : String     | @Ok(raw  ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:59,051 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:23) INFO  - Init file-pool by: D:/workspace/.metadata/.plugins/org.eclipse.wst.server.core/tmp1/wtpwebapps/demo/WEB-INF/tmp/user_avatar [20000]
2018-01-26 16:05:59,053 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:37) DEBUG - file-pool.home: 'D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps\demo\WEB-INF\tmp\user_avatar'
2018-01-26 16:05:59,054 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:66) INFO  - file-pool.cursor: 0
2018-01-26 16:05:59,058 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:57).uploadAvatar : void       | @Ok(>>:/user/profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:59,059 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:128).readAvatar : Object     | @Ok(raw:jpg) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:59,060 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:146).activeMail : Object     | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:59,066 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/user/update' >> (AuthorityModule.java:37).updateUser  : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:59,071 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/captcha/next'             >> (CaptchaModule.java:23).next          : BufferedImage | @Ok(raw:png) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:05:59,071 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:217) INFO  - Found 19 module methods
2018-01-26 16:05:59,071 org.nutz.mvc.impl.NutLoading.evalLocalization(NutLoading.java:303) DEBUG - Localization: org.nutz.mvc.impl.NutMessageLoader('msg/')  dft<zh-CN>
2018-01-26 16:05:59,076 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( msg/ ) , regex( ^.+[.]properties$ )
2018-01-26 16:05:59,076 org.nutz.mvc.impl.NutMessageLoader.load(NutMessageLoader.java:27) DEBUG - Load Messages in 1 resource : [[File[D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps\demo\WEB-INF\classes\msg\zh-CN\user.properties]]]
2018-01-26 16:05:59,078 org.nutz.mvc.impl.NutMessageLoader.load(NutMessageLoader.java:95) DEBUG - Message Loaded, size = 2
2018-01-26 16:05:59,084 org.nutz.mvc.impl.NutLoading.createSessionProvider(NutLoading.java:410) INFO  - SessionBy --> org.nutz.integration.shiro.ShiroSessionProvider@14a345cd
2018-01-26 16:05:59,084 org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:271) INFO  - Setup application...
2018-01-26 16:05:59,087 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2018-01-26 16:05:59,089 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
2018-01-26 16:05:59,090 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dao
2018-01-26 16:05:59,090 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dao
2018-01-26 16:05:59,093 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dao) in JsonLoader(paths=[ioc/])
2018-01-26 16:05:59,093 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dao'<interface org.nutz.dao.Dao>
2018-01-26 16:05:59,102 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.dao.impl.NutDao without AOP
2018-01-26 16:05:59,103 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dao' to [app] 
2018-01-26 16:05:59,114 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2018-01-26 16:05:59,114 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dataSource
2018-01-26 16:05:59,114 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dataSource
2018-01-26 16:05:59,128 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dataSource) in JsonLoader(paths=[ioc/])
2018-01-26 16:05:59,129 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dataSource'<>
2018-01-26 16:05:59,146 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class com.alibaba.druid.pool.DruidDataSource without AOP
2018-01-26 16:05:59,147 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dataSource' to [app] 
2018-01-26 16:05:59,149 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2018-01-26 16:05:59,149 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=conf
2018-01-26 16:05:59,149 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=conf
2018-01-26 16:05:59,186 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(conf) in JsonLoader(paths=[ioc/])
2018-01-26 16:05:59,186 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'conf'<>
2018-01-26 16:05:59,186 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.ioc.impl.PropertiesProxy without AOP
2018-01-26 16:05:59,186 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'conf' to [app] 
2018-01-26 16:05:59,268 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 3 resource by src( custom/ ) , regex( ^.+[.]properties$ )
2018-01-26 16:05:59,269 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps\demo\WEB-INF\classes\custom\cron.properties]
2018-01-26 16:05:59,269 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps\demo\WEB-INF\classes\custom\db.properties]
2018-01-26 16:05:59,270 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps\demo\WEB-INF\classes\custom\mail.properties]
2018-01-26 16:05:59,787 com.alibaba.druid.pool.DruidDataSource.init(DruidDataSource.java:715) INFO  - {dataSource-1} inited
2018-01-26 16:05:59,787 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2018-01-26 16:06:00,061 org.nutz.dao.jdbc.Jdbcs.<clinit>(Jdbcs.java:90) DEBUG - Jdbcs init complete
2018-01-26 16:06:00,061 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
2018-01-26 16:06:00,436 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:188) DEBUG - select expert : org.nutz.dao.impl.jdbc.oracle.OracleJdbcExpert
2018-01-26 16:06:00,442 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:199) DEBUG - JDBC Driver --> 11.2.0.4.0
2018-01-26 16:06:00,442 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:200) DEBUG - JDBC Name   --> Oracle JDBC driver
2018-01-26 16:06:00,442 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:202) DEBUG - JDBC URL    --> jdbc:oracle:thin:@127.0.0.1:1521/NUTZBOOK
2018-01-26 16:06:00,442 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:221) DEBUG - Database info --> ORACLE:[Oracle - Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options]
2018-01-26 16:06:00,458 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 21 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2018-01-26 16:06:00,603 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT COUNT(*) FROM atf_user 
2018-01-26 16:06:00,609 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'nutQuartzCronJobFactory'<class org.nutz.integration.quartz.NutQuartzCronJobFactory>
2018-01-26 16:06:00,609 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=nutQuartzCronJobFactory
2018-01-26 16:06:00,609 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=nutQuartzCronJobFactory
2018-01-26 16:06:00,609 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(nutQuartzCronJobFactory) in QuartzIocLoader@398955960
2018-01-26 16:06:00,609 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'nutQuartzCronJobFactory'<class org.nutz.integration.quartz.NutQuartzCronJobFactory>
2018-01-26 16:06:00,610 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.integration.quartz.NutQuartzCronJobFactory without AOP
2018-01-26 16:06:00,610 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'nutQuartzCronJobFactory' to [app] 
2018-01-26 16:06:00,617 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'scheduler'<>
2018-01-26 16:06:00,617 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=scheduler
2018-01-26 16:06:00,617 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=scheduler
2018-01-26 16:06:00,617 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(scheduler) in QuartzIocLoader@398955960
2018-01-26 16:06:00,617 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'scheduler'<>
2018-01-26 16:06:00,618 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'scheduler' to [app] 
2018-01-26 16:06:00,656 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1172) INFO  - Using default implementation for ThreadExecutor
2018-01-26 16:06:00,675 org.quartz.core.SchedulerSignalerImpl.<init>(SchedulerSignalerImpl.java:61) INFO  - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2018-01-26 16:06:00,675 org.quartz.core.QuartzScheduler.<init>(QuartzScheduler.java:240) INFO  - Quartz Scheduler v.2.2.3 created.
2018-01-26 16:06:00,683 org.quartz.simpl.RAMJobStore.initialize(RAMJobStore.java:155) INFO  - RAMJobStore initialized.
2018-01-26 16:06:00,684 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.

2018-01-26 16:06:00,684 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1327) INFO  - Quartz scheduler 'NutzbookScheduler' initialized from default resource file in Quartz package: 'quartz.properties'
2018-01-26 16:06:00,684 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1331) INFO  - Quartz scheduler version: 2.2.3
2018-01-26 16:06:00,685 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'jobFactory'<>
2018-01-26 16:06:00,685 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=jobFactory
2018-01-26 16:06:00,685 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=jobFactory
2018-01-26 16:06:00,685 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(jobFactory) in QuartzIocLoader@398955960
2018-01-26 16:06:00,686 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'jobFactory'<>
2018-01-26 16:06:00,686 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.integration.quartz.NutQuartzJobFactory without AOP
2018-01-26 16:06:00,686 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'jobFactory' to [app] 
2018-01-26 16:06:00,745 org.quartz.core.QuartzScheduler.setJobFactory(QuartzScheduler.java:2311) INFO  - JobFactory set to: org.nutz.integration.quartz.NutQuartzJobFactory@31b24c25
2018-01-26 16:06:00,746 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2018-01-26 16:06:00,746 org.quartz.core.QuartzScheduler.start(QuartzScheduler.java:575) INFO  - Scheduler NutzbookScheduler_$_NON_CLUSTERED started.
2018-01-26 16:06:00,747 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2018-01-26 16:06:00,747 org.nutz.integration.quartz.NutQuartzCronJobFactory.init(NutQuartzCronJobFactory.java:35) DEBUG - job define name=net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob cron=0 0/2 * * * ?
2018-01-26 16:06:00,760 org.nutz.integration.quartz.NutQuartzCronJobFactory.init(NutQuartzCronJobFactory.java:28) DEBUG - found cron job packages = net.wendal.nutzbook.quartz.job
2018-01-26 16:06:00,761 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( net/wendal/nutzbook/quartz/job/ ) , regex( ^.+[.]class$ )
2018-01-26 16:06:00,762 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'authorityService'<interface net.wendal.nutzbook.service.AuthorityService>
2018-01-26 16:06:00,762 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=authorityService
2018-01-26 16:06:00,762 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(authorityService) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2018-01-26 16:06:00,762 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'authorityService'<interface net.wendal.nutzbook.service.AuthorityService>
2018-01-26 16:06:00,762 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.service.AuthorityServiceImpl without AOP
2018-01-26 16:06:00,762 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'authorityService' to [app] 
2018-01-26 16:06:00,762 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 1 triggers
2018-01-26 16:06:00,766 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'cleanNonActiveUserJob'<class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob>
2018-01-26 16:06:00,768 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2018-01-26 16:06:00,769 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=cleanNonActiveUserJob
2018-01-26 16:06:00,769 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(cleanNonActiveUserJob) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2018-01-26 16:06:00,770 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'cleanNonActiveUserJob'<class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob>
2018-01-26 16:06:00,770 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob without AOP
2018-01-26 16:06:00,770 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'cleanNonActiveUserJob' to [app] 
2018-01-26 16:06:00,772 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM atf_user  WHERE name=?
    |     1 |
    |-------|
    | admin |
  For example:> "SELECT * FROM atf_user  WHERE name='admin'"
2018-01-26 16:06:00,775 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2018-01-26 16:06:00,777 org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:276) DEBUG - batch acquisition of 0 triggers
2018-01-26 16:06:00,778 org.quartz.core.JobRunShell.run(JobRunShell.java:201) DEBUG - Calling execute on job DEFAULT.net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2018-01-26 16:06:00,778 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:28) DEBUG - clean Non-Active User , start
2018-01-26 16:06:00,813 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - DELETE FROM atf_user_profile WHERE u_id>? AND ct<? AND (email_checked=? OR email IS NULL )
    |  1 |                   2 |     3 |
    |----|---------------------|-------|
    | 10 | 2018-01-25 16:06:00 | false |
  For example:> "DELETE FROM atf_user_profile WHERE u_id>10 AND ct<'2018-01-25 16:06:00' AND (email_checked=false OR email IS NULL )"
2018-01-26 16:06:00,840 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:32) DEBUG - delete 0 UserProfile
2018-01-26 16:06:00,841 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - delete from atf_user where id > 10 and not exists (select 1 from atf_user_profile where atf_user.id = uid ) and ct < ?
    |                   1 |
    |---------------------|
    | 2018-01-25 16:06:00 |
  For example:> "delete from atf_user where id > 10 and not exists (select 1 from atf_user_profile where atf_user.id = uid ) and ct < '2018-01-25 16:06:00'"
2018-01-26 16:06:00,842 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:39) DEBUG - delete 0 User
2018-01-26 16:06:00,843 net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob.execute(CleanNonActiveUserJob.java:41) DEBUG - clean Non-Active User , Done
2018-01-26 16:06:00,900 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM atf_role  WHERE name=?
    |     1 |
    |-------|
    | admin |
  For example:> "SELECT * FROM atf_role  WHERE name='admin'"
2018-01-26 16:06:01,089 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:125) ERROR - Error happend during start serivce!
java.lang.NullPointerException
	at net.wendal.nutzbook.service.AuthorityServiceImpl.checkBasicRoles(AuthorityServiceImpl.java:29)
	at net.wendal.nutzbook.MainSetup.init(MainSetup.java:46)
	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:4689)
	at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5329)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1407)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1397)
	at java.util.concurrent.FutureTask.run(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)
2018-01-26 16:06:01,098 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:127) ERROR - try to depose ioc
2018-01-26 16:06:01,099 org.nutz.ioc.impl.NutIoc.depose(NutIoc.java:255) INFO  - org.nutz.ioc.impl.NutIoc@1820170770 is closing. startup date [18-01-26 16:05:58.673]
2018-01-26 16:06:01,099 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'cleanNonActiveUserJob' ...
2018-01-26 16:06:01,099 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'authorityService' ...
2018-01-26 16:06:01,099 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'jobFactory' ...
2018-01-26 16:06:01,100 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'scheduler' ...
2018-01-26 16:06:01,100 org.quartz.core.QuartzScheduler.shutdown(QuartzScheduler.java:694) INFO  - Scheduler NutzbookScheduler_$_NON_CLUSTERED shutting down.
2018-01-26 16:06:01,100 org.quartz.core.QuartzScheduler.standby(QuartzScheduler.java:613) INFO  - Scheduler NutzbookScheduler_$_NON_CLUSTERED paused.
2018-01-26 16:06:01,100 org.quartz.simpl.SimpleThreadPool.shutdown(SimpleThreadPool.java:328) DEBUG - Shutting down threadpool...
2018-01-26 16:06:01,100 org.quartz.simpl.SimpleThreadPool.shutdown(SimpleThreadPool.java:395) DEBUG - Shutdown of threadpool complete.
2018-01-26 16:06:01,102 org.quartz.core.QuartzScheduler.shutdown(QuartzScheduler.java:771) INFO  - Scheduler NutzbookScheduler_$_NON_CLUSTERED shutdown complete.
2018-01-26 16:06:01,103 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'nutQuartzCronJobFactory' ...
2018-01-26 16:06:01,106 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'conf' ...
2018-01-26 16:06:01,107 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'dao' ...
2018-01-26 16:06:01,107 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:113) DEBUG - Depose object 'dataSource' ...
2018-01-26 16:06:01,160 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:612) DEBUG - WorkerThread is shut down.
2018-01-26 16:06:01,160 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:612) DEBUG - WorkerThread is shut down.
2018-01-26 16:06:01,230 com.alibaba.druid.pool.DruidDataSource.close(DruidDataSource.java:1444) INFO  - {dataSource-1} closed
2018-01-26 16:06:01,231 org.nutz.ioc.impl.NutIoc.depose(NutIoc.java:262) INFO  - org.nutz.ioc.impl.NutIoc@1820170770 is deposed. startup date [18-01-26 16:05:58.673]
一月 26, 2018 4:06:01 下午 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:4689)
	at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5329)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1407)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1397)
	at java.util.concurrent.FutureTask.run(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.NullPointerException
	at net.wendal.nutzbook.service.AuthorityServiceImpl.checkBasicRoles(AuthorityServiceImpl.java:29)
	at net.wendal.nutzbook.MainSetup.init(MainSetup.java:46)
	at org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:274)
	at org.nutz.mvc.impl.NutLoading.load(NutLoading.java:121)
	... 15 more

一月 26, 2018 4:06:01 下午 org.apache.catalina.core.StandardContext startInternal
严重: One or more Filters failed to start. Full details will be found in the appropriate container log file
一月 26, 2018 4:06:01 下午 org.apache.catalina.core.StandardContext startInternal
严重: Context [/demo] startup failed due to previous errors
一月 26, 2018 4:06:01 下午 org.apache.catalina.core.ApplicationContext log
信息: Cleaning up Shiro Environment
一月 26, 2018 4:06:01 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesJdbc
警告: The web application [demo] 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.
一月 26, 2018 4:06:01 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesJdbc
警告: The web application [demo] registered the JDBC driver [oracle.jdbc.OracleDriver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
一月 26, 2018 4:06:01 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
警告: The web application [demo] appears to have started a thread named [NutzbookScheduler_Worker-1] 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)
 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
一月 26, 2018 4:06:01 下午 org.apache.coyote.AbstractProtocol start
信息: Starting ProtocolHandler ["http-nio-8080"]
一月 26, 2018 4:06:01 下午 org.apache.coyote.AbstractProtocol start
信息: Starting ProtocolHandler ["ajp-nio-8009"]
一月 26, 2018 4:06:01 下午 org.apache.catalina.startup.Catalina start
信息: Server startup in 8437 ms
2018-01-26 16:06:01,344 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:612) DEBUG - WorkerThread is shut down.

@管理员(admin)
改过这里了，然后还是报错，开始是8楼的结果现在是这样的

一月 26, 2018 4:10:53 下午 org.apache.tomcat.util.digester.SetPropertiesRule begin
警告: [SetPropertiesRule]{Server/Service/Engine/Host/Context} Setting property 'source' to 'org.eclipse.jst.jee.server:demo' did not find a matching property.
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server version:        Apache Tomcat/8.0.36
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server built:          Jun 9 2016 13:55:50 UTC
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Server number:         8.0.36.0
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: OS Name:               Windows 7
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: OS Version:            6.1
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Architecture:          amd64
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Java Home:             C:\Program Files\Java\jre1.8.0_151
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: JVM Version:           1.8.0_151-b12
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: JVM Vendor:            Oracle Corporation
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: CATALINA_BASE:         D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: CATALINA_HOME:         D:\soft
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dcatalina.base=D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dcatalina.home=D:\soft
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dwtp.deploy=D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Djava.endorsed.dirs=D:\soft\endorsed
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.VersionLoggerListener log
信息: Command line argument: -Dfile.encoding=UTF-8
一月 26, 2018 4:10:53 下午 org.apache.catalina.core.AprLifecycleListener lifecycleEvent
信息: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: C:\Program Files\Java\jre1.8.0_151\bin;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;C:/Program Files/Java/jre1.8.0_151/bin/server;C:/Program Files/Java/jre1.8.0_151/bin;C:/Program Files/Java/jre1.8.0_151/lib/amd64;C:\ProgramData\Oracle\Java\javapath;E:\orcl\product\11.2.0\dbhome_1\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\java\jdk1.8.0_151\bin;C:\java\jdk1.8.0_151\jre\bin;C:\Program Files\TortoiseSVN\bin;D:\soft\apache-maven-3.5.2-bin\apache-maven-3.5.2\bin;C:\Users\Administrator\Downloads\mysql-5.7.20-winx64\mysql-5.7.20-winx64\bin;D:\software\tortoiseGit\bin;C:\Users\Administrator\Desktop;;.
一月 26, 2018 4:10:53 下午 org.apache.coyote.AbstractProtocol init
信息: Initializing ProtocolHandler ["http-nio-8080"]
一月 26, 2018 4:10:53 下午 org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
信息: Using a shared selector for servlet write/read
一月 26, 2018 4:10:53 下午 org.apache.coyote.AbstractProtocol init
信息: Initializing ProtocolHandler ["ajp-nio-8009"]
一月 26, 2018 4:10:53 下午 org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
信息: Using a shared selector for servlet write/read
一月 26, 2018 4:10:53 下午 org.apache.catalina.startup.Catalina load
信息: Initialization processed in 770 ms
一月 26, 2018 4:10:53 下午 org.apache.catalina.core.StandardService startInternal
信息: Starting service Catalina
一月 26, 2018 4:10:53 下午 org.apache.catalina.core.StandardEngine startInternal
信息: Starting Servlet Engine: Apache Tomcat/8.0.36
一月 26, 2018 4:10:55 下午 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.
一月 26, 2018 4:10:58 下午 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.
一月 26, 2018 4:10:58 下午 org.apache.catalina.core.ApplicationContext log
信息: Initializing Shiro environment
2018-01-26 16:10:58,441 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:128) INFO  - Starting Shiro environment initialization.
2018-01-26 16:10:58,452 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:76) DEBUG - Checking any specified config locations.
2018-01-26 16:10:58,452 org.apache.shiro.web.env.IniWebEnvironment.init(IniWebEnvironment.java:81) DEBUG - No INI instance or config locations specified.  Trying default config locations.
2018-01-26 16:10:58,456 org.apache.shiro.io.ResourceUtils.loadFromClassPath(ResourceUtils.java:159) DEBUG - Opening resource from class path [shiro.ini]
2018-01-26 16:10:58,460 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [main]
2018-01-26 16:10:58,462 org.apache.shiro.config.Ini.load(Ini.java:351) DEBUG - Parsing [urls]
2018-01-26 16:10:58,463 org.apache.shiro.web.env.IniWebEnvironment.getDefaultIni(IniWebEnvironment.java:136) DEBUG - Discovered non-empty INI configuration at location 'classpath:shiro.ini'.  Using for configuration.
2018-01-26 16:10:58,466 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=main,urls]
2018-01-26 16:10:58,714 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:234) DEBUG - No authorizationCache instance set.  Checking for a cacheManager...
2018-01-26 16:10:58,715 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:248) DEBUG - No cache or cacheManager properties have been set.  Authorization cache cannot be obtained.
2018-01-26 16:10:58,715 org.apache.shiro.config.ReflectionBuilder.createNewInstance(ReflectionBuilder.java:296) INFO  - An instance with name 'authc' already exists.  Redefining this object as a new instance of type org.nutz.integration.shiro.SimpleAuthenticationFilter
2018-01-26 16:10:58,740 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: false
2018-01-26 16:10:58,741 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Boolean' value 'false' to type 'Boolean'
2018-01-26 16:10:58,741 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Boolean
2018-01-26 16:10:58,743 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:10:58,743 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Byte'
2018-01-26 16:10:58,744 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Byte value '0'
2018-01-26 16:10:58,744 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value:  
2018-01-26 16:10:58,745 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Character' value ' ' to type 'Character'
2018-01-26 16:10:58,745 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Character
2018-01-26 16:10:58,745 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:10:58,746 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Double'
2018-01-26 16:10:58,746 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Double value '0.0'
2018-01-26 16:10:58,747 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:10:58,747 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Float'
2018-01-26 16:10:58,747 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Float value '0.0'
2018-01-26 16:10:58,748 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:10:58,748 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Integer'
2018-01-26 16:10:58,748 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Integer
2018-01-26 16:10:58,749 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:10:58,749 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Long'
2018-01-26 16:10:58,749 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Long value '0'
2018-01-26 16:10:58,750 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:10:58,750 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Short'
2018-01-26 16:10:58,750 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Short value '0'
2018-01-26 16:10:58,751 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0.0
2018-01-26 16:10:58,752 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigDecimal' value '0.0' to type 'BigDecimal'
2018-01-26 16:10:58,752 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigDecimal
2018-01-26 16:10:58,752 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:10:58,752 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigInteger' value '0' to type 'BigInteger'
2018-01-26 16:10:58,753 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigInteger
2018-01-26 16:10:58,753 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: false
2018-01-26 16:10:58,753 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Boolean' value 'false' to type 'Boolean'
2018-01-26 16:10:58,753 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Boolean
2018-01-26 16:10:58,753 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:10:58,753 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Byte'
2018-01-26 16:10:58,753 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Byte value '0'
2018-01-26 16:10:58,753 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value:  
2018-01-26 16:10:58,753 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Character' value ' ' to type 'Character'
2018-01-26 16:10:58,754 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Character
2018-01-26 16:10:58,754 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:10:58,754 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Double'
2018-01-26 16:10:58,754 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Double value '0.0'
2018-01-26 16:10:58,754 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:10:58,754 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Float'
2018-01-26 16:10:58,754 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Float value '0.0'
2018-01-26 16:10:58,754 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:10:58,755 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Integer'
2018-01-26 16:10:58,755 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Integer
2018-01-26 16:10:58,755 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:10:58,755 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Long'
2018-01-26 16:10:58,755 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Long value '0'
2018-01-26 16:10:58,755 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 0
2018-01-26 16:10:58,756 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer' value '0' to type 'Short'
2018-01-26 16:10:58,756 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:171) DEBUG -     Converted to Short value '0'
2018-01-26 16:10:58,757 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: 
2018-01-26 16:10:58,757 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value '' to type 'String'
2018-01-26 16:10:58,763 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Z@75812d9a
2018-01-26 16:10:58,763 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'boolean[]' value '[Z@75812d9a' to type 'boolean[]'
2018-01-26 16:10:58,763 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a boolean[]
2018-01-26 16:10:58,763 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [B@1836b64a
2018-01-26 16:10:58,764 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'byte[]' value '[B@1836b64a' to type 'byte[]'
2018-01-26 16:10:58,764 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a byte[]
2018-01-26 16:10:58,765 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [C@4e2a97a4
2018-01-26 16:10:58,765 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'char[]' value '[C@4e2a97a4' to type 'char[]'
2018-01-26 16:10:58,765 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a char[]
2018-01-26 16:10:58,766 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [D@4c4652e4
2018-01-26 16:10:58,766 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'double[]' value '[D@4c4652e4' to type 'double[]'
2018-01-26 16:10:58,766 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a double[]
2018-01-26 16:10:58,766 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [F@30574b0b
2018-01-26 16:10:58,766 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'float[]' value '[F@30574b0b' to type 'float[]'
2018-01-26 16:10:58,766 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a float[]
2018-01-26 16:10:58,766 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [I@1dfe3fad
2018-01-26 16:10:58,767 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'int[]' value '[I@1dfe3fad' to type 'int[]'
2018-01-26 16:10:58,767 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a int[]
2018-01-26 16:10:58,767 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [J@7730c01
2018-01-26 16:10:58,768 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'long[]' value '[J@7730c01' to type 'long[]'
2018-01-26 16:10:58,768 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a long[]
2018-01-26 16:10:58,768 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [S@79dcbf79
2018-01-26 16:10:58,768 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'short[]' value '[S@79dcbf79' to type 'short[]'
2018-01-26 16:10:58,768 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a short[]
2018-01-26 16:10:58,768 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.math.BigDecimal;@73d9bc5a
2018-01-26 16:10:58,768 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigDecimal[]' value '[Ljava.math.BigDecimal;@73d9bc5a' to type 'BigDecimal[]'
2018-01-26 16:10:58,768 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigDecimal[]
2018-01-26 16:10:58,769 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.math.BigInteger;@baf228
2018-01-26 16:10:58,769 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'BigInteger[]' value '[Ljava.math.BigInteger;@baf228' to type 'BigInteger[]'
2018-01-26 16:10:58,769 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a BigInteger[]
2018-01-26 16:10:58,769 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Boolean;@2284f697
2018-01-26 16:10:58,769 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Boolean[]' value '[Ljava.lang.Boolean;@2284f697' to type 'Boolean[]'
2018-01-26 16:10:58,769 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Boolean[]
2018-01-26 16:10:58,770 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Byte;@5dd044fd
2018-01-26 16:10:58,770 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Byte[]' value '[Ljava.lang.Byte;@5dd044fd' to type 'Byte[]'
2018-01-26 16:10:58,770 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Byte[]
2018-01-26 16:10:58,770 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Character;@49e4021f
2018-01-26 16:10:58,771 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Character[]' value '[Ljava.lang.Character;@49e4021f' to type 'Character[]'
2018-01-26 16:10:58,771 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Character[]
2018-01-26 16:10:58,771 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Double;@7a6dd5a4
2018-01-26 16:10:58,771 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Double[]' value '[Ljava.lang.Double;@7a6dd5a4' to type 'Double[]'
2018-01-26 16:10:58,771 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Double[]
2018-01-26 16:10:58,771 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Float;@544c2dff
2018-01-26 16:10:58,772 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Float[]' value '[Ljava.lang.Float;@544c2dff' to type 'Float[]'
2018-01-26 16:10:58,772 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Float[]
2018-01-26 16:10:58,772 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Integer;@49066c32
2018-01-26 16:10:58,772 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Integer[]' value '[Ljava.lang.Integer;@49066c32' to type 'Integer[]'
2018-01-26 16:10:58,772 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Integer[]
2018-01-26 16:10:58,772 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Long;@48d0dc84
2018-01-26 16:10:58,772 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Long[]' value '[Ljava.lang.Long;@48d0dc84' to type 'Long[]'
2018-01-26 16:10:58,772 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Long[]
2018-01-26 16:10:58,772 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Short;@7d4680f8
2018-01-26 16:10:58,775 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Short[]' value '[Ljava.lang.Short;@7d4680f8' to type 'Short[]'
2018-01-26 16:10:58,775 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Short[]
2018-01-26 16:10:58,775 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.String;@7f1e3a97
2018-01-26 16:10:58,775 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String[]' value '[Ljava.lang.String;@7f1e3a97' to type 'String[]'
2018-01-26 16:10:58,775 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a String[]
2018-01-26 16:10:58,775 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.lang.Class;@2044d34a
2018-01-26 16:10:58,775 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Class[]' value '[Ljava.lang.Class;@2044d34a' to type 'Class[]'
2018-01-26 16:10:58,776 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Class[]
2018-01-26 16:10:58,776 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.util.Date;@69ccd6fa
2018-01-26 16:10:58,777 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Date[]' value '[Ljava.util.Date;@69ccd6fa' to type 'Date[]'
2018-01-26 16:10:58,777 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Date[]
2018-01-26 16:10:58,777 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.util.Calendar;@71dc328a
2018-01-26 16:10:58,777 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'Calendar[]' value '[Ljava.util.Calendar;@71dc328a' to type 'Calendar[]'
2018-01-26 16:10:58,778 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a Calendar[]
2018-01-26 16:10:58,778 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.io.File;@78f01264
2018-01-26 16:10:58,778 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.io.File[]' value '[Ljava.io.File;@78f01264' to type 'java.io.File[]'
2018-01-26 16:10:58,778 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.io.File[]
2018-01-26 16:10:58,778 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.sql.Date;@54270964
2018-01-26 16:10:58,778 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.sql.Date[]' value '[Ljava.sql.Date;@54270964' to type 'java.sql.Date[]'
2018-01-26 16:10:58,779 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.sql.Date[]
2018-01-26 16:10:58,779 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.sql.Time;@78e77c70
2018-01-26 16:10:58,779 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.sql.Time[]' value '[Ljava.sql.Time;@78e77c70' to type 'java.sql.Time[]'
2018-01-26 16:10:58,779 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.sql.Time[]
2018-01-26 16:10:58,779 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.sql.Timestamp;@29fdbaae
2018-01-26 16:10:58,779 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.sql.Timestamp[]' value '[Ljava.sql.Timestamp;@29fdbaae' to type 'java.sql.Timestamp[]'
2018-01-26 16:10:58,779 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.sql.Timestamp[]
2018-01-26 16:10:58,779 org.apache.commons.beanutils.converters.AbstractConverter.setDefaultValue(AbstractConverter.java:353) DEBUG - Setting default value: [Ljava.net.URL;@bce2e50
2018-01-26 16:10:58,779 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'java.net.URL[]' value '[Ljava.net.URL;@bce2e50' to type 'java.net.URL[]'
2018-01-26 16:10:58,780 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:162) DEBUG -     No conversion required, value is already a java.net.URL[]
2018-01-26 16:10:58,803 org.apache.commons.beanutils.ConvertUtilsBean.convert(ConvertUtilsBean.java:481) DEBUG - Convert string '/user/login' to class 'java.lang.String'
2018-01-26 16:10:58,803 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value '/user/login' to type 'String'
2018-01-26 16:10:58,857 org.apache.commons.beanutils.ConvertUtilsBean.convert(ConvertUtilsBean.java:481) DEBUG - Convert string '/user/login' to class 'java.lang.String'
2018-01-26 16:10:58,857 org.apache.commons.beanutils.converters.AbstractConverter.convert(AbstractConverter.java:140) DEBUG - Converting 'String' value '/user/login' to type 'String'
2018-01-26 16:10:58,858 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:234) DEBUG - No authorizationCache instance set.  Checking for a cacheManager...
2018-01-26 16:10:58,858 org.apache.shiro.realm.AuthorizingRealm.getAuthorizationCacheLazy(AuthorizingRealm.java:248) DEBUG - No cache or cacheManager properties have been set.  Authorization cache cannot be obtained.
2018-01-26 16:10:58,869 org.apache.shiro.config.IniFactorySupport.createInstance(IniFactorySupport.java:122) DEBUG - Creating instance from Ini [sections=main,urls]
2018-01-26 16:10:58,872 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/rs/*] from String definition [anon]
2018-01-26 16:10:58,872 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/rs/*] to filter [anon] with config [null]
2018-01-26 16:10:58,873 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/logout] from String definition [logout]
2018-01-26 16:10:58,873 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/logout] to filter [logout] with config [null]
2018-01-26 16:10:58,873 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/error] from String definition [anon]
2018-01-26 16:10:58,873 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/error] to filter [anon] with config [null]
2018-01-26 16:10:58,874 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/login] from String definition [anon]
2018-01-26 16:10:58,874 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/login] to filter [anon] with config [null]
2018-01-26 16:10:58,874 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.createChain(DefaultFilterChainManager.java:127) DEBUG - Creating chain [/user/profile/active/mail] from String definition [anon]
2018-01-26 16:10:58,874 org.apache.shiro.web.filter.mgt.DefaultFilterChainManager.applyChainConfig(DefaultFilterChainManager.java:278) DEBUG - Attempting to apply path [/user/profile/active/mail] to filter [anon] with config [null]
2018-01-26 16:10:58,874 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]
2018-01-26 16:10:58,874 org.apache.shiro.web.env.EnvironmentLoader.initEnvironment(EnvironmentLoader.java:141) INFO  - Shiro environment initialized in 431 ms.
2018-01-26 16:10:58,909 org.nutz.mvc.NutFilter._init(NutFilter.java:85) INFO  - NutFilter[nutz] starting ...
2018-01-26 16:10:58,938 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=10 time use 20ms
2018-01-26 16:10:58,952 org.nutz.resource.Scans.printLocations(Scans.java:521) DEBUG - Locations count=30 time use 14ms
2018-01-26 16:10:59,006 org.nutz.castor.Castors.reload(Castors.java:115) DEBUG - Using 95 castor for Castors
2018-01-26 16:10:59,030 org.nutz.mvc.config.AbstractNutConfig.createLoading(AbstractNutConfig.java:59) DEBUG - Loading by class org.nutz.mvc.impl.NutLoading
2018-01-26 16:10:59,032 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:55) INFO  - Nutz Version : 1.r.62 
2018-01-26 16:10:59,033 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:56) INFO  - Nutz.Mvc[nutz] is initializing ...
2018-01-26 16:10:59,033 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:60) DEBUG - Web Container Information:
2018-01-26 16:10:59,034 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:61) DEBUG -  - Default Charset : UTF-8
2018-01-26 16:10:59,034 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:62) DEBUG -  - Current . path  : C:\Users\Administrator\Desktop\.
2018-01-26 16:10:59,034 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:63) DEBUG -  - Java Version    : 1.8.0_151
2018-01-26 16:10:59,034 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:64) DEBUG -  - File separator  : \
2018-01-26 16:10:59,034 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:65) DEBUG -  - Timezone        : Asia/Shanghai
2018-01-26 16:10:59,036 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:66) DEBUG -  - OS              : Windows 7 amd64
2018-01-26 16:10:59,036 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:67) DEBUG -  - ServerInfo      : Apache Tomcat/8.0.36
2018-01-26 16:10:59,037 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:68) DEBUG -  - Servlet API     : 3.1
2018-01-26 16:10:59,038 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:73) DEBUG -  - ContextPath     : /demo
2018-01-26 16:10:59,038 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:74) DEBUG -  - context.tempdir : D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\work\Catalina\localhost\demo
2018-01-26 16:10:59,038 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:75) DEBUG -  - MainModule      : net.wendal.nutzbook.MainModule
2018-01-26 16:10:59,041 org.nutz.mvc.impl.NutLoading.createContext(NutLoading.java:235) DEBUG - >> app.root = D:/workspace/.metadata/.plugins/org.eclipse.wst.server.core/tmp1/wtpwebapps/demo
2018-01-26 16:10:59,046 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=[])
2018-01-26 16:10:59,109 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 2 resource by src( ioc/ ) , regex( ^(.+[.])(js|json)$ )
2018-01-26 16:10:59,110 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [dao.js]
2018-01-26 16:10:59,115 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:49) DEBUG - loading [mail.js]
2018-01-26 16:10:59,116 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 5 bean define from path=[ioc/] --> [conf, dao, emailAuthenticator, dataSource, htmlEmail]
2018-01-26 16:10:59,140 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 21 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2018-01-26 16:10:59,159 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.AuthorityModule
2018-01-26 16:10:59,173 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.CaptchaModule
2018-01-26 16:10:59,175 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserModule
2018-01-26 16:10:59,184 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.module.UserProfileModule
2018-01-26 16:10:59,188 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob
2018-01-26 16:10:59,191 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.AuthorityServiceImpl
2018-01-26 16:10:59,192 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.EmailServiceImpl
2018-01-26 16:10:59,194 org.nutz.ioc.loader.annotation.AnnotationIocLoader.addClass(AnnotationIocLoader.java:76) DEBUG - Found @IocBean : class net.wendal.nutzbook.service.UserService
2018-01-26 16:10:59,200 org.nutz.ioc.loader.annotation.AnnotationIocLoader.<init>(AnnotationIocLoader.java:52) INFO  - Found 8 classes in 1 base-packages!
beans = ["cleanNonActiveUserJob", "authorityService", "userProfileModule", "captchaModule", "authorityModule", "userModule", "emailService", "userService"]
2018-01-26 16:10:59,207 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:40) DEBUG - Loaded 5 bean define from reader --
[txREPEATABLE_READ, txSERIALIZABLE, txNONE, txREAD_UNCOMMITTED, txREAD_COMMITTED]
2018-01-26 16:10:59,210 org.nutz.ioc.loader.combo.ComboIocLoader.createIocLoader(ComboIocLoader.java:110) DEBUG - found quartz -- org.nutz.integration.quartz.QuartzIocLoader
2018-01-26 16:10:59,214 org.nutz.ioc.loader.json.JsonLoader.<init>(JsonLoader.java:57) DEBUG - Loaded 0 bean define from path=[] --> []
2018-01-26 16:10:59,218 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:98) INFO  - NutIoc init begin ...
2018-01-26 16:10:59,221 org.nutz.ioc.impl.NutIoc.<init>(NutIoc.java:115) INFO  - ... NutIoc init complete
2018-01-26 16:10:59,224 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:159) INFO  - Build URL mapping by org.nutz.mvc.impl.UrlMappingImpl ...
2018-01-26 16:10:59,226 org.nutz.mvc.impl.NutLoading.createViewMakers(NutLoading.java:366) DEBUG - @Views(DefaultViewMaker.class)
2018-01-26 16:10:59,242 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( mvc/nutzbook-mvc-chain.js ) , regex( ^(.+[.])(js|json)$ )
2018-01-26 16:10:59,248 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"
   }
}
2018-01-26 16:10:59,249 org.nutz.mvc.impl.NutLoading.createChainMaker(NutLoading.java:263) DEBUG - @ChainBy(org.nutz.mvc.impl.NutActionChainMaker)
2018-01-26 16:10:59,256 org.nutz.mvc.impl.Loadings.scanModules(Loadings.java:154) DEBUG - module class location 'file:/D:/workspace/.metadata/.plugins/org.eclipse.wst.server.core/tmp1/wtpwebapps/demo/WEB-INF/classes/'
2018-01-26 16:10:59,256 org.nutz.mvc.impl.Loadings.scanModuleInPackage(Loadings.java:184) DEBUG -  > scan 'net.wendal.nutzbook'
2018-01-26 16:10:59,269 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 21 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2018-01-26 16:10:59,270 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.AuthorityModule'
2018-01-26 16:10:59,271 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.CaptchaModule'
2018-01-26 16:10:59,271 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserModule'
2018-01-26 16:10:59,271 org.nutz.mvc.impl.Loadings.checkModule(Loadings.java:199) DEBUG -    >> add 'net.wendal.nutzbook.module.UserProfileModule'
2018-01-26 16:10:59,343 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/'                    >> (UserModule.java:122).index           : void       | @Ok(jsp:jsp.user.list) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,429 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/add'                 >> (UserModule.java:77).add              : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,430 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/count'               >> (UserModule.java:44).count            : int        | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,435 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/update'              >> (UserModule.java:89).update           : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,437 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/delete'              >> (UserModule.java:99).delete           : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,450 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/query'               >> (UserModule.java:110).query           : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,454 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/error'               >> (UserModule.java:158).error           : void       | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,456 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/login'               >> (UserModule.java:53).login            : Object     | @Ok(json:{locked:'password|salt',ignoreNull:true}) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,458 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/logout'              >> (UserModule.java:71).logout           : void       | @Ok(>>:/ ) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,462 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/login'               >> (UserModule.java:166).loginPage       : void       | @Ok(jsp:jsp.user.login) @Fail(http:500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,469 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/admin/authority/user/update' >> (AuthorityModule.java:37).updateUser  : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,472 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/'            >> (UserProfileModule.java:139).index    : UserProfile | @Ok(jsp:jsp.user.profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,473 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/get'         >> (UserProfileModule.java:85).get       : UserProfile | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,474 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/update'      >> (UserProfileModule.java:100).update   : void       | @Ok(void ) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,476 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:173).activeMailCallback : String     | @Ok(raw  ) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,492 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:23) INFO  - Init file-pool by: D:/workspace/.metadata/.plugins/org.eclipse.wst.server.core/tmp1/wtpwebapps/demo/WEB-INF/tmp/user_avatar [20000]
2018-01-26 16:10:59,494 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:37) DEBUG - file-pool.home: 'D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps\demo\WEB-INF\tmp\user_avatar'
2018-01-26 16:10:59,495 org.nutz.filepool.NutFilePool.<init>(NutFilePool.java:66) INFO  - file-pool.cursor: 0
2018-01-26 16:10:59,499 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:57).uploadAvatar : void       | @Ok(>>:/user/profile) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,502 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/avatar'      >> (UserProfileModule.java:128).readAvatar : Object     | @Ok(raw:jpg) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,503 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/user/profile/active/mail' >> (UserProfileModule.java:146).activeMail : Object     | @Ok(json:full) @Fail(jsp:jsp.500) | by 1 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,505 org.nutz.mvc.impl.UrlMappingImpl.print(UrlMappingImpl.java:146) DEBUG -    '/captcha/next'             >> (CaptchaModule.java:23).next          : BufferedImage | @Ok(raw:png) @Fail(jsp:jsp.500) | by 0 Filters | (I:UTF-8/O:UTF-8)
2018-01-26 16:10:59,505 org.nutz.mvc.impl.NutLoading.evalUrlMapping(NutLoading.java:217) INFO  - Found 19 module methods
2018-01-26 16:10:59,505 org.nutz.mvc.impl.NutLoading.evalLocalization(NutLoading.java:303) DEBUG - Localization: org.nutz.mvc.impl.NutMessageLoader('msg/')  dft<zh-CN>
2018-01-26 16:10:59,510 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( msg/ ) , regex( ^.+[.]properties$ )
2018-01-26 16:10:59,510 org.nutz.mvc.impl.NutMessageLoader.load(NutMessageLoader.java:27) DEBUG - Load Messages in 1 resource : [[File[D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps\demo\WEB-INF\classes\msg\zh-CN\user.properties]]]
2018-01-26 16:10:59,512 org.nutz.mvc.impl.NutMessageLoader.load(NutMessageLoader.java:95) DEBUG - Message Loaded, size = 2
2018-01-26 16:10:59,515 org.nutz.mvc.impl.NutLoading.createSessionProvider(NutLoading.java:410) INFO  - SessionBy --> org.nutz.integration.shiro.ShiroSessionProvider@489dd5a5
2018-01-26 16:10:59,516 org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:271) INFO  - Setup application...
2018-01-26 16:10:59,519 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2018-01-26 16:10:59,521 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
2018-01-26 16:10:59,522 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dao
2018-01-26 16:10:59,522 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dao
2018-01-26 16:10:59,525 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dao) in JsonLoader(paths=[ioc/])
2018-01-26 16:10:59,526 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dao'<interface org.nutz.dao.Dao>
2018-01-26 16:10:59,535 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.dao.impl.NutDao without AOP
2018-01-26 16:10:59,536 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dao' to [app] 
2018-01-26 16:10:59,544 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2018-01-26 16:10:59,544 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=dataSource
2018-01-26 16:10:59,544 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=dataSource
2018-01-26 16:10:59,555 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(dataSource) in JsonLoader(paths=[ioc/])
2018-01-26 16:10:59,555 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'dataSource'<>
2018-01-26 16:10:59,572 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class com.alibaba.druid.pool.DruidDataSource without AOP
2018-01-26 16:10:59,572 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'dataSource' to [app] 
2018-01-26 16:10:59,574 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2018-01-26 16:10:59,574 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=conf
2018-01-26 16:10:59,574 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=conf
2018-01-26 16:10:59,589 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(conf) in JsonLoader(paths=[ioc/])
2018-01-26 16:10:59,589 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'conf'<>
2018-01-26 16:10:59,590 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.ioc.impl.PropertiesProxy without AOP
2018-01-26 16:10:59,590 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'conf' to [app] 
2018-01-26 16:10:59,636 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 3 resource by src( custom/ ) , regex( ^.+[.]properties$ )
2018-01-26 16:10:59,637 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps\demo\WEB-INF\classes\custom\cron.properties]
2018-01-26 16:10:59,638 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps\demo\WEB-INF\classes\custom\db.properties]
2018-01-26 16:10:59,639 org.nutz.ioc.impl.PropertiesProxy.setPaths(PropertiesProxy.java:113) DEBUG - load properties from File[D:\workspace\.metadata\.plugins\org.eclipse.wst.server.core\tmp1\wtpwebapps\demo\WEB-INF\classes\custom\mail.properties]
2018-01-26 16:11:00,131 com.alibaba.druid.pool.DruidDataSource.init(DruidDataSource.java:715) INFO  - {dataSource-1} inited
2018-01-26 16:11:00,132 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dataSource'<>
2018-01-26 16:11:00,288 org.nutz.dao.jdbc.Jdbcs.<clinit>(Jdbcs.java:90) DEBUG - Jdbcs init complete
2018-01-26 16:11:00,288 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
2018-01-26 16:11:00,800 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:188) DEBUG - select expert : org.nutz.dao.impl.jdbc.oracle.OracleJdbcExpert
2018-01-26 16:11:00,805 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:199) DEBUG - JDBC Driver --> 11.2.0.4.0
2018-01-26 16:11:00,806 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:200) DEBUG - JDBC Name   --> Oracle JDBC driver
2018-01-26 16:11:00,806 org.nutz.dao.impl.DaoSupport$1.invoke(DaoSupport.java:202) DEBUG - JDBC URL    --> jdbc:oracle:thin:@127.0.0.1:1521/NUTZBOOK
2018-01-26 16:11:00,806 org.nutz.dao.impl.DaoSupport.setDataSource(DaoSupport.java:221) DEBUG - Database info --> ORACLE:[Oracle - Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options]
2018-01-26 16:11:00,816 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 21 resource by src( net/wendal/nutzbook/ ) , regex( ^.+[.]class$ )
2018-01-26 16:11:00,918 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT COUNT(*) FROM atf_user 
2018-01-26 16:11:00,923 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'nutQuartzCronJobFactory'<class org.nutz.integration.quartz.NutQuartzCronJobFactory>
2018-01-26 16:11:00,923 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=nutQuartzCronJobFactory
2018-01-26 16:11:00,923 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=nutQuartzCronJobFactory
2018-01-26 16:11:00,924 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(nutQuartzCronJobFactory) in QuartzIocLoader@1536830160
2018-01-26 16:11:00,924 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'nutQuartzCronJobFactory'<class org.nutz.integration.quartz.NutQuartzCronJobFactory>
2018-01-26 16:11:00,924 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.integration.quartz.NutQuartzCronJobFactory without AOP
2018-01-26 16:11:00,925 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'nutQuartzCronJobFactory' to [app] 
2018-01-26 16:11:00,928 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'scheduler'<>
2018-01-26 16:11:00,928 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=scheduler
2018-01-26 16:11:00,928 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=scheduler
2018-01-26 16:11:00,929 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(scheduler) in QuartzIocLoader@1536830160
2018-01-26 16:11:00,929 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'scheduler'<>
2018-01-26 16:11:00,929 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'scheduler' to [app] 
2018-01-26 16:11:00,967 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1172) INFO  - Using default implementation for ThreadExecutor
2018-01-26 16:11:01,064 org.quartz.core.SchedulerSignalerImpl.<init>(SchedulerSignalerImpl.java:61) INFO  - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2018-01-26 16:11:01,065 org.quartz.core.QuartzScheduler.<init>(QuartzScheduler.java:240) INFO  - Quartz Scheduler v.2.2.3 created.
2018-01-26 16:11:01,065 org.quartz.simpl.RAMJobStore.initialize(RAMJobStore.java:155) INFO  - RAMJobStore initialized.
2018-01-26 16:11:01,066 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.

2018-01-26 16:11:01,066 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1327) INFO  - Quartz scheduler 'NutzbookScheduler' initialized from default resource file in Quartz package: 'quartz.properties'
2018-01-26 16:11:01,066 org.quartz.impl.StdSchedulerFactory.instantiate(StdSchedulerFactory.java:1331) INFO  - Quartz scheduler version: 2.2.3
2018-01-26 16:11:01,066 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'jobFactory'<>
2018-01-26 16:11:01,066 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=jobFactory
2018-01-26 16:11:01,066 org.nutz.ioc.loader.map.MapLoader.load(MapLoader.java:67) DEBUG - Loading define for name=jobFactory
2018-01-26 16:11:01,067 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(jobFactory) in QuartzIocLoader@1536830160
2018-01-26 16:11:01,068 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'jobFactory'<>
2018-01-26 16:11:01,068 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class org.nutz.integration.quartz.NutQuartzJobFactory without AOP
2018-01-26 16:11:01,070 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'jobFactory' to [app] 
2018-01-26 16:11:01,109 org.quartz.core.QuartzScheduler.setJobFactory(QuartzScheduler.java:2311) INFO  - JobFactory set to: org.nutz.integration.quartz.NutQuartzJobFactory@5ed0d1c4
2018-01-26 16:11:01,109 org.quartz.core.QuartzScheduler.start(QuartzScheduler.java:575) INFO  - Scheduler NutzbookScheduler_$_NON_CLUSTERED started.
2018-01-26 16:11:01,110 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'conf'<>
2018-01-26 16:11:01,110 org.nutz.integration.quartz.NutQuartzCronJobFactory.init(NutQuartzCronJobFactory.java:35) DEBUG - job define name=net.wendal.nutzbook.quartz.job.CleanNonActiveUserJob cron=0 0/2 * * * ?
2018-01-26 16:11:01,123 org.nutz.integration.quartz.NutQuartzCronJobFactory.init(NutQuartzCronJobFactory.java:28) DEBUG - found cron job packages = net.wendal.nutzbook.quartz.job
2018-01-26 16:11:01,125 org.nutz.resource.Scans.scan(Scans.java:274) DEBUG - Found 1 resource by src( net/wendal/nutzbook/quartz/job/ ) , regex( ^.+[.]class$ )
2018-01-26 16:11:01,126 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'authorityService'<interface net.wendal.nutzbook.service.AuthorityService>
2018-01-26 16:11:01,126 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:177) DEBUG - 	 >> Load definition name=authorityService
2018-01-26 16:11:01,126 org.nutz.ioc.loader.combo.ComboIocLoader.load(ComboIocLoader.java:161) DEBUG - Found IocObject(authorityService) in AnnotationIocLoader(packages=[net.wendal.nutzbook])
2018-01-26 16:11:01,126 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:209) DEBUG - 	 >> Make...'authorityService'<interface net.wendal.nutzbook.service.AuthorityService>
2018-01-26 16:11:01,126 org.nutz.ioc.aop.impl.DefaultMirrorFactory.getMirror(DefaultMirrorFactory.java:70) DEBUG - Load class net.wendal.nutzbook.service.AuthorityServiceImpl without AOP
2018-01-26 16:11:01,126 org.nutz.ioc.impl.ScopeContext.save(ScopeContext.java:64) DEBUG - Save object 'authorityService' to [app] 
2018-01-26 16:11:01,129 org.nutz.ioc.impl.NutIoc.get(NutIoc.java:151) DEBUG - Get 'dao'<interface org.nutz.dao.Dao>
2018-01-26 16:11:01,132 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM atf_user  WHERE name=?
    |     1 |
    |-------|
    | admin |
  For example:> "SELECT * FROM atf_user  WHERE name='admin'"
2018-01-26 16:11:01,192 org.nutz.dao.impl.sql.run.NutDaoExecutor.printSQL(NutDaoExecutor.java:388) DEBUG - SELECT * FROM atf_role  WHERE name=?
    |     1 |
    |-------|
    | admin |
  For example:> "SELECT * FROM atf_role  WHERE name='admin'"
2018-01-26 16:11:01,200 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:125) ERROR - Error happend during start serivce!
java.lang.NullPointerException
	at net.wendal.nutzbook.service.AuthorityServiceImpl.checkBasicRoles(AuthorityServiceImpl.java:29)
	at net.wendal.nutzbook.MainSetup.init(MainSetup.java:46)
	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:4689)
	at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5329)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1407)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1397)
	at java.util.concurrent.FutureTask.run(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)
2018-01-26 16:11:01,203 org.nutz.mvc.impl.NutLoading.load(NutLoading.java:127) ERROR - try to depose ioc
2018-01-26 16:11:01,206 org.nutz.ioc.impl.NutIoc.depose(NutIoc.java:255) INFO  - org.nutz.ioc.impl.NutIoc@1130996368 is closing. startup date [18-01-26 16:10:59.219]
2018-01-26 16:11:01,206 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'authorityService' ...
2018-01-26 16:11:01,207 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'jobFactory' ...
2018-01-26 16:11:01,207 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'scheduler' ...
2018-01-26 16:11:01,207 org.quartz.core.QuartzScheduler.shutdown(QuartzScheduler.java:694) INFO  - Scheduler NutzbookScheduler_$_NON_CLUSTERED shutting down.
2018-01-26 16:11:01,207 org.quartz.core.QuartzScheduler.standby(QuartzScheduler.java:613) INFO  - Scheduler NutzbookScheduler_$_NON_CLUSTERED paused.
2018-01-26 16:11:01,207 org.quartz.simpl.SimpleThreadPool.shutdown(SimpleThreadPool.java:328) DEBUG - Shutting down threadpool...
2018-01-26 16:11:01,207 org.quartz.simpl.SimpleThreadPool.shutdown(SimpleThreadPool.java:395) DEBUG - Shutdown of threadpool complete.
2018-01-26 16:11:01,207 org.quartz.core.QuartzScheduler.shutdown(QuartzScheduler.java:771) INFO  - Scheduler NutzbookScheduler_$_NON_CLUSTERED shutdown complete.
2018-01-26 16:11:01,207 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'nutQuartzCronJobFactory' ...
2018-01-26 16:11:01,207 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'conf' ...
2018-01-26 16:11:01,208 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:108) DEBUG - Depose object 'dao' ...
2018-01-26 16:11:01,208 org.nutz.ioc.impl.ScopeContext.clear(ScopeContext.java:113) DEBUG - Depose object 'dataSource' ...
一月 26, 2018 4:11:01 下午 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:4689)
	at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5329)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1407)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1397)
	at java.util.concurrent.FutureTask.run(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.NullPointerException
	at net.wendal.nutzbook.service.AuthorityServiceImpl.checkBasicRoles(AuthorityServiceImpl.java:29)
	at net.wendal.nutzbook.MainSetup.init(MainSetup.java:46)
	at org.nutz.mvc.impl.NutLoading.evalSetup(NutLoading.java:274)
	at org.nutz.mvc.impl.NutLoading.load(NutLoading.java:121)
	... 15 more

一月 26, 2018 4:11:01 下午 org.apache.catalina.core.StandardContext startInternal
严重: One or more Filters failed to start. Full details will be found in the appropriate container log file
一月 26, 2018 4:11:01 下午 org.apache.catalina.core.StandardContext startInternal
严重: Context [/demo] startup failed due to previous errors
2018-01-26 16:11:01,261 com.alibaba.druid.pool.DruidDataSource.close(DruidDataSource.java:1444) INFO  - {dataSource-1} closed
2018-01-26 16:11:01,262 org.nutz.ioc.impl.NutIoc.depose(NutIoc.java:262) INFO  - org.nutz.ioc.impl.NutIoc@1130996368 is deposed. startup date [18-01-26 16:10:59.219]
一月 26, 2018 4:11:01 下午 org.apache.catalina.core.ApplicationContext log
信息: Cleaning up Shiro Environment
一月 26, 2018 4:11:01 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesJdbc
警告: The web application [demo] 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.
一月 26, 2018 4:11:01 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesJdbc
警告: The web application [demo] registered the JDBC driver [oracle.jdbc.OracleDriver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
一月 26, 2018 4:11:01 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
警告: The web application [demo] appears to have started a thread named [NutzbookScheduler_Worker-1] 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)
 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
一月 26, 2018 4:11:01 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
警告: The web application [demo] appears to have started a thread named [NutzbookScheduler_Worker-2] 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)
 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
一月 26, 2018 4:11:01 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
警告: The web application [demo] appears to have started a thread named [NutzbookScheduler_Worker-3] 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)
 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568)
一月 26, 2018 4:11:01 下午 org.apache.coyote.AbstractProtocol start
信息: Starting ProtocolHandler ["http-nio-8080"]
一月 26, 2018 4:11:01 下午 org.apache.coyote.AbstractProtocol start
信息: Starting ProtocolHandler ["ajp-nio-8009"]
一月 26, 2018 4:11:01 下午 org.apache.catalina.startup.Catalina start
信息: Server startup in 7613 ms
2018-01-26 16:11:01,563 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:612) DEBUG - WorkerThread is shut down.
2018-01-26 16:11:01,563 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:612) DEBUG - WorkerThread is shut down.
2018-01-26 16:11:01,563 org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:612) DEBUG - WorkerThread is shut down.

注入了
@管理员(admin)
我在3楼贴了代码 然后也加上了@IocBean(name="authorityService")

加上了
@管理员(admin)

package net.wendal.nutzbook.service;

import java.util.List;

import org.nutz.dao.Chain;
import org.nutz.dao.Cnd;
import org.nutz.dao.Dao;
import org.nutz.dao.entity.Record;
import org.nutz.ioc.loader.annotation.Inject;
import org.nutz.ioc.loader.annotation.IocBean;

import net.wendal.nutzbook.bean.Permission;
import net.wendal.nutzbook.bean.Role;
import net.wendal.nutzbook.bean.User;

@IocBean(name="authorityService")
public class AuthorityServiceImpl implements AuthorityService {
	@Inject
	protected Dao dao;

	@Override
	public void checkBasicRoles(User admin) {
		// 检查一下admin的权限
		Role adminRole = dao.fetch(Role.class, "admin");
		if (adminRole == null) {
			adminRole = addRole("admin");
		}
		// admin账号必须存在与admin组
		if (0 == dao.count("t_user_role",
				Cnd.where("u_id", "=", admin.getId()).and("role_id", "=", adminRole.getId()))) {
			dao.insert("t_user_role", Chain.make("u_id", admin.getId()).add("role_id", adminRole.getId()));
		}
		// admin组必须有authority:* 也就是权限管理相关的权限
		List<Record> res = dao.query("t_role_permission", Cnd.where("role_id", "=", adminRole.getId()));
		OUT: for (Permission permission : dao.query(Permission.class,
				Cnd.where("name", "like", "authority:%").or("name", "like", "user:%"), null)) {
			for (Record re : res) {
				if (re.getInt("permission_id") == permission.getId())
					continue OUT;
			}
			dao.insert("t_role_permission",
					Chain.make("role_id", adminRole.getId()).add("permission_id", permission.getId()));
		}
		;
	}

	@Override
	public void initFormPackage(String pkg) {
		// TODO Auto-generated method stub

	}

	@Override
	public void addPermission(String permission) {
		// TODO Auto-generated method stub

	}

	@Override
	public Role addRole(String role) {
		// TODO Auto-generated method stub
		return null;
	}
}

@wendal没有改名字