From: Matthew Bloch <matthew@...>
Date: 2010-04-07T04:53:49+09:00
Subject: Re: More on logger hang-ups



On Tue, 2010-04-06 at 21:33 +0900, Brian Candler wrote:
> Matthew Bloch wrote:
> > --> #0 Debugger.interrupt_last
> >        at
> > line 
> > /usr/lib/ruby/gems/1.8/gems/ruby-debug-base-0.10.3/lib/ruby-debug-base.rb:89
> >     #1 at
> > line /usr/lib/ruby/gems/1.8/gems/ruby-debug-0.10.3/bin/rdebug:351
> >     #2 MonitorMixin.write at line /usr/lib/ruby/1.8/logger.rb:504
> >     #3 Logger::LogDevice.write(message#String)
> >        at line /usr/lib/ruby/1.8/logger.rb:496
> >     #4 MonitorMixin.write at line /usr/lib/ruby/1.8/logger.rb:504
> >     #5 Logger::LogDevice.write(message#String)
> >        at line /usr/lib/ruby/1.8/logger.rb:496
> 
> (1) Note line #4 calling MonitorMixin.write - this seems to imply that 
> @dev *is* a MonitorMixin??

Hmm, yes it wasn't a file, it was another Logger::LogDevice - now
changed to a File...

> (2) It looks like LogDevice.write is calling itself re-entrantly here?

Yup, by mistake, but not the same LogDevice (separate locks).

> Is it possible that you've called Logger.new() with an existing Logger 
> instance as an argument?
> 
> (3) Why is Logger.initialize in the backtrace? The source line number 
> suggests Logger#add (which makes a lot more sense). But if you are 
> really calling Logger.new() lots of times, that sounds like a problem. 

That is a bit of a mystery, no I've only created one Logger and there's
no Logger#new around.

That suggests the backtrace is wrong / elided somewhere.  I'm now
waiting for it to happen again after removing the LogDevice confusion.

-- 
Matthew