emit transaction failed: error_class=NoMethodError error="undefined method `full_pack'

[sagimann]

Problem

Suddenly, in recent days, td-agent stops sending events via the ES plugin, showing the following for each event in its log file:

2019-08-27 06:57:24 +0000 [warn]: #0 emit transaction failed: error_class=NoMethodError error="undefined method `full_pack' for #<MessagePack::Packer:0x007f3de657dbb0>" location="/opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-1.7.0/lib/fluent/event.rb:63:in `to_msgpack_stream'" tag="**************"

From what I could gather, this did not occur on machines where td-agent --version showed "1.6.3", but did start recently in machines with td-agent showing version 1.7.0. Also, looking at the logs, it showed fluentd 1.7.0 instead of 1.6.3 and fluentd elastic search plugin changed from 3.5.4 to 3.5.5. We do not install the plugin directly, but rather via fluent-plugin-aws-elasticsearch-service.

Steps to replicate

in ubuntu:

curl -L https://toolbelt.treasuredata.com/sh/install-ubuntu-xenial-td-agent2.sh | sh
td-agent-gem install fluent-plugin-aws-elasticsearch-service

The td-agent conf file is:

<source>
  @type syslog
  tag syslog
</source>

<source> 
  @type tail
  format multiline
  format_firstline /^\d{4}-\d{2}-\d{2}/
  format1 /^(?<timestamp>\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d+)\s+\[(?<pid>.+)\]\s+(?<level>[^ ]+)\s+(?<message>.*)/
  time_format %Y-%m-%d %H:%M:%S,%N
  time_key timestamp
  path /var/log/xxxx/x*
  tag xxxx
</source>

<filter **>
  @type record_transformer
  enable_ruby
  remove_keys ["error"]
  <record>
    hostname "#{Socket.gethostname}"
    environment dev
  </record>
</filter>

<match fluent.**>
  @type null
</match>

<match **>
  @type "aws-elasticsearch-service"
  type_name "access_log"
  logstash_format true
  include_tag_key true
  tag_key "@log_name"
  reload_connections false
  flush_interval 1s
  <endpoint>
   url xxxxxxx
   region xxxxx
  </endpoint>
  <secondary>
    @type file
    path /var/log/td-agent/failed_records
  </secondary>
</match>

Expected Behavior or What you need to ask

error should not be issued, and the event should be emitted correctly to ES

Using Fluentd and ES plugin versions

• Ubuntu 18.04
• td-agent 1.7.0

boot log:

2019-08-27 08:56:08 +0000 [info]: parsing config file is succeeded path="/etc/td-agent/td-agent.conf"
2019-08-27 08:56:08 +0000 [warn]: secondary type should be same with primary one primary="Fluent::TreasureDataLogOutput" secondary="Fluent::Plugin::FileOutput"
2019-08-27 08:56:08 +0000 [info]: using configuration file: <ROOT>
  <source>
    @type syslog
    tag "syslog"
  </source>
  <source>
    @type tail
    format multiline
    format_firstline /^\d{4}-\d{2}-\d{2}/
    format1 /^(?<timestamp>\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d+)\s+\[(?<pid>.+)\]\s+(?<level>[^ ]+)\s+(?<message>.*)/
    time_format %Y-%m-%d %H:%M:%S,%N
    time_key timestamp
    path "/var/log/xxxx/x*"
    tag "xxx.xxx"
    <parse>
      time_key timestamp
      time_format %Y-%m-%d %H:%M:%S,%N
      format_firstline /^\d{4}-\d{2}-\d{2}/
      @type multiline
      format1 /^(?<timestamp>\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d+)\s+\[(?<pid>.+)\]\s+(?<level>[^ ]+)\s+(?<message>.*)/
    </parse>
  </source>
  <filter **>
    @type record_transformer
    enable_ruby 
    remove_keys ["error"]
    <record>
      hostname 1fffcfd5bb61
      environment staging
    </record>
  </filter>
  <match fluent.**>
    @type null
  </match>
  <match **>
    @type aws-elasticsearch-service
    type_name "access_log"
    logstash_format true
    include_tag_key true
    tag_key "@log_name"
    reload_connections false
    flush_interval 1s
    <endpoint>
      url "xxxxx"
      region "xxxxx"
    </endpoint>
    <secondary>
      @type "file"
      path "/var/log/td-agent/failed_records"
      <buffer time>
        path /var/log/td-agent/failed_records
      </buffer>
    </secondary>
    <buffer>
      flush_interval 1s
    </buffer>
  </match>
