Opened 6 years ago

Closed 6 years ago

#1631 closed defect (done)

ThreadSafeLog doesn't work with LogView

Reported by: ascheibe Owned by: ascheibe
Priority: medium Milestone: HeuristicLab 3.3.6
Component: Core Version: 3.3.6
Keywords: Cc:

Description

The HiveEngine uses a ThreadSafeLog together with the LogView. If a message is added to the ThreadSafeLog, it aquires a WriteLock, and uses the standard Log for logging. Log fires the MessageAdded event before ThreadSafeLog releases the WriteLock. The LogView tries to aquire a ReadLock on MessageAdded which leads to the exception:

System.Threading.LockRecursionException: A read lock may not be acquired with the write lock held in this mode.

Change History (16)

comment:1 follow-up: Changed 6 years ago by abeham

I think there's also a bug in the cloning constructor as stated in an earlier mail. Maybe you could look into this as well.

comment:2 in reply to: ↑ 1 Changed 6 years ago by ascheibe

Replying to abeham: I tried your unit test with the fix suggested by you and i also tried cloning a ThreadSafeLog "manually". It works perfectly, i will commit it to trunk.

comment:3 Changed 6 years ago by ascheibe

r6705 fixed cloning bug in ThreadSafeLog

comment:4 Changed 6 years ago by ascheibe

I think there are 3 ways to fix this bug:

  • Rewrite LogView's Content_MessageAdded(..) method so that it doesn't access the messages directly but instead uses the EventArgs to append the messages to the TextBox.
  • Inherit ThreadSafeLog from Log and override the LogMessage(..) method. In this way the event could be fired after the lock is released.
  • Remove ThreadSafeLog and make Log thread-safe.

The first option would be the easiest way, but I think the second way is better because the user of ThreadSafeLog probably expects that the messages can be accessed after a MessageAdded event is fired. On the other hand this would mean that you can't really wrap a Log in a ThreadSafeLog anymore.

comment:5 Changed 6 years ago by ascheibe

  • Status changed from new to assigned

comment:6 Changed 6 years ago by abeham

To be honest, I like neither solution. Here's why:

  1. If you expose the log message in the EventArg you'll still get an exception when you access Messages.
  2. It doesn't help that you inherit from ThreadSafeLog and override LogMessage, because it can happen that another call to LogMessage occurs before the notified class access Messages.
  3. Making Log thread safe could be an option, but the performance penalty would need to be evaluated first. In which conditions is Log used and can they accept a lower performance?

To fix ThreadSafeLog I would suggest to call TryEnterReadLock with probably infinite timeout in the call to Messages and block until the read lock can be acquired.

comment:7 Changed 6 years ago by ascheibe

r6862 inherited ThreadSafeLog from Log to fix the LockRecursionException problem

comment:8 Changed 6 years ago by ascheibe

I have also added a unit test to demostrate and test the problem with ThreadSafeLog and LogView. I think everything should work fine now. One little problem which could occur is that the order in which the MessageAdded events are fired could be wrong. The solution would be to make the Log methods additionally threadsafe but i think thats an overkill?

comment:9 Changed 6 years ago by ascheibe

  • Owner changed from ascheibe to abeham
  • Status changed from assigned to reviewing

comment:10 follow-up: Changed 6 years ago by abeham

  • Owner changed from abeham to ascheibe
  • Status changed from reviewing to assigned

I reviewed the changes:

  • I would rather put the lock in the Clone() override than in the cloning constructor and have the cloning constructor call the base class' cloning constructor as usual. Otherwise cloning will break should Log or Item get a new cloneable property.
  • I would propose to make the class sealed and change the protected modifiers to private.
  • There's no need to implement IDeepCloneable yet again (in the class declaration) as Item and therefor Log already implement IDeepCloneable.
  • (I find it nicer to put the finally block on the same line as the closing brace.)

Not related to these changes, but I think Log isn't a very fast implementation. It should actually use a LinkedList<T> instead of a List<T>. Correct me if I am wrong, but it seems that it is only performing operations at the ends of the list.

Last edited 6 years ago by abeham (previous) (diff)

comment:11 in reply to: ↑ 10 Changed 6 years ago by gkronber

Replying to abeham:

It should actually use a LinkedList<T> instead of a List<T>. Correct me if I am wrong, but it seems that it is only performing operations at the ends of the list.

List<T>.Add is an O(1) operation. I do not see a problem.

In the .NET framework LinkedList<T> is implemented as a doubly linked list to make appending also O(1) (AddLast(n)). But I think List<T> is perfectly fine we should not change that.

comment:12 Changed 6 years ago by ascheibe

r7113 implemented review comments for ThreadSafeLog

Last edited 6 years ago by ascheibe (previous) (diff)

comment:13 Changed 6 years ago by ascheibe

  • Owner changed from ascheibe to abeham
  • Status changed from assigned to reviewing

comment:14 Changed 6 years ago by abeham

Thanks!

@gkronber: Yes Add isn't really the problem, but if you look at CapMessages it uses RemoveAt(0) which is O(N). So, adding messages to the log is O(1) as long as there's no cap, but when it's full adding log messages becomes an O(N) operation. That's probably more of a theoretical issue right now (I don't know to what extent people are using Log), but I thought to mention it as part of the code review.

comment:15 Changed 6 years ago by abeham

  • Owner changed from abeham to ascheibe
  • Status changed from reviewing to readytorelease

comment:16 Changed 6 years ago by swagner

  • Resolution set to done
  • Status changed from readytorelease to closed
  • Version changed from 3.3.5 to 3.3.6
Note: See TracTickets for help on using tickets.