LogStash Ruby日期计算报错：LogStash::Timestamp无法转String

我每5分钟向Elasticsearch索引存储一份文件，文件每行包含起始日期与结束日期。配置LogStash处理日期并为结束日期加1天时，出现以下Ruby异常：

[ERROR] 2023-04-13 13:52:37.082 [[main]>worker10] ruby - Ruby exception occurred: no implicit conversion of LogStash::Timestamp into String
[ERROR] 2023-04-13 13:52:37.082 [[main]>worker4] ruby - Ruby exception occurred: no implicit conversion of LogStash::Timestamp into String
[ERROR] 2023-04-13 13:52:37.082 [[main]>worker7] ruby - Ruby exception occurred: no implicit conversion of LogStash::Timestamp into String
[ERROR] 2023-04-13 13:52:37.082 [[main]>worker0] ruby - Ruby exception occurred: no implicit conversion of LogStash::Timestamp into String
[ERROR] 2023-04-13 13:52:37.082 [[main]>worker12] ruby - Ruby exception occurred: no implicit conversion of LogStash::Timestamp into String
[ERROR] 2023-04-13 13:52:37.082 [[main]>worker5] ruby - Ruby exception occurred: no implicit conversion of LogStash::Timestamp into String
[ERROR] 2023-04-13 13:52:37.082 [[main]>worker13] ruby - Ruby exception occurred: no implicit conversion of LogStash::Timestamp into String
[ERROR] 2023-04-13 13:52:37.083 [[main]>worker6] ruby - Ruby exception occurred: no implicit conversion of LogStash::Timestamp into String
[ERROR] 2023-04-13 13:52:37.084 [[main]>worker17] ruby - Ruby exception occurred: no implicit conversion of NilClass into String
[ERROR] 2023-04-13 13:52:37.084 [[main]>worker14] ruby - Ruby exception occurred: no implicit conversion of LogStash::Timestamp into String
[ERROR] 2023-04-13 13:52:37.086 [[main]>worker9] ruby - Ruby exception occurred: no implicit conversion of LogStash::Timestamp into String
[ERROR] 2023-04-13 13:52:37.086 [[main]>worker17] ruby - Ruby exception occurred: no implicit conversion of LogStash::Timestamp into String
[ERROR] 2023-04-13 13:52:37.087 [[main]>worker16] ruby - Ruby exception occurred: no implicit conversion of LogStash::Timestamp into String
[ERROR] 2023-04-13 13:52:37.087 [[main]>worker14] ruby - Ruby exception occurred: no implicit conversion of NilClass into String
[ERROR] 2023-04-13 13:52:37.087 [[main]>worker11] ruby - Ruby exception occurred: no implicit conversion of LogStash::Timestamp into String
[ERROR] 2023-04-13 13:52:37.087 [[main]>worker1] ruby - Ruby exception occurred: no implicit conversion of LogStash::Timestamp into String
[ERROR] 2023-04-13 13:52:37.087 [[main]>worker16] ruby - Ruby exception occurred: no implicit conversion of NilClass into String
[ERROR] 2023-04-13 13:52:37.087 [[main]>worker1] ruby - Ruby exception occurred: no implicit conversion of NilClass into String 

对应的LogStash配置如下：

input {
  file {
    path => "/path"
    start_position => "beginning"
    mode => "read"
    sincedb_path => "/dev/null"
  }
}
filter {
    grok {
      match => { "message" => "%{DATA}%{NUMBER:SN}%{DATA}%{NUMBER:ID}%{DATA}%{WORD:Source}%{DATA}%{TIMESTAMP_ISO8601:Start_Time}%{DATA}%{TIMESTAMP_ISO8601:End_Time}%{DATA}%{WORD:Status}" }
    }
      if "FINISHED" in [message] {
          mutate {add_field  => { "number" => 1 } } }
      if "RUNNING" in [message] {
          mutate { add_field => { "number" => 3 } }}
    date {
      match => [ "End_Time", "yyyy-MM-dd HH:mm" ]
      target => "enddate"}
    date {
      match => [ "@timestamp", "yyyy-MM-dd HH:mm" ]
      target => "mytimestamp" }
   # mutate { rename => { "mytimestamp" => "@timestamp" } }
    mutate { convert => { "mytimestamp" => "string" } }
    ruby {
       code => "
          require 'time'
          current_time = Date.parse(event.get('enddate'))
          new_time = current_time + 86400
          event.set('enddateone', new_time.iso8601(3))"
      }
      if "ABORTED" in [message]  {
        if [enddateone] >= [mytimestamp] {
          mutate { add_field => { "number" => 4 } }}
        else {
          mutate { add_field => { "number" => 2 } }}
  }
}
output {
  elasticsearch {}
}

问题原因分析 #

1. LogStash::Timestamp类型转换错误：date过滤器处理后，enddate是LogStash::Timestamp类型，不是字符串，直接用Date.parse解析会触发类型不兼容错误。
2. 空值引发的NilClass错误：部分事件中enddate可能为空（比如grok匹配失败、date解析失败），此时调用Date.parse传入nil会报错。
3. 字符串比较的逻辑风险：将mytimestamp转成字符串后和enddateone比较，字符串的排序规则不一定和时间顺序一致，可能导致判断结果错误。

修复步骤 #

1. 正确转换时间类型：把LogStash::Timestamp转为Ruby原生Time对象后再进行计算。
2. 增加空值校验：在Ruby代码中先判断enddate是否存在，避免空值引发异常。
3. 用时间类型做比较：保留时间类型字段进行大小判断，放弃字符串比较的方式。

修复后的核心配置片段 #

替换原有的ruby过滤器和后续的比较逻辑：

filter {
    # 原有grok、status判断等过滤器保留...

    date {
      match => [ "End_Time", "yyyy-MM-dd HH:mm" ]
      target => "enddate"
      # 标记解析失败的事件，方便排查
      tag_on_failure => [ "enddate_parse_fail" ]
    }
    date {
      match => [ "@timestamp", "yyyy-MM-dd HH:mm" ]
      target => "mytimestamp"
    }

    # 替换原ruby过滤器
    ruby {
       code => "
          require 'time'
          enddate = event.get('enddate')
          if enddate
            # 将LogStash时间对象转为Ruby Time
            current_time = enddate.time
            # 加1天（86400秒）
            new_time = current_time + 86400
            # 存储字符串格式的日期
            event.set('enddateone', new_time.iso8601(3))
            # 存储时间类型的日期用于后续比较
            event.set('enddateone_time', LogStash::Timestamp.new(new_time))
          end"
      }

      # 优化ABORTED状态的判断逻辑
      if "ABORTED" in [message] and [enddateone_time] {
        if [enddateone_time] >= [mytimestamp] {
          mutate { add_field => { "number" => 4 } }
        } else {
          mutate { add_field => { "number" => 2 } }
        }
      }
}

额外优化建议 #

• 给grok过滤器添加失败标记，方便排查格式异常的日志：

  grok {
    match => { "message" => "%{DATA}%{NUMBER:SN}%{DATA}%{NUMBER:ID}%{DATA}%{WORD:Source}%{DATA}%{TIMESTAMP_ISO8601:Start_Time}%{DATA}%{TIMESTAMP_ISO8601:End_Time}%{DATA}%{WORD:Status}" }
    tag_on_failure => [ "grok_parse_fail" ]
  }
  

• 改用解析后的Status字段判断任务状态，比直接匹配message更准确：

  if [Status] == "FINISHED" {
      mutate { add_field => { "number" => 1 } }
  }
  if [Status] == "RUNNING" {
      mutate { add_field => { "number" => 3 } }
  }
  

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