rubylinuxshellxinetd

Ruby Script fails while invoked via xinetd


This is my first post on stack overflow and it's a bummer, so please bear with me.

I have a ruby script which has worked flawlessly for years on an Ubuntu 14.04 Server. I set up a new Ubuntu 22.04 Server and migrated the Script, but it doesn't work anymore, and it fails in a spectacularly weird fashion!

The Script does the following

The Script is (any mysql references commented out)

#!/usr/bin/ruby
# encoding: utf-8

require 'securerandom'
require 'optparse'
require 'parseconfig'
require 'syslog'
require 'fileutils'
#require 'mysql2'
require 'time'
require 'open3'

BANNER = 'dmc 0.1/24.06.2015'
CONFIGFILE = '/etc/dmc.secrets'
TMPFILES_EXTENSIONS = ['','.png','.txt']
DEFAULT_VALUE = ' '

class Dmc 
  def initialize
    Encoding.default_external = Encoding::UTF_8
    Encoding.default_internal = Encoding::UTF_8
    @config = {}
    @daten = {}
    OptionParser.new do |opts|
      opts.banner = "Usage: r_backup.rb [options]"
      opts.on('-p', '--printer', 'print directly') { |v| @config[:printer] = v }
    end.parse!
    log BANNER
    readConfig CONFIGFILE
    createTmpFile
    convert
    cleanup
  end

  def readConfig(configfile)
    configdata = ParseConfig.new(configfile)
    @config[:temp_extensions] = TMPFILES_EXTENSIONS
    @config[:temp_dir] = configdata['temp_dir']
    @config[:out_dir] = configdata['out_dir']
    @config[:tmpfile] = File.join(configdata['temp_dir'],SecureRandom.uuid)
    @config[:now] = Time.new
    @config[:tif_tmp] = @config[:tmpfile] + '.png'
    @config[:txt_tmp] = @config[:tmpfile]
    @config[:out_basefilename] = @config[:now].strftime('%Y-%m-%d-%H-%M')
    @config[:mysql_host] = configdata['mysql_host']
    @config[:mysql_database] = configdata['mysql_database']
    @config[:mysql_user] = configdata['mysql_user']
    @config[:mysql_passwd] = configdata['mysql_passwd']

    @daten[:d_bezeichnung] = [/bezeichnung/,DEFAULT_VALUE,'bezeichnung']
    @daten[:d_losnummer] = [/losnummer/,DEFAULT_VALUE,'losnummer']
    @daten[:d_firmware] = [/Firmwareversion:/, DEFAULT_VALUE,'firmware']
    @daten[:d_dma_seriennummer] = [/DMA.*Dichte.*Seriennummer:/, DEFAULT_VALUE,'dma_seriennummer']
    @daten[:d_xsample_seriennummer] = [/.*xsample.*Seriennummer:.*/, DEFAULT_VALUE,'xsample_seriennummer']
    @daten[:d_proben_id] = [/Eindeutige.*Probennr.:/, DEFAULT_VALUE,'proben_id']
    @daten[:d_datum] = [/Datum:/, DEFAULT_VALUE,'datum']
    @daten[:d_zeit] = [/Zeit:/, DEFAULT_VALUE,'zeit']
    @daten[:d_staerke] = [/Ethanol.*OIML.*\(.*\):/, DEFAULT_VALUE,'staerke']
    @daten[:d_dichte_temperatur] = [/Dichte Temperatur:/, DEFAULT_VALUE,'dichte_temperatur']
    @daten[:d_relative_dichte] = [/Relative Dichte:/, DEFAULT_VALUE,'rel_dichte']
    @daten[:d_dichte] = [/Dichte:.*g/, DEFAULT_VALUE,'dichte']
    @daten[:d_feld_1] = [/Feld 1:/, DEFAULT_VALUE,'feld1']
    @daten[:d_feld_2] = [/Feld 2/, DEFAULT_VALUE,'feld2']
    @daten[:d_feld_3] = [/Feld 3/, DEFAULT_VALUE,'feld3']
    @daten[:d_status] = [/Dichte Status:/, DEFAULT_VALUE,'status']
    @daten[:d_zucker] = [/Zucker/, DEFAULT_VALUE,'zucker']
    @daten[:d_extrakt] = [/.*trakt.*:/, DEFAULT_VALUE,'extrakt']
    @daten[:d_datum_zeit] = [/datum_zeit/,@config[:now].strftime('%Y-%m-%d %H:%M:%S'),'datum_zeit']
  end

  def convert
    begin
      log "convert"
      cmd = '/usr/local/bin/pcl6 -r300 -dNOPAUSE -sDEVICE=pngmono -o ' + @config[:tif_tmp] +' ' + @config[:tmpfile]
      log cmd
      `#{cmd}`
      cmd = '/usr/bin/tesseract ' + @config[:tif_tmp]  + ' ' +  @config[:txt_tmp]  + ' -l deu'
      log cmd
      `#{cmd}`
      log "1"
      readTxt
      writeOutputFiles
 #     if @config[:printer] !=nil
 #       printDirect
 #     elsif
 #       writeDatabase
 #     end
    end
  end

  def printDirect
    cmd = "/usr/bin/lp -dlabordrucker " + @config[:tmpfile]
    puts `#{cmd}`
  end
 
  def writeDatabase
    begin
      con =  Mysql2::Client.new(:host =>  @config[:mysql_host], :username => @config[:mysql_user],:password => @config[:mysql_passwd],:database => @config[:mysql_database])
      columns = ''
      values = ''
      @daten.each do |key,value|
        columns += value[2] + ','
        values += "'" + value[1] + "',"
    log "c=#{value[2]} == #{value[1]}"
      end
      columns = columns.chop
      values = values.chop
      if columns.length > 1 && values.length > 1
        cmd = "INSERT INTO dm (#{columns}) VALUES (#{values})"
        log cmd
        con.query(cmd)
      end
      unless con.nil?
        con.close
      end
    end
  end

  def writeOutputFiles
    begin
     output_dir = File.join(@config[:out_dir],@config[:now].strftime('%Y'),@config[:now].strftime('%-m'),@config[:now].strftime('%Y')+'-'+@config[:now].strftime('%m')+'-' + @config[:now].strftime('%d'))
     FileUtils.mkdir_p output_dir
     output_pdf_file = File.join(output_dir,@config[:out_basefilename] + '__' + @daten[:d_proben_id][1].gsub(/\s+/, '') + '.pdf')
     cmd = 'pcl6 -r300 -dNOPAUSE -sDEVICE=pdfwrite -o ' + output_pdf_file + ' ' + @config[:tmpfile]
     log cmd
     `#{cmd}`
     output_text_file = File.join(output_dir,@config[:out_basefilename] + '__' + @daten[:d_proben_id][1].gsub(/\s+/, '') + '.txt')
     cmd = 'cp ' +  @config[:tmpfile] + '.txt ' + output_text_file 
     log cmd
     `#{cmd}`
    end
  end

  def readTxt
    begin
      textfile = @config[:txt_tmp]+'.txt'
      log "Reading textfile : #{textfile}"
      lines = File.readlines(textfile)
      lines.each do |line|
        @daten.each do |key,value|
          match = line.match(value[0])
          unless match.nil?
           value[1] = line[line.index(':')+1..-1].strip
          end
        end
      end
      begin
    @daten[:d_datum_zeit][1] = Time.parse(@daten[:d_datum][1] + ' ' + @daten[:d_zeit][1]).strftime('%Y-%m-%d %H:%M:%S')
      rescue ArgumentError
    @daten[:d_datum_zeit][1] = Time.new.to_s 
      end
      log "datum: #{@daten[:d_datum_zeit][1]}"
    end
  end

  def createTmpFile
   f = STDIN.read()
   log "Create Temp File :#{@config[:tmpfile]}"
   tmp = File.open(@config[:tmpfile],'w')
   tmp.write(f)
   tmp.close
  end

  def cleanup
    @config[:temp_extensions].each do |ext|
      del = @config[:tmpfile] + ext     
      if File.exists?(del)
        log "Delete Temp File :#{del}"
        File.delete(del)
      end
    end
  end

  def getTimeStamp
    date = Time.new
    return date.strftime('%Y-%m-%d-%H-%M-%S')
  end


  def log (str)
    str = "#{getTimeStamp()} :#{str}\n"
    str = str.sub("%","P")
    puts str
    Syslog.open($0, Syslog::LOG_PID|Syslog::LOG_CONS )  
    Syslog.log(Syslog::LOG_PID, str )
    Syslog.close
 end
  
