Too bad even the trace doesn''t say which hash is involved.
Sorry this post is long: am trying to provide enough context to be
meaningful.
Occurs _intermittently_ when rake jobs:work is pulling a command out
of delayed_jobs while my status observer is in the process of parsing
a log file for detailed results of the previous delayed_job denizen.
I have an observer class (in RAILS_ROOT/lib ) which listens for the
events, makes a copy of them and calls the owner class ( in apps/
models ) which then calls on the log parser (also in /lib) to do the
actual work. (Should both of those classes, the observer and the
parser be in app/models?)
Am due to deliver this application in a few days and this is killing
it (and me).
Am using DirectoryWatcher to look for flag files that indicate the
start and finish of the delayed_jobs.
That is started at the end of environment.rb like this:
require ''directory_watcher''
$scriptStatusObserver = ScriptStatusObserver.new
dirToWatch ="#{RAILS_ROOT}/tmp/flags"
$directoryWatcher = DirectoryWatcher.new( dirToWatch )
$directoryWatcher.glob= "*.flg"
$directoryWatcher.interval=(15)
$directoryWatcher.add_observer( $scriptStatusObserver )
$directoryWatcher.persist=("#{RAILS_ROOT}/tmp/flags/dw_state.yml")
$directoryWatcher.start
at_exit { $directoryWatcher.stop }
This code is outside of the run method (btw is that the best place or
is inside the run better?)
Here is the observer:
require ''script_run''
class ScriptStatusObserver
def initialize
@rcvdEvents = []
end
def update( *events )
begin
puts "#{__LINE__.to_s}: ScriptStatusObserver events:
\n"+events.to_yaml
cnt = 0
events.each do |e|
if e.to_s.match(/^\s*added/)
cnt = cnt + 1
@rcvdEvents << e
end
end
ScriptRun.new.catch_up( @rcvdEvents ) if cnt > 0
@rcvdEvents.clear
rescue
puts $!
end
end
end
Here is ScriptRun (it attaches to an associative table built with
has_many:through)
#require ''observer''
class ScriptRun < ActiveRecord::Base
set_table_name "scripts_runs"
belongs_to :script
belongs_to :run
def parse( result )
parser = LogParser.new
parser.parse(result)
end
def catch_up( events )
events.each do |e|
typ = e.type
path = e.path
thisMatch = path.match(/flags\/(\d+)_(\d+)_([\d\.]+)_(\w+)
\.flg/)
run_id = thisMatch[1]
script_id = thisMatch[2]
ts = thisMatch[3]
status = thisMatch[4]
if e.to_s.match(/^\s*added/)
status_update( script_id, run_id, status, ts, path )
end
end
end
def status_update( script_id, run_id, status, ts, path )
scriptrun = ScriptRun.find(:first, :conditions => [ "run_id = ?
and script_id = ?", run_id.to_i, script_id.to_i ])
if scriptrun.kind_of?(ScriptRun)
currStatus = scriptrun.status
if not currStatus == ''completed''
scriptrun.update_attribute(:status, status)
if status == ''parse''
flag = File.new(path)
logSpec = flag.gets
flag.close
logName = File.basename(logSpec)
logPath = logSpec.sub(logName, '''')
logName =~ /^(([\w_]+)_([\w]+)_(\d+))\.log$/
name = $1
basename = $2
runenv = $3
tsOrPid = $4
result = Result.new
result.log_path = logPath
result.basename = basename
result.name = name
result.script_id = script_id.to_i
result.run_id = run_id.to_i
if runenv == ''sit''
runenv = ''SIT3348''
end
result.application_environment_id
ApplicationEnvironment.find(:first, :conditions =>
[ "nodename = ?", runenv]).id
parse(result)
if run_completed?( run_id )
myRun = Run.find(run_id.to_i)
if myRun.kind_of?( Run )
myRun.update_attribute( :completed, Time.now.to_f )
end
end
end
end
else
puts "#{__LINE__.to_s}: ScriptRun.status_update: ScriptRun not
found for run #{run_id} script #{script_id} ts #{ts.to_s}"
end
File.delete(path)
end
def run_completed?( id )
scriptruns = ScriptRun.find(:all, :conditions => [ "run_id =
?",
id.to_i] )
scriptruns.each do |sr|
if not sr.status == ''completed''
return false
end
end
return true
end
end
LogParser is too long even for this post but it reads the script log
and pulls detailed information (counts and timings) out of the log and
writes to a details table. It also tallies and calculates averages and
rolls those up into summary tables for quicker access from the web
pages.
Here is the error trace:
(don''t ask why everything is under my Windows profile. It''s a
long
story)
Scanner running 1270239731.43
directory_watcher.notify_observers: #<ScriptStatusObserver:0x48ae838
@rcvdEvents
=[#<struct DirectoryWatcher::Event type=:added, path="C:/Documents and
Settings/
pneve/workspace/waftt-0.29/tmp/flags/
100039_11_1270236464.921_parse.flg">, #<str
uct DirectoryWatcher::Event type=:added, path="C:/Documents and
Settings/pneve/w
orkspace/waftt-0.29/tmp/flags/100039_18_1270239550.108_parse.flg">]>
update:[#<struct DirectoryWatcher::Event type=:added, path="C:/
Documents and Set
tings/pneve/workspace/waftt-0.29/tmp/flags/
100039_19_1270239727.368_parse.flg">,
#<struct DirectoryWatcher::Event type=:removed, path="C:/Documents and
Settings
/pneve/workspace/waftt-0.29/tmp/flags/
100039_18_1270239550.108_parse.flg">]
rake aborted!
can''t modify frozen hash
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/rails/
activerecord/l
ib/active_record/attribute_methods.rb:313:in `[]=''
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/rails/
activerecord/l
ib/active_record/attribute_methods.rb:313:in
`write_attribute_without_dirty''
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/rails/
activerecord/l
ib/active_record/dirty.rb:139:in `write_attribute''
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/rails/
activerecord/l
ib/active_record/attribute_methods.rb:211:in `last_error=''
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/plugins/
delayed_job/
lib/delayed/worker.rb:141:in `handle_failed_job''
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/plugins/
delayed_job/
lib/delayed/worker.rb:115:in `run''
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/plugins/
delayed_job/
lib/delayed/worker.rb:162:in `reserve_and_run_one_job''
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/plugins/
delayed_job/
lib/delayed/worker.rb:92:in `work_off''
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/plugins/
delayed_job/
lib/delayed/worker.rb:91:in `times''
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/plugins/
delayed_job/
lib/delayed/worker.rb:91:in `work_off''
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/plugins/
delayed_job/
lib/delayed/worker.rb:66:in `start''
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/rails/
activesupport/
lib/active_support/core_ext/benchmark.rb:10:in `realtime''
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/plugins/
delayed_job/
lib/delayed/worker.rb:65:in `start''
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/plugins/
delayed_job/
lib/delayed/worker.rb:62:in `loop''
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/plugins/
delayed_job/
lib/delayed/worker.rb:62:in `start''
C:/Documents and Settings/pneve/workspace/waftt-0.29/vendor/plugins/
delayed_job/
lib/delayed/tasks.rb:13
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:636:in `call''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:636:in `execute''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:631:in `each''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:631:in `execute''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:597:in `invoke_with_call_chain''
c:/Documents and Settings/pneve/ruby/lib/ruby/1.8/monitor.rb:242:in
`synchronize
''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:590:in `invoke_with_call_chain''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:583:in `invoke''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:2051:in `invoke_task''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:2029:in `top_level''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:2029:in `each''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:2029:in `top_level''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:2068:in `standard_exception_handling''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:2023:in `top_level''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:2001:in `run''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:2068:in `standard_exception_handling''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
lib/rake.
rb:1998:in `run''
c:/Documents and Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/
bin/rake:
31
c:/Documents and Settings/pneve/ruby/bin/rake:16:in `load''
c:/Documents and Settings/pneve/ruby/bin/rake:16
--
You received this message because you are subscribed to the Google Groups
"Ruby on Rails: Talk" group.
To post to this group, send email to
rubyonrails-talk-/JYPxA39Uh5TLH3MbocFF+G/Ez6ZCGd0@public.gmane.org
To unsubscribe from this group, send email to
rubyonrails-talk+unsubscribe-/JYPxA39Uh5TLH3MbocFF+G/Ez6ZCGd0@public.gmane.org
For more options, visit this group at
http://groups.google.com/group/rubyonrails-talk?hl=en.
Too bad even the trace doesn''t say which hash is involved.
Sorry this post is long: am trying to provide enough context to be
meaningful.
Occurs _intermittently_ when rake jobs:work is pulling a command out of
delayed_jobs while my status observer is in the process of parsing a log
file for detailed results of the previous delayed_job denizen. I have
an observer class (in RAILS_ROOT/lib ) which listens for the events,
makes a copy of them and calls the owner class ( in apps/models ) which
then calls on the log parser (also in /lib) to do the actual work.
(Should both of those classes, the observer and the parser be in
app/models?)
Am due to deliver this application in a few days and this is killing it
(and me).
Am using DirectoryWatcher to look for flag files that indicate the start
and finish of the delayed_jobs.
That is started at the end of environment.rb like this:
require ''directory_watcher''
$scriptStatusObserver = ScriptStatusObserver.new
dirToWatch ="#{RAILS_ROOT}/tmp/flags"
$directoryWatcher = DirectoryWatcher.new( dirToWatch )
$directoryWatcher.glob= "*.flg"
$directoryWatcher.interval=(15)
$directoryWatcher.add_observer( $scriptStatusObserver )
$directoryWatcher.persist=("#{RAILS_ROOT}/tmp/flags/dw_state.yml")
$directoryWatcher.start
at_exit { $directoryWatcher.stop }
This code is outside of the run method (btw is that the best place or is
inside the run better?)
Here is the observer:
require ''script_run''
class ScriptStatusObserver
def initialize
@rcvdEvents = []
end
def update( *events )
begin
puts "#{__LINE__.to_s}: ScriptStatusObserver events:
\n"+events.to_yaml
cnt = 0
events.each do |e|
if e.to_s.match(/^\s*added/)
cnt = cnt + 1
@rcvdEvents << e
end
end
ScriptRun.new.catch_up( @rcvdEvents ) if cnt > 0
@rcvdEvents.clear
rescue
puts $!
end
end
end
Here is ScriptRun (it attaches to an associative table built with
has_many:through)
#require ''observer''
class ScriptRun < ActiveRecord::Base
set_table_name "scripts_runs"
belongs_to :script
belongs_to :run
def parse( result )
parser = LogParser.new
parser.parse(result)
end
def catch_up( events )
events.each do |e|
typ = e.type
path = e.path
thisMatch = path.match(/flags\/(\d+)_(\d+)_([\d\.]+)_(\w+)\.flg/)
run_id = thisMatch[1]
script_id = thisMatch[2]
ts = thisMatch[3]
status = thisMatch[4]
if e.to_s.match(/^\s*added/)
status_update( script_id, run_id, status, ts, path )
end
end
end
def status_update( script_id, run_id, status, ts, path )
scriptrun = ScriptRun.find(:first, :conditions => [ "run_id = ? and
script_id = ?", run_id.to_i, script_id.to_i ])
if scriptrun.kind_of?(ScriptRun)
currStatus = scriptrun.status
if not currStatus == ''completed''
scriptrun.update_attribute(:status, status)
if status == ''parse''
flag = File.new(path)
logSpec = flag.gets
flag.close
logName = File.basename(logSpec)
logPath = logSpec.sub(logName, '''')
logName =~ /^(([\w_]+)_([\w]+)_(\d+))\.log$/
name = $1
basename = $2
runenv = $3
tsOrPid = $4
result = Result.new
result.log_path = logPath
result.basename = basename
result.name = name
result.script_id = script_id.to_i
result.run_id = run_id.to_i
if runenv == ''sit''
runenv = ''SIT3348''
end
result.application_environment_id
ApplicationEnvironment.find(:first, :conditions => [
"nodename = ?", runenv]).id
parse(result)
if run_completed?( run_id )
myRun = Run.find(run_id.to_i)
if myRun.kind_of?( Run )
myRun.update_attribute( :completed, Time.now.to_f )
end
end
end
end
else
puts "#{__LINE__.to_s}: ScriptRun.status_update: ScriptRun not
found for run #{run_id} script #{script_id} ts #{ts.to_s}"
end
File.delete(path)
end
def run_completed?( id )
scriptruns = ScriptRun.find(:all, :conditions => [ "run_id =
?",
id.to_i] )
scriptruns.each do |sr|
if not sr.status == ''completed''
return false
end
end
return true
end
end
LogParser is too long even for this post but it reads the script log and
pulls detailed information (counts and timings) out of the log and
writes to a details table. It also tallies and calculates averages and
rolls those up into summary tables for quicker access from the web
pages.
Here is the error trace:
(don''t ask why everything is under my Windows profile. It''s a
long
story)
Scanner running 1270239731.43
directory_watcher.notify_observers: #<ScriptStatusObserver:0x48ae838
@rcvdEvents
=[#<struct DirectoryWatcher::Event type=:added, path="C:/Documents and
Settings/
pneve/workspace/waftt-0.29/tmp/flags/100039_11_1270236464.921_parse.flg">,
#<str
uct DirectoryWatcher::Event type=:added, path="C:/Documents and
Settings/pneve/w
orkspace/waftt-0.29/tmp/flags/100039_18_1270239550.108_parse.flg">]>
update:[#<struct DirectoryWatcher::Event type=:added, path="C:/Documents
and Set
tings/pneve/workspace/waftt-0.29/tmp/flags/100039_19_1270239727.368_parse.flg">,
#<struct DirectoryWatcher::Event type=:removed, path="C:/Documents and
Settings
/pneve/workspace/waftt-0.29/tmp/flags/100039_18_1270239550.108_parse.flg">]
rake aborted!
can''t modify frozen hash
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/rails/activerecord/l
ib/active_record/attribute_methods.rb:313:in `[]=''
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/rails/activerecord/l
ib/active_record/attribute_methods.rb:313:in
`write_attribute_without_dirty''
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/rails/activerecord/l
ib/active_record/dirty.rb:139:in `write_attribute''
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/rails/activerecord/l
ib/active_record/attribute_methods.rb:211:in `last_error=''
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/plugins/delayed_job/
lib/delayed/worker.rb:141:in `handle_failed_job''
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/plugins/delayed_job/
lib/delayed/worker.rb:115:in `run''
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/plugins/delayed_job/
lib/delayed/worker.rb:162:in `reserve_and_run_one_job''
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/plugins/delayed_job/
lib/delayed/worker.rb:92:in `work_off''
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/plugins/delayed_job/
lib/delayed/worker.rb:91:in `times''
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/plugins/delayed_job/
lib/delayed/worker.rb:91:in `work_off''
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/plugins/delayed_job/
lib/delayed/worker.rb:66:in `start''
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/rails/activesupport/
lib/active_support/core_ext/benchmark.rb:10:in `realtime''
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/plugins/delayed_job/
lib/delayed/worker.rb:65:in `start''
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/plugins/delayed_job/
lib/delayed/worker.rb:62:in `loop''
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/plugins/delayed_job/
lib/delayed/worker.rb:62:in `start''
C:/Documents and
Settings/pneve/workspace/waftt-0.29/vendor/plugins/delayed_job/
lib/delayed/tasks.rb:13
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:636:in `call''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:636:in `execute''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:631:in `each''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:631:in `execute''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:597:in `invoke_with_call_chain''
c:/Documents and Settings/pneve/ruby/lib/ruby/1.8/monitor.rb:242:in
`synchronize
''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:590:in `invoke_with_call_chain''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:583:in `invoke''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:2051:in `invoke_task''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:2029:in `top_level''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:2029:in `each''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:2029:in `top_level''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:2068:in `standard_exception_handling''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:2023:in `top_level''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:2001:in `run''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:2068:in `standard_exception_handling''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/lib/rake.
rb:1998:in `run''
c:/Documents and
Settings/pneve/ruby/lib/ruby/gems/1.8/gems/rake-0.8.7/bin/rake:
31
c:/Documents and Settings/pneve/ruby/bin/rake:16:in `load''
c:/Documents and Settings/pneve/ruby/bin/rake:16
--
Posted via http://www.ruby-forum.com/.
--
You received this message because you are subscribed to the Google Groups
"Ruby on Rails: Talk" group.
To post to this group, send email to
rubyonrails-talk-/JYPxA39Uh5TLH3MbocFF+G/Ez6ZCGd0@public.gmane.org
To unsubscribe from this group, send email to
rubyonrails-talk+unsubscribe-/JYPxA39Uh5TLH3MbocFF+G/Ez6ZCGd0@public.gmane.org
For more options, visit this group at
http://groups.google.com/group/rubyonrails-talk?hl=en.