NHibernate的调试技巧和Log4Net配置
对新手而言NHibernate的调试事件很痛苦的事情,不知道NHibernate做了些什么,错误出现在什么地方。
我给出一些常用的调试办法希望对你有所帮助。
1.查看NHibernate写在控制台里的Sql语句
在配置文件中有这么个选项,如果把它设置为true,NHibernate会把执行的Sql显示在控制台上。
对于控制台应用程序我们可以设置断点后很轻松的看到NHibernate执行了什么Sql。
下图是从数据库中读取一条数据。
如果你写了单元测试,从NUnit同样可以很容易地看到。
2.配置Log4net来查看NHibernate留下的日志
如果你的程序是Asp.Net程序。那就看不到控制台信息了。那么就使用第二招配置Log4net。
按习惯,我还是使用单独的配置文件。当然你也可以配置在应用程序配置文件中(App.config或Web.Config)。
<log4net>
<appender name="rollingFile" type="log4net.Appender.RollingFileAppender,log4net" >
<param name="File" value="log.txt" />
<param name="AppendToFile" value="false" />
<param name="RollingStyle" value="Date" />
<param name="DatePattern" value="yyyy.MM.dd" />
<param name="StaticLogFileName" value="true" />
<layout type="log4net.Layout.PatternLayout,log4net">
<param name="ConversionPattern" value="%d [%t] %-5p %c [%x] <%X{auth}> - %m%n" />
</layout>
</appender>
<root>
<!--如果只需要看看Sql设置INFO就够了,如果你要调试可以设置为DEBUG或ALL-->
<priority value="INFO" />
<appender-ref ref="rollingFile" />
</root>
</log4net>
读取log4net配置的代码
运行了程序后你可以在应用程序目录找到log.txt的配置文件。里面记录了包括Sql的NHibernate的运行信息。
这是一个日志的片断
2006-08-08 22:22:16,968 [2036] INFO NHibernate.Cfg.Environment [(null)] <(null)> - nhibernate section not found in application configuration file
2006-08-08 22:22:16,968 [2036] INFO NHibernate.Cfg.Environment [(null)] <(null)> - Using reflection optimizer
2006-08-08 22:22:17,000 [2036] INFO NHibernate.Cfg.Configuration [(null)] <(null)> - Searching for mapped documents in assembly: DDLLY.MyDoc.NHibernateTest.Log4NetTest
2006-08-08 22:22:17,000 [2036] INFO NHibernate.Cfg.Configuration [(null)] <(null)> - Found mapping documents in assembly: DDLLY.MyDoc.NHibernateTest.Log4NetTest.User.hbm.xml
2006-08-08 22:22:17,062 [2036] INFO NHibernate.Dialect.Dialect [(null)] <(null)> - Using dialect: NHibernate.Dialect.MsSql2000Dialect
2006-08-08 22:22:17,109 [2036] INFO NHibernate.Cfg.Binder [(null)] <(null)> - Mapping class: DDLLY.MyDoc.NHibernateTest.Log4NetTest.User -> users
2006-08-08 22:22:17,156 [2036] INFO NHibernate.Cfg.Configuration [(null)] <(null)> - Configured SessionFactory: DDLLY.MyDoc.NHibernateTest.Log4NetTest
2006-08-08 22:22:17,171 [2036] INFO NHibernate.Cfg.Configuration [(null)] <(null)> - processing one-to-many association mappings
2006-08-08 22:22:17,171 [2036] INFO NHibernate.Cfg.Configuration [(null)] <(null)> - processing one-to-one association property references
2006-08-08 22:22:17,171 [2036] INFO NHibernate.Cfg.Configuration [(null)] <(null)> - processing foreign key constraints
2006-08-08 22:22:17,187 [2036] INFO NHibernate.Dialect.Dialect [(null)] <(null)> - Using dialect: NHibernate.Dialect.MsSql2000Dialect
2006-08-08 22:22:17,187 [2036] INFO NHibernate.Cfg.SettingsFactory [(null)] <(null)> - use outer join fetching: True
2006-08-08 22:22:17,187 [2036] INFO NHibernate.Connection.ConnectionProviderFactory [(null)] <(null)> - Intitializing connection provider: NHibernate.Connection.DriverConnectionProvider
2006-08-08 22:22:17,187 [2036] INFO NHibernate.Connection.ConnectionProvider [(null)] <(null)> - Configuring ConnectionProvider
2006-08-08 22:22:17,187 [2036] INFO NHibernate.Cfg.SettingsFactory [(null)] <(null)> - Optimize cache for minimal puts: False
2006-08-08 22:22:17,203 [2036] INFO NHibernate.Cfg.SettingsFactory [(null)] <(null)> - echoing all SQL to stdout
2006-08-08 22:22:17,203 [2036] INFO NHibernate.Cfg.SettingsFactory [(null)] <(null)> - Query language substitutions: {false=0, no='N', yes='Y', true=1}
2006-08-08 22:22:17,203 [2036] INFO NHibernate.Cfg.SettingsFactory [(null)] <(null)> - cache provider: NHibernate.Cache.HashtableCacheProvider
2006-08-08 22:22:17,203 [2036] INFO NHibernate.Cfg.Configuration [(null)] <(null)> - instantiating and configuring caches
2006-08-08 22:22:17,218 [2036] INFO NHibernate.Impl.SessionFactoryImpl [(null)] <(null)> - building session factory
2006-08-08 22:22:17,812 [2036] INFO NHibernate.Impl.SessionFactoryObjectFactory [(null)] <(null)> - Factory name:DDLLY.MyDoc.NHibernateTest.Log4NetTest
2006-08-08 22:22:17,859 [2036] INFO NHibernate.Loader.Loader [(null)] <(null)> - SELECT user0_.Id as Id0_, user0_.Email as Email0_, user0_.UserName as UserName0_, user0_.Password as Password0_ FROM users user0_ WHERE user0_.Id=@p0
从这个文件我们可以看到NHibernate都做了些什么(包括执行了什么Sql,看上面的最后一行)。
当你想更详细的信息可以把priority设置为ALL,这样可以看到所有信息。
提示:NHibernate会把一般信息记录为INFO,调试信息记录为Debug,错误信息记录为Error。
Log4Net中支持多个appender你可以也把日志记录到数据库等其他地方,请参看Log4Net的文档,这里不做讲解。
3.让NHibernate的日志不影响你使用Log4Net写日志
NHibernate总是会调用配置<root>里面的“appender-ref”来写配置。
所以如果你系统本省也使用了Log4Net记录日志,而不想让NHibernate的日志影响,则可以定义logger。
<log4net>
<root>
<!--如果只需要看看Sql设置INFO就够了,如果你要调试可以设置为DEBUG或ALL-->
<priority value="INFO" />
<appender-ref ref="rollingFile" />
</root>
<logger name="ApplicationInfoLog">
<level value="INFO" />
<appender-ref ref="rollingFile1" />
</logger>
<appender name="rollingFile" type="log4net.Appender.RollingFileAppender,log4net" >
<param name="File" value="log.txt" />
<param name="AppendToFile" value="false" />
<param name="RollingStyle" value="Date" />
<param name="DatePattern" value="yyyy.MM.dd" />
<param name="StaticLogFileName" value="true" />
<layout type="log4net.Layout.PatternLayout,log4net">
<param name="ConversionPattern" value="%d [%t] %-5p %c [%x] <%X{auth}> - %m%n" />
</layout>
</appender>
<appender name="rollingFile1" type="log4net.Appender.RollingFileAppender,log4net" >
<param name="File" value="log1.txt" />
<param name="AppendToFile" value="false" />
<param name="RollingStyle" value="Date" />
<param name="DatePattern" value="yyyy.MM.dd" />
<param name="StaticLogFileName" value="true" />
<layout type="log4net.Layout.PatternLayout,log4net">
<param name="ConversionPattern" value="%d [%t] %-5p %c [%x] <%X{auth}> - %m%n" />
</layout>
</appender>
</log4net>
日志记录代码
applicationInfoLog.Info("记录日志");
此例中NHibernater日志会存在log.txt,系统日志记录在log1.txt。
4.在使用SqlServer时使用事件查看器监视Sql
对于SqlServer数据库,如果你没有条件可以完成上面的功能,那么你可以使用事件查看器来监视执行的Sql,使用比较简单,不多说了。