</ROOT>
2019-08-27 08:56:08 +0000 [info]: starting fluentd-1.7.0 pid=105 ruby="2.1.10"
2019-08-27 08:56:08 +0000 [info]: spawn command to main:  cmdline=["/opt/td-agent/embedded/bin/ruby", "-Eascii-8bit:ascii-8bit", "/usr/sbin/td-agent", "--log", "/var/log/td-agent/td-agent.log", "--daemon", "/var/run/td-agent/td-agent.pid", "--under-supervisor"]
2019-08-27 08:56:08 +0000 [info]: gem 'fluent-mixin-plaintextformatter' version '0.2.6'
2019-08-27 08:56:08 +0000 [info]: gem 'fluent-plugin-aws-elasticsearch-service' version '2.1.0'
2019-08-27 08:56:08 +0000 [info]: gem 'fluent-plugin-elasticsearch' version '3.5.5'
2019-08-27 08:56:08 +0000 [info]: gem 'fluent-plugin-kafka' version '0.6.1'
2019-08-27 08:56:08 +0000 [info]: gem 'fluent-plugin-mongo' version '0.8.1'
2019-08-27 08:56:08 +0000 [info]: gem 'fluent-plugin-rewrite-tag-filter' version '1.5.6'
2019-08-27 08:56:08 +0000 [info]: gem 'fluent-plugin-s3' version '0.8.5'
2019-08-27 08:56:08 +0000 [info]: gem 'fluent-plugin-scribe' version '0.10.14'
2019-08-27 08:56:08 +0000 [info]: gem 'fluent-plugin-td' version '0.10.29'
2019-08-27 08:56:08 +0000 [info]: gem 'fluent-plugin-td-monitoring' version '0.2.3'
2019-08-27 08:56:08 +0000 [info]: gem 'fluent-plugin-webhdfs' version '0.7.1'
2019-08-27 08:56:08 +0000 [info]: gem 'fluentd' version '1.7.0'
2019-08-27 08:56:08 +0000 [info]: gem 'fluentd' version '0.12.40'
2019-08-27 08:56:08 +0000 [info]: adding match pattern="td.*.*" type="tdlog"
2019-08-27 08:56:08 +0000 [warn]: #0 secondary type should be same with primary one primary="Fluent::TreasureDataLogOutput" secondary="Fluent::Plugin::FileOutput"
2019-08-27 08:56:08 +0000 [info]: adding match pattern="debug.**" type="stdout"
2019-08-27 08:56:08 +0000 [info]: adding source type="forward"
2019-08-27 08:56:08 +0000 [info]: adding source type="http"
2019-08-27 08:56:08 +0000 [info]: adding source type="debug_agent"
2019-08-27 08:56:08 +0000 [info]: #0 starting fluentd worker pid=115 ppid=110 worker=0
2019-08-27 08:56:08 +0000 [info]: #0 listening dRuby uri="druby://127.0.0.1:24230" object="Fluent::Engine" worker=0
2019-08-27 08:56:08 +0000 [info]: #0 listening port port=24224 bind="0.0.0.0"
2019-08-27 08:56:08 +0000 [info]: #0 fluentd worker is now running worker=0

*** LOCAL GEMS ***

