HELP!! Delayed-job: Rake aborted! Can't modify frozen hash
- by pmneve
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: #, #]
update:[#,
/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:inwrite_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:inlast_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:inrun'
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:inwork_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:inwork_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:inrealtime'
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:inloop'
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:incall'
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:ineach'
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:ininvoke_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:ininvoke_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:ininvoke_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:ineach'
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:instandard_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:inrun'
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:inrun'
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