Peculiar behavior of logger.rb under Rails

I am using logger to record method calls in a Rails app. It
is used in the context of some “set_trace_func proc” code,
which is invoked at the start of “…/public/dispatch.fcgi”.

As the app runs, a log of all method calls is generated.
However, at line 5463 in the log, the line prefixes go away:

I, [09:44:43#26539] INFO – : call 8 Object:method_added …
I, [09:44:43#26539] INFO – : call 8 Object:method_added …
call 8 Object:method_added … (P07/blankslate.rb:57)
call 7 Kernel:require … (P04/custom_require.rb:26)

The prefixes do not reappear in the remainder of the (26979 line)
log. To eliminate the possibility that logger gets confused at a
given number of output lines, I wrote a simple test script:

#!/usr/bin/env ruby

require ‘/usr/local/lib/ruby/site_ruby/1.8/boswell.rb’
Boswell.new(‘/tmp/rdm/TST’)

def foo
a=1
end

50000.times do
foo
end

However, this did not reproduce the problem. So, I assume that
there is some untoward interaction going on with the Rails code.
Can anyone suggest a way of tracking this down?

-r

http://www.cfcl.com/rdm Rich M.
http://www.cfcl.com/rdm/resume [email protected]
http://www.cfcl.com/rdm/weblog +1 650-873-7841

Technical editing and writing, programming, and web development