end

d = Dmc.new


When invoked from a command line it works flawlessly as expected, so there is nothing wrong with the code (It uses full paths for files, so no problem with running it from anywhere). But this script is normally invoked via xinetd; xinetd opens a port, accepts data and invokes the script with this data as STDIN.

This way the error happens here:

  def convert
    begin
      log "convert"
      cmd = '/usr/local/bin/pcl6 -r300 -dNOPAUSE -sDEVICE=pngmono -o ' + @config[:tif_tmp] +' ' + @config[:tmpfile]
      log cmd
      `#{cmd}`
      cmd = '/usr/bin/tesseract ' + @config[:tif_tmp]  + ' ' +  @config[:txt_tmp]  + ' -l deu'
      log cmd
      `#{cmd}`
      log "1"
      readTxt
      writeOutputFiles
 #     if @config[:printer] !=nil
 #       printDirect
 #     else if
 #       writeDatabase
 #     end
    end
  end

First a system call is executed which calls ghostplc to convert ppl to image; this will be done, a proper image is created

Then tesseract is called via system call which throws an exception without any attempt to call anything, and the script stops without reaching the puts "1" line.

The weird part is that after the pcl6 system calls ANY system call will fail, irrespective of content; even a simple ls will fail. Even weirder is that when you put a ls system call BEFORE pcl6, then the pcl6 system call will fail.

