1 Topic by dummzeuch

  • dummzeuch
  • Guest

Topic: another timing issue

Hi,

I have got, what I think is another timing issue, even when writing to a file rather than to a socket.

My application is using multiple threads and writes quite a few log messaes (maybe too many but it worked with our old logging system). When logging is turned off, everything works fine. When I turn on logging, I am losing data (the app is acquiring data from a video camera using DirectShow).

Without having looked at the code: Does it use a separate thread for writing the file? If yes, how does is pass the log message to this thread? Is it possible that a thread gets put to sleep during a call to log a message?

Will the promised bugifx also fix this issue?

twm

2 Reply by tgurock

  • tgurock
  • Administrator
  • Offline
  • Registered: 2009-07-09
  • Posts: 628

Re: another timing issue

Hi,

SmartInspect (and actually any other logging framework) can somewhat change the threading behavior of your application. When logging is enabled, your application takes different code paths and may thus behave differently. And, in order to be thread-safe, SmartInspect needs to use locks/critical sections, which naturally may further influence the threading behavior.

SmartInspect does currently not use a dedicated thread for writing the logging data (SmartInspect 3.0 will have an option to do this). What you might see in your specific case is, that when a thread writes a log message to a file, another thread of your application may be scheduled since the first thread can be blocked while doing the I/O operation. This may then result in the problem you have described.

A fix to this problem would be to add some kind of asynchronous I/O handling/logging which we are working on for SmartInspect 3.0.

3 Reply by dummzeuch

  • dummzeuch
  • Guest

Re: another timing issue

Tobias Gurock wrote:


SmartInspect (and actually any other logging framework) can somewhat change the threading behavior of your application. When logging is enabled, your application takes different code paths and may thus behave differently.

Yes, I am aware of that. I merely wanted to know how much.

And, in order to be thread-safe, SmartInspect needs to use locks/critical sections,

Not necessarily. There are lock free datastructures which work without them. e.g. see my post in the delphi forum: http://www.delphi-forum.de/viewtopic.php?t=81264

(The code I posted there was originally developed to make our home grown logging system thread safe, but I decided that I'd rather pay some people (you) who have shown they know something about logging and also I rather liked your log viewer.)

SmartInspect does currently not use a dedicated thread for writing the logging data (SmartInspect 3.0 will have an option to do this). What you might see in your specific case is, that when a thread writes a log message to a file, another thread of your application may be scheduled since the first thread can be blocked while doing the I/O operation. This may then result in the problem you have described.

A fix to this problem would be to add some kind of asynchronous I/O handling/logging which we are working on for SmartInspect 3.0.

Hm, I guess I'll have to get my logging thread using the code I linked above to work then. Unless SmartInspect 3 is about to be released next week...

btw: Feel free to use the code and adapt it to your needs, if you like the approach. But beware: It hasn't been tested very thoroughly.

twm

4 Reply by tgurock

  • tgurock
  • Administrator
  • Offline
  • Registered: 2009-07-09
  • Posts: 628

Re: another timing issue

I'm aware of lock-free data structures, but they are usually only applicable to very specific problems which are not really present in the SmartInspect libraries. For instance, consider the core of the SmartInspect class which is, among other things, responsible for managing/creating the connections, connecting, disconnecting and writing the log packets. We need to take care that even if multiple threads try to simultaneously change the connections string, the enabled status or write one or more log packets, the SmartInspect class handles this correctly. Without using locks, this would be, I guess, nearly impossible to get right.

We haven't decided on the SmartInspect 3.0 release date yet, but it won't make it this month. I am preparing a blog series on some upcoming SmartInspect features in which I can probably give a few more details about a release date.

I'm sorry to hear that this problem is preventing you from using SmartInspect but fixing/minimizing this particular issue unfortunately takes some time. Implementing support for asynchronous I/O handling/logging is quite complex in a feature-rich framework such as SmartInspect. Also, I would like to point out once more that all logging frameworks somewhat change the threading behavior and the particular situation you have described cannot be prevented altogether but merely reduced/minimized. To minimize this problem, SmartInspect 3.0 will introduce a new asynchronous protocol option which allows to move the (potentially blocking) I/O operations to a different (possibly lower-priority) thread.