actionmailer (4.2.8) actionpack (4.2.8) actionview (4.2.8) activejob (4.2.8) activemodel (4.2.8) activerecord (4.2.8) activesupport (4.2.8) addressable (2.5.2, 2.5.1) arel (6.0.4) aws-eventstream (1.0.3) aws-partitions (1.206.0) aws-sdk (2.10.45) aws-sdk-core (3.64.0, 2.10.45) aws-sdk-resources (2.10.45) aws-sigv4 (1.1.0, 1.0.2) bigdecimal (default: 1.2.4) bson (4.1.1) builder (3.2.3) bundler (1.14.5) celluloid (0.15.2) concurrent-ruby (1.1.5) cool.io (1.5.1) crass (1.0.2) diff-lcs (1.3) dig_rb (1.0.1) draper (1.4.0) elasticsearch (7.3.0) elasticsearch-api (7.3.0) elasticsearch-transport (7.3.0) erubis (2.7.0) excon (0.66.0) faraday (0.15.4) faraday_middleware-aws-sigv4 (0.2.4) fluent-logger (0.7.1) fluent-mixin-plaintextformatter (0.2.6) fluent-plugin-aws-elasticsearch-service (2.1.0) fluent-plugin-elasticsearch (3.5.5) fluent-plugin-kafka (0.6.1) fluent-plugin-mongo (0.8.1) fluent-plugin-rewrite-tag-filter (1.5.6) fluent-plugin-s3 (0.8.5) fluent-plugin-scribe (0.10.14) fluent-plugin-td (0.10.29) fluent-plugin-td-monitoring (0.2.3) fluent-plugin-webhdfs (0.7.1) fluentd (1.7.0, 0.12.40) fluentd-ui (0.4.4) font-awesome-rails (4.7.0.1) globalid (0.4.0) haml (4.0.7) haml-rails (0.5.3) hike (1.2.3) hirb (0.7.3) http_parser.rb (0.6.0) httpclient (2.8.2.4) i18n (0.8.1) io-console (default: 0.4.3) ipaddress (0.8.3) jbuilder (2.6.3) jmespath (1.3.1) jquery-rails (3.1.4) json (default: 1.8.1) kramdown (1.13.2) kramdown-haml (0.0.3) loofah (2.1.1, 2.0.3) ltsv (0.1.0) mail (2.6.4) mime-types (3.1) mime-types-data (3.2016.0521) mini_portile2 (2.3.0, 2.1.0) minitest (5.10.1, default: 4.7.5) mixlib-cli (1.7.0) mixlib-config (2.2.4) mixlib-log (1.7.1) mixlib-shellout (2.2.7) mongo (2.2.7) msgpack (1.1.0) multi_json (1.12.1) multipart-post (2.1.1) nokogiri (1.8.1) ohai (6.20.0) oj (2.18.1) parallel (1.8.0) psych (default: 2.0.5) public_suffix (3.0.0, 2.0.5) puma (3.8.2) rack (1.6.5) rack-test (0.6.3) rails (4.2.8) rails-deprecated_sanitizer (1.0.3) rails-dom-testing (1.0.8) rails-html-sanitizer (1.0.3) railties (4.2.8) rake (default: 10.1.0) rdoc (default: 4.1.0) request_store (1.3.2) ruby-kafka (0.4.2) ruby-progressbar (1.8.3) rubyzip (1.2.1, 1.1.7) sass (3.2.19) sass-rails (4.0.5) serverengine (2.1.1) settingslogic (2.0.9) sigdump (0.2.4) sprockets (2.12.4) sprockets-rails (2.3.3) string-scrub (0.0.5) strptime (0.2.3) sucker_punch (1.0.5) systemu (2.5.2) td (0.15.2) td-client (0.8.85) td-logger (0.3.27) test-unit (default: 2.1.10.0) thor (0.19.4) thread_safe (0.3.6) thrift (0.8.0) tilt (1.4.1) timers (1.1.0) tzinfo (2.0.0, 1.2.3) tzinfo-data (1.2017.2) uuidtools (2.1.5) webhdfs (0.8.0) yajl-ruby (1.3.0) zip-zip (0.3)

• ES version (6.x)

[sagimann]

One workaround I found in the meantime. Call this before installing the fluent-plugin-aws-elasticsearch-service gem: td-agent-gem install fluentd -v 1.6.3 .. now install fluent-plugin-aws-elasticsearch-service...

[cosmo0920]

Contaminated usage for fluentd 1.7.0 and 0.12.40 is dangerous. Please uninstall Fluentd v0.12.40 when using Fluentd v1.7 or later.

[cosmo0920]

And td-agent 2 is already EOL. We don't provide any issue triage for td-agent 2. Could you use td-agent 3 with this installation step?

$ curl -L https://toolbelt.treasuredata.com/sh/install-ubuntu-xenial-td-agent3.sh | sh