title: MySQL server has gone away error in delayed_job task
body: <p>I'm trying to debug a scenario in which the delayed_job process dies under certain circumstances because of a <code>Mysql2::Error: MySQL server has gone away</code> error.</p>
  
  <p>My setup is a bit complex, but I tried to whittle it down to the basics. The <code>run</code> method in the <code>ClustalwFlowTask</code> class is handled as a background job. It basically runs a <code>clustalw2</code> command (a program that does multiple sequence alignment for DNA and proteins)</p>
  
  <p>The details of the command and any error that occurs during its execution should be logged in the flow_tasks table and not caught by delayed_job (see the <code>update_attribute</code> statements). </p>
  
  <pre><code>require 'open3'
  class ClustalwFlowTask &lt; FlowTask
  
    def run
      # setup code ------
  
      # fasta is a file object
      cmd = "clustalw2 -INFILE=#{fasta.path}"
  
      Rails.logger.info "[INFO #{Time.now}] #{self} running #{cmd}"
      #update_attribute(:command, cmd)
  
      raw_stdin,  raw_stdout, raw_stderr = Open3.popen3(cmd)
  
      Rails.logger.info "*********** RAW STDERR: #{raw_stderr} ************"
  
      stdin, stdout, stderr = [raw_stdin,  raw_stdout, raw_stderr].map do |io|
        s = io.read.strip rescue nil
        io.close
        s
      end
  
      Rails.logger.info "*************** #{stderr} *******************"
      unless stderr.blank?
        Rails.logger.info "============  THERE IS AN ERROR  ============"
        #update_attribute(:error, stderr)
        return false
      end
  
      # more code here -----
  end
  </code></pre>
  
  <p>The weird behavior starts when a user doesn't have the <code>clustalw2</code> binary installed, that is if the stderr variable in the method is not blank. Note that I uncommented all the <code>update_attribute</code> statements from the <code>#run</code> method during debugging, so there is no apparent MySQL involvement. (One of my first hunches was that the stderr message is too big or contains something that causes the MySQL server to shut down, but that doesn't seem to be the case)</p>
  
  <p>The delayed_job log contains the following:</p>
  
  <pre><code>2012-03-26T09:19:25-0700: [Worker(delayed_job host:JadeDragon.local pid:8998)] ClustalwFlowTask failed with ActiveRecord::StatementInvalid: Mysql2::Error: closed MySQL connection: DELETE FROM `delayed_jobs` WHERE `delayed_jobs`.`id` = 107 - 0 failed attempts
  </code></pre>
  
  <p>What seems to be happening here is that delayed_job attempted to delete a successful task from the db, but was unable to do so because the mysql connection had been severed. This occurs after the <code>return false</code> statement in the <code>ClustalwFlowTask#run</code> code, since that's when, according to delayed_job, the task is finished successfully.</p>
  
  <p>The development log has this:</p>
  
  <pre><code>================  THERE IS AN ERROR  ================
     (0.5ms)  BEGIN
  Mysql2::Error: MySQL server has gone away: BEGIN
    SQL (0.2ms)  DELETE FROM `delayed_jobs` WHERE `delayed_jobs`.`id` = 110
  Mysql2::Error: closed MySQL connection: DELETE FROM `delayed_jobs` WHERE `delayed_jobs`.`id` = 110
     (0.1ms)  ROLLBACK
  Mysql2::Error: closed MySQL connection: ROLLBACK
     (0.1ms)  BEGIN
  Mysql2::Error: closed MySQL connection: BEGIN
     (0.1ms)  ROLLBACK
  Mysql2::Error: closed MySQL connection: ROLLBACK
  closed MySQL connection
  </code></pre>
  
  <p>I'm running out of ideas on how to debug this, so any help would be greatly appreciated.</p>