So, this script will only execute ONE system call at all, regardless of the position in the code, all subsequent calls will fail, and I have no clue as to why!

I have tested this way (invoking via xinetd) with another ruby script which simply makes a couple of system calls, to no avail, because this script executes without fail.

If you want to test this script you have to do the following steps:

  1. install xinetd and tesseract (with German language file) from repository
  2. Download ghostpcl from https://ghostscript.com/releases/gpcldnld.html and place it in /usr/local/bin
  3. create directories /data/script and /data/dm
  4. add the line "dmc 9101/TCP" to /etc services
  5. create a file named dmc in /etc/xinetd.d/ with the contents
service dmc
{
        socket_type = stream
        protocol = tcp
        wait = no
        user = root
        server = /data/script/dmc
        disable = no
        port = 9101
}
  1. create a file /etc/dmc_secrets with the content:
temp_dir=/tmp
out_dir=/data/dm

mysql_host=localhost
mysql_database=database
mysql_user=dm
mysql_passwd=anything

the mysql parameters will not be used in this script because they ur commented out 6. get a PCL Testfile with

wget http://www.lunqual.de/pcl_testdata

If it is setup correctly you can first run the script from command line:

dmc <pcl_testdata

It should work and leave a PDF and a Textfile in /data/dm

Next is a test with xinetd. Instead of a printer to dump the file you can use my little helper portdump.rb

#!/usr/bin/ruby
# encoding: utf-8
require 'socket'

    Encoding.default_external = Encoding::UTF_8
    Encoding.default_internal = Encoding::UTF_8
    
    host = '127.0.0.1'
    port = 7777
    puts "Portdump Usage portdump -pPORT -hHOST <file"
    ARGV.each do|arg|
      if arg.start_with?("-p")
        port = arg[2..-1]
      end
      if arg.start_with?("-h")
        host = arg[2..-1]
      end
    end
    puts "Host=#{host}, Port=#{port}" 
    s = TCPSocket.new host,port 
    puts "Socket Open"
    f = STDIN.read()
    s.send f,0
    puts "Data sent"
    s.close
    puts "Portdump closed"

invoke it with

portdump.rb -p9101 -hlocalhost <pcl_testdata

this will dump the data to xinedt, which in turn invokes dmc. dmc logs all things to syslog, so with tail -n30 /var/log/syslog you can see if it works. For me, the script exits after the "pcl6" system call. You can place a ls system call in the convert method and the script will exit after the first call.

TLDR; Ruby script works on command line, but fails weirdly when invoked via xinetd. No clue as to why.


Solution

  • Solved!

    After much tinkering the problem turned out to be a simple case of Broken Pipe! A simple $stdout = File.new( '/dev/null', 'w' ) at the start of the script solved the problem and now the script is working as intended.

    This was obviously no problem of the ruby version back in Ubuntu 14.04, but is now.

    Well, thank you all for your comments and hints; Lesson learned...