Enterprise Library Logging存在延时问题
Enterprise Library是微软 Patterns & Practices 项目组推出的公共模块解决方案,用来解决我们在企业级开发中遇到公共问题,如配置管理、数据访问、缓存管理、记录操作日志、异常管理、加密解密、权限管理 等。
无意中,我们发现了它的Enterprise Library Logging模块有一个问题(不知道算不算bug),每当程序调用Enterprise Library Logging写日志,会向因特网发送请求(网址是:crl.microsoft.com),而如果此时服务器不能访问外网,它会等待将近15秒才继续往下执行!如果服务器能访问外网,此问题就不会存在了!
如果实在不想使服务器访问外网,可以在windows目录 里的host文件里加入以下的映射:
127.0.0.1 crl.microsoft.com
------------------------------------------------
下面是测试代码:
下面代码片段:
Console.WriteLine("Start write log: " + DateTime.Now);
var logent = new LogEntry();
logent.Categories.Add(logCategory);
logent.Priority = logLevel;
logent.Message = msg;
logent.TimeStamp = DateTime.Now;
logent.Title = LogCaller;
if (!string.IsNullOrEmpty(managedThreadName))
logent.ManagedThreadName = managedThreadName;
if (!string.IsNullOrEmpty(AppName))
logent.ExtendedProperties.Add("AppName", AppName);
Logger.Write(logent);
Console.WriteLine("End write log: " + DateTime.Now);
执行结果:
Start write log: 1/13/2011 11:37:17 PM
End write log: 1/13/2011 11:37:32 PM
下面是国外某个博客的测试情况及详细解决方案:
This is the Netmon output:
_____________________________________________________________________________________
111 5.019387 DNS DNS: QueryId = 0xAEAE, QUERY
(Standard query), Query for crl.microsoft.com
of type Host Addr on class Internet
112 5.024270 DNS DNS: QueryId = 0xAEAE, QUERY (Standard
query), Response - Server failure
113 5.024270 DNS DNS: QueryId = 0xAEAE, QUERY (Standard
query), Query for crl.microsoft.com of type Host Addr on class
Internet
123 6.024270 DNS DNS: QueryId = 0xAEAE, QUERY (Standard
query), Query for crl.microsoft.com of type Host Addr on class Internet
124 6.024270 DNS DNS: QueryId = 0xAEAE, QUERY (Standard
query), Response - Server failure
125 6.024270 DNS DNS: QueryId = 0xAEAE, QUERY (Standard
query), Query for crl.microsoft.com of type Host Addr on class Internet
126 6.024270 DNS DNS: QueryId = 0xAEAE, QUERY (Standard
query), Query for crl.microsoft.com of type Host Addr on class Internet
127 6.024270 DNS DNS: QueryId = 0xAEAE, QUERY (Standard
query), Query for crl.microsoft.com of type Host Addr on class Internet
128 6.024270 DNS DNS: QueryId = 0xAEAE, QUERY (Standard
query), Query for crl.microsoft.com of type Host Addr on class Internet
129 6.024270 DNS DNS: QueryId = 0xAEAE, QUERY (Standard
query), Response - Server failure
130 6.024270 DNS DNS: QueryId = 0xAEAE, QUERY (Standard
query), Response - Server failure
131 6.024270 DNS DNS: QueryId = 0xAEAE, QUERY (Standard
query), Response - Server failure
184 10.024270 DNS DNS: QueryId = 0xAEAE, QUERY (Standard
query), Query for crl.microsoft.com of type Host Addr on class Internet
227 14.025102 DNS DNS: QueryId = 0xB6AF, QUERY (Standard
query), Query for crl.microsoft.com.myorg.com of type Host Addr on
class Internet
228 14.030961 DNS DNS: QueryId = 0xB6AF, QUERY (Standard
query), Response - Name Error
229 14.030961 DNS DNS: QueryId = 0xBFAC, QUERY (Standard
query), Query for crl.microsoft.com.myorg.com of type Host Addr on
class Internet
230 14.035844 DNS DNS:
QueryId = 0xBFAC, QUERY (Standard query), Response - Name Error
_____________________________________________________________________________________
Notice how the DNS
requests for "crl.microsoft.com" took almost 9 seconds !
This was very funny, so we googled for this symptom.
Internet research
shows these results:
Support Certificates
In Your Applications With The .NET Framework 2.0:
http://msdn.microsoft.com/msdnmag/issues/07/03/NETSecurity/default.aspx
Microsoft, VeriSign, and Certificate Revocation:
http://amug.org/~glguerin/opinion/revocation.html
How Office Performs Certificate Revocation:
http://office.microsoft.com/en-us/ork2003/HA011403081033.aspx
This one is talking about IE slowness:
http://www.wilderssecurity.com/archive/index.php/t-47121.html
Management Studio slowness:
http://weblogs.sqlteam.com/tarad/archive/2006/10/05/13676.aspx
http://blogs.msdn.com/dtjones/archive/2006/08/23/714738.aspx
talking about the
similar symptoms, only when using MS SQL Management Studio.
The cause of the problem is the same…
FAQ, Why does SSMS
take 45s to start up?
http://blogs.msdn.com/euanga/archive/2006/07/11/662053.aspx
Why does the .NET Runtime Optimization Service keep trying to use the
internet:
http://forums.microsoft.com/MSDN/ShowPost.aspx?PostID=522726&SiteID=1
so, what have we
got here?
It seems that Microsoft added a mechanism to the .Net CLR that checks
every signed assembly when loading it
against an online revocation list.
When working in an intranet environment with IP segments
that are no defined as local Intranet, the mechanism is trying to
locate the crl server for 9 seconds before it
gives up, delaying the assembly loading.
When checking the Enterprise Library Common assembly,
We see that is indeed signed using a Microsoft Certificate:
How do we work around
it you say ?
Well, there are several options.
The easiest one is to disable the crl check. Oddly it is done from the
Internet Options dialog available from Internet Explorer:
Now, let's run our
test program again:
Running the program after removing the check:
__________________________
Started at:22/07/2007 18:17:47
Before Work at:22/07/2007 18:17:47
After Work at:22/07/2007 18:17:47
Total Time elapsed(Milliseconds):147
Ended at:22/07/2007 18:17:47
Press any key to exit...
__________________________
Notice
that this time we are down to a total of 147 milliseconds, which is
much more reasonable.
What about the netmon output ? Well, since there is no check
Netmon output is empty !
What about security you say?
If you are canceling the crl check, you are exposed to bogus
certifications.
My answer to that is: If you are already disconnected from the
Internet,
then you are just exposed as before, only this time you are not slowing
down your applications for nothing.
A questions might be asked about situations where Internet connection
is partly available through a firewall.
In this situation you might consider asking the network administrator
to allow connections to the crl server,
or if you which, make it fail the requests immediately, so you don't
need to configure the Internet Options for every node.
Another optional workaround is to define the crl address in the
etc/hosts file pointing it to localhost (127.0.0.1),
which will quickly fail every crl request it gets.
Let's run our test again, this time without removing the revocation
check, but defining the crl address in the hosts file:
Running the program after redirecting the dns name to localhost:
___________________________
Started at:22/07/2007 18:18:37
Before Work at:22/07/2007 18:18:37
After Work at:22/07/2007 18:18:37
Total Time elapsed(Milliseconds):219
Ended at:22/07/2007 18:18:37
Press any key to exit...
___________________________
Notice that
this time we are using 219 milliseconds, which is a bit more then the
first workaround, but still reasonable.
What about the netmon output? Well, since there is no outside
communication
Netmon output is empty in this case too!
Conclusion:
When working with
signed assemblies having no Internet connection to crl.microsoft.com,
you need to consider the loading delay time for the assemblies, or work
around them as suggested above.