Ubuntu22.04下xinetd调用Ruby脚本仅首个系统调用成功后续失败

这是我首次在技术社区发布问题，还请多多包涵。
我有一个在Ubuntu 14.04服务器上稳定运行多年的Ruby脚本，近期迁移到新部署的Ubuntu 22.04服务器后，出现了非常怪异的运行故障。

脚本执行逻辑如下：

• 通过STDIN接收PCL（打印控制语言）数据
• 将接收的数据存入临时文件
• 调用ghostpcl将PCL数据转换为图片文件存储
• 调用tesseract（OCR工具）识别图片中的文本，存储为文本文件
• 读取文本文件内容，写入MySQL数据库
• 调用ghostpcl将PCL数据转换为PDF文件
• 将生成的文本、PDF文件移动到归档目录
• 删除临时文件后退出

脚本完整代码 #

所有MySQL相关代码已注释：

#!/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

故障现象 #

脚本在命令行直接调用时运行完全正常，所有外部命令均使用绝对路径，不存在路径依赖问题。但脚本的正常使用场景是通过xinetd触发：xinetd监听指定端口，接收传入数据后将数据作为STDIN输入调用该脚本。

xinetd调用场景下故障出现在convert方法中：首个系统调用（调用ghostpcl将PCL转为PNG）可以正常执行，生成符合预期的图片文件，但后续调用tesseract的系统调用会直接抛出异常，脚本未执行到打印"1"的代码行就提前终止。

故障特殊表现如下：

• 执行完首个系统调用后，无论后续执行什么系统调用（哪怕是简单的ls命令）都会失败
• 如果将ls这类简单命令放在pcl6调用之前执行，则pcl6调用会失败
  即xinetd场景下该脚本总共只能成功执行一次系统调用，后续所有系统调用均无法执行。同环境下测试仅包含多次系统调用的简单Ruby脚本，通过xinetd触发时可正常运行，无该问题。

复现步骤 #

1. 从系统软件源安装xinetd、tesseract及德语语言包
2. 下载ghostpcl二进制程序，放置到/usr/local/bin目录
3. 创建/data/script、/data/dm目录
4. 在/etc/services文件中添加行dmc 9101/TCP
5. 在/etc/xinetd.d/目录下创建名为dmc的配置文件，内容如下：

service dmc
{
        socket_type = stream
        protocol = tcp
        wait = no
        user = root
        server = /data/script/dmc
        disable = no
        port = 9101
}

6. 创建/etc/dmc.secrets配置文件，内容如下（因MySQL相关代码已注释，数据库参数实际不生效）：

temp_dir=/tmp
out_dir=/data/dm

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

7. 准备PCL格式测试文件用于功能验证

配置完成后可先在命令行测试：执行dmc <pcl_testdata，脚本可正常运行，在/data/dm目录下生成对应的PDF和文本文件。

xinetd场景测试可使用辅助脚本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"

执行命令portdump.rb -p9101 -hlocalhost <pcl_testdata即可将测试数据发送到xinetd监听端口触发脚本运行，脚本日志会输出到syslog，可通过tail -n30 /var/log/syslog查看运行状态。实际测试中脚本执行完首个pcl6系统调用后就会退出，调整系统调用顺序也仅能执行首个调用。

故障总结 #

Ruby脚本命令行运行完全正常，通过xinetd触发时仅能执行一次系统调用，后续调用全部失败，暂未定位到故障原因。

内容的提问来源于stack exchange，提问作者lunqual