log4net阻塞问题

最近在使用log4net记录日志的时候,碰到一个阻塞问题,即某个看起来毫不相干的事件会导致程序不再打印日志,并且该日志文件提示被占用,无法删除和修改,同时报出了以下异常:

ERROR Failed to append to appender [MyAppender]

System.Threading.ThreadAbortException: 正在中止线程。

  在 System.Threading.Monitor.ReliableEnter(Object obj, Boolean& lockTaken)

  在 log4net.Appender.AppenderSkeleton.DoAppend(LoggingEvent loggingEvent)

  在 log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(LoggingEvent loggingEvent)

ERROR Exception while logging

System.Threading.ThreadAbortException: 正在中止线程。

  在 log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(LoggingEvent loggingEvent)

  在 log4net.Repository.Hierarchy.Logger.CallAppenders(LoggingEvent loggingEvent)

  在 log4net.Repository.Hierarchy.Logger.ForcedLog(Type callerStackBoundaryDeclaringType, Level level, Object message, Exception exception)

  在 log4net.Repository.Hierarchy.Logger.Log(Type callerStackBoundaryDeclaringType, Level level, Object message, Exception exception)


于是问题来了:

1、我们配置的是最小锁,按道理不应该无法释放文件

2、看了log4的源码,这个异常应该是能够catch到的,但是为什么会一直往上抛

3、线程内的异常抛到了线程外,为什么没有导致程序崩溃

由于MyAppender是我开发的,用来提供压缩日志功能,因此一开始以为是这个我的appender存在bug。但是检查一遍之后并没有发现有什么问题。转了一圈log4net社区之后也没有发现有人提到这样的问题。遂只能看下调用方的使用方式,于是发现了调用方的一个奇怪操作。

调用方在进行某个事件时,会不停的创建线程,并且没有让线程自然结束,而是使用了Abort()方法强制结束线程。然后来看下微软对abort方法的说明:

Remarks

When this method is invoked on a thread, the system throws a ThreadAbortException in the thread to abort it. ThreadAbortException is a special exception that can be caught by application code, but is re-thrown at the end of the catchblock unless ResetAbort is called. ResetAbort cancels the request to abort, and prevents the ThreadAbortException from terminating the thread. Unexecuted finally blocks are executed before the thread is aborted.

可以看到,这个abort()的方法并不是直接使线程停止,而是通过在线程内抛出异常来达到线程中断的目的,并且这个异常是个特殊异常,虽然可以被捕获,但是依然会上抛到线程外,并且不会被全局异常捕获,这也解释了问题2和3。

 Note

When a thread calls Abort on itself, the effect is similar to throwing an exception; the ThreadAbortException happens immediately, and the result is predictable. However, if one thread calls Abort on another thread, the abort interrupts whatever code is running. 

在调用了abort方法后,除非线程在执行非托管代码,否则线程将立刻抛出异常。那么对写文件来说,就将存在刚把文件打开,这个线程就被终止了,或者说刚写完文件,还没来得及释放就被终止了的情况。这个很容易证明:

Thread th=new Thread(() =>

            {

                    FileStream file = File.Open(@"TestLog4net.txt",FileMode.Open);

                    Thread.Sleep(2000);

            });

            th.Start();

            Thread.Sleep(1000);

            th.Abort();


这时候TestLog4net.txt这个文件将提示被占用。当然,由于这个异常时可以捕获的,因此完全可以通过try-catch-finally来释放文件。但是在log4net里面,有个:

override protected void Append(LoggingEvent loggingEvent)

{

if (m_stream.AcquireLock())

{

try

{

base.Append(loggingEvent);

}

finally

{

m_stream.ReleaseLock();

}

}

}


可以看到,这个AcquireLock()并没有在try-catch中,而正是在这个方法中打开了文件流,并只有在ReleaseLock()中才会释放掉。因此如果在AcquireLock()执行时中断了线程,那么问题1就发生了。

这种占用,除了上面说的在try-catch块中解决,还可以通过调用GC的方式让他进行回收。


结论:

1、abort()是个很危险的方法,因为你不知道线程什么时候被终止,无法清理数据。如果想让线程中断,尽量使用信号量等方式来让线程正常结束。

2、在使用第三方的库的时候,最好能够做线程隔离,或者尽量不要在他们的线程中做太多操作,因为你不知道他们会有什么骚操作。

最后我们通过线程池来异步写文件来避免这个坑。

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 204,921评论 6 478
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 87,635评论 2 381
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 151,393评论 0 338
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,836评论 1 277
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,833评论 5 368
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,685评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 38,043评论 3 399
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,694评论 0 258
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 42,671评论 1 300
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,670评论 2 321
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,779评论 1 332
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,424评论 4 321
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 39,027评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,984评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,214评论 1 260
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 45,108评论 2 351
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,517评论 2 343

推荐阅读更多精彩内容