前些日子,我们的NHibernateQQ群上,一位老兄(未征求其同意,不好透露他的信息)碰到了一个问题:NHibernate映射Blob字段(他用Binary映射SQL Server的Image类型,用来存储文件),当处理的文件大小比较大的时候(大于 10M )速度就极慢了,不能忍受。呼吁我们一起解决这个问题。
我先作了一个不用NHibernate的程序:
数据表:
CREATE TABLE [dbo].[FileBlob] (
[FileID] [int] IDENTITY (1, 1) NOT NULL ,
[FileName] [varchar] (255) COLLATE Chinese_PRC_CI_AS NOT NULL ,
[CreateTime] [smalldatetime] NOT NULL ,
[Stream] [image] NULL
) ON [PRIMARY] TEXTIMAGE_ON [PRIMARY]
数据插入:
public FileBlob Add(FileBlob blob)
{
SqlConnection conn=new SqlConnection(m_ConnectionString);
conn.Open();
SqlCommand cmd=conn.CreateCommand();
string sql="Insert Into FileBlob(FileName,CreateTime,Stream) "+
"Values(@FileName,@CreateTime,@Stream);"+
"Select Scope_Identity()";
cmd.CommandText=sql;
cmd.Parameters.Add("@FileName",blob.FileName);
cmd.Parameters.Add("@CreateTime",blob.CreateTime);
cmd.Parameters.Add("@Stream",SqlDbType.Image,blob.Stream.Length,"Stream");
if(blob.Stream==null)
{
cmd.Parameters["@Stream"].Value=DBNull.Value;
}
else
{
cmd.Parameters["@Stream"].Value=blob.Stream;
}
object id=cmd.ExecuteScalar();
conn.Close();
return Get(int.Parse(id.ToString()));
}
数据获取:
public FileBlob Get(int id)
{
SqlConnection conn=new SqlConnection(m_ConnectionString);
conn.Open();
SqlCommand cmd=conn.CreateCommand();
string sql="Select * from FileBlob Where FileID=@FileID";
cmd.CommandText=sql;
cmd.Parameters.Add("@FileID",id);
SqlDataReader reader=cmd.ExecuteReader();
if(reader.Read())
{
FileBlob blob=new FileBlob();
blob.ID=int.Parse(reader["FileID"].ToString());
blob.FileName=reader["FileName"].ToString();
blob.CreateTime=DateTime.Parse(reader["CreateTime"].ToString());
if(reader["Stream"]!=DBNull.Value)
{
blob.Stream=reader["Stream"] as byte[];
}
reader.Close();
return blob;
}
else
{
reader.Close();
conn.Close();
return null;
}
}
用SqlCommand进行标准的(当然是相对于NHibernate来说)进行数据访问,测试数据如下:
测试文件 | aaa.rar 17.0 MB |
插入 | |
次数 | 时间(秒) |
第1次 | 2.07 |
第2次 | 1.73 |
第3次 | 2.64 |
第4次 | 1.57 |
第5次 | 1.95 |
平均 | 1.992 |
获取 | |
次数 | 时间(秒) |
第1次 | 0.093 |
第2次 | 0.109 |
第3次 | 0.171 |
第4次 | 0.109 |
第5次 | 0.172 |
平均 | 0.1308 |
可见,直接使用SqlCommand进行Blog类型的数据访问性能是不错的。
那么接下来,我使用NHibernate进行同样的测试:
数据持久化类:
[ClassAttribute("FileBlob")]
public class FileBlob : Persistency
{
private int m_FileID;
private string m_FileName;
private System.DateTime m_CreateTime;
private System.Byte[] m_Stream;
public FileBlob()
{
}
[Id("FileID", "native", "0")]
public new virtual int ID
{
get
{
return this.m_FileID;
}
set
{
this.m_FileID = value;
}
}
[PropertyAttribute("FileName")]
public virtual string FileName
{
get
{
return this.m_FileName;
}
set
{
this.m_FileName = value;
}
}
[PropertyAttribute("CreateTime")]
public virtual System.DateTime CreateTime
{
get
{
return this.m_CreateTime;
}
set
{
this.m_CreateTime = value;
}
}
[PropertyAttribute("Stream")]
public virtual System.Byte[] Stream
{
get
{
return this.m_Stream;
}
set
{
this.m_Stream = value;
}
}
}
映射文件:
<class name="NHibernateBlobTest.FileBlob, NHibernateBlobTest" table="FileBlob">
<id name="ID" type="Int32" column="FileID" access="property" unsaved-value="0">
<generator class="native" />
</id>
<property name="FileName" column="FileName" access="property" type="String" />
<property name="CreateTime" column="CreateTime" access="property" type="DateTime" />
<property name="Stream" type="BinaryBlob">
<column name="Stream" sql-type="Image"></column>
</property>
</class>
测试数据如下:
测试文件 | aaa.rar 17.0 MB |
插入 | |
次数 | 时间(秒) |
第1次 | 28.8 |
第2次 | 26.94 |
第3次 | 16.26 |
第4次 | 18.5 |
第5次 | 14.68 |
平均 | 21.03 |
获取 | |
基本上和死机一样,不必测了,一定有什么地方出问题了 |
解决过程:
提出问题的那个老兄说去看代码找问题,我是很懒的人,看代码对我来说太慢太没效率了。所以决定用更直接的方法,用性能分析工具直接定位性能地下的代码块。
性能分析工具有很多种,比如:Intel的VTune——最近Intel在大力推广,不过我对它没什么好感,从网上下载的7.2版本安装都不成功,7.0版本好不容易安成了,使用时候却老报错。另外呢,还有DevPartner——包括性能分析、代码覆盖率等等测试,我就用它了(以后我会写其它文章具体介绍DevPartner的使用方法)。
首先测试插入问题,我用DevePartner的录制操作过程,然后停止录制后,它会生成一个测试结果,包括整个程序运行调用的源码和引用的Dll的全部方法运行的时间。在结果中我看到,在NHibernate 中的各个方法调用时间都比较正常,反而使Log4Net(NHibernate使用Log4Net进行日志记录,记录NHibernate操作数据的各个步骤)的一个Debug方法运行时间超常。我突然明白了,原来NHibernate用Log4Net记录所有插入的数据,也就是说为的 17M 大小的文件被Log4Net写入的日志。等找到了Log文件,吓我一跳,已经 239M 了,难怪这么慢呢。于是我把App.Config内Log4Net的配置改为不记录任何:
<log4net threshold="OFF">
再次测试插入数据,平局插入时间大约在3~4秒,虽然还是远不及直接用SqlCommand,但是已经有了非常大的提高。
提出问题的那个老兄也发现了数据获取的瓶颈所在:原来,在NHibernate的源代码NHibernate.Type.BinaryType类的Get()方法,有如下代码片断:
MemoryStream outputStream = new MemoryStream(1024);
byte[ ] buffer = new byte[1024];
long fieldOffset = 0;
try
{
while( true )
{
long amountRead = rs.GetBytes( index, fieldOffset, buffer, 0, 1024 );
if( amountRead == 0 )
{
break;
}
fieldOffset += amountRead;
outputStream.Write( buffer, 0, ( int ) amountRead );
}
outputStream.Close();
}
catch( IOException ioe )
{
throw new HibernateException( "IOException occurred reading a binary value", ioe );
}
问题就在这里了,NHibernate用MemoryStream的构造函数分配了它的初始大小1024字节,而我们的测试文件大小是 17M ,那么用这样的大小进行循环,就需要17*1024*1024/1024=17408次,如此大的循环,能不慢么。找到问题了,改起来就容易了,我们修改一下NHibernate的源代码,把MemoryStream不分配初始大小,而每次读取的buffer大小为1024*1024。测试速度发现,每次获取大约在1.5秒以内,提高性能非常巨大(当然比SqlCommand读取到DataReader还是太慢了,为了O/R牺牲一些性能吧)。
结论
NHibernate在性能上还是有些缺陷的,而且目前的版本0.7 Beta还是不是很成熟(当然大部分应用没有问题)。这也可以使我们理解微软在VS2005中放弃ObjectSpaces的原因了。
但是,作为一个坚定的面向对象、领域模型驱动的信仰者,使用事务脚本和表模式的数据访问方式进行业务逻辑构建是我不能接受的,尽管我同意在一些性能要求极高的系统中应当放弃 O/R 。这就要求我们能够更多的参与到开源工程中,不仅仅是使用,更要理解、改进。使我们的设计能够更好的降低软件次要复杂度,让我们更多的精力投入到解决主要复杂度的事情上来。