InvalidParameterException: 'logGroupNamePrefix' failed to satisfy constraint

[sagardesai0094]

Problem

Seeing the following error:

2021-02-10 03:13:38 +0000 [warn]: #0 [out_cloudwatch_logs] failed to flush the buffer. retry_time=10 next_retry_seconds=2021-02-10 03:22:59 +0000 chunk="5baf2a6358ee9ea6714bb0da720d09dc" error_class=Aws::CloudWatchLogs::Errors::InvalidParameterException error="2 validation errors detected: Value '' at 'logGroupNamePrefix' failed to satisfy constraint: Member must satisfy regular expression pattern: [\\.\\-_/#A-Za-z0-9]+; Value '' at 'logGroupNamePrefix' failed to satisfy constraint: Member must have length greater than or equal to 1"

 2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/aws-sdk-core-3.111.2/lib/seahorse/client/plugins/raise_response_errors.rb:17:in `call'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/aws-sdk-core-3.111.2/lib/aws-sdk-core/plugins/jsonvalue_converter.rb:22:in `call'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/aws-sdk-core-3.111.2/lib/aws-sdk-core/plugins/idempotency_token.rb:19:in `call'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/aws-sdk-core-3.111.2/lib/aws-sdk-core/plugins/param_converter.rb:26:in `call'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/aws-sdk-core-3.111.2/lib/seahorse/client/plugins/request_callback.rb:71:in `call'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/aws-sdk-core-3.111.2/lib/aws-sdk-core/plugins/response_paging.rb:12:in `call'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/aws-sdk-core-3.111.2/lib/seahorse/client/plugins/response_target.rb:24:in `call'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/aws-sdk-core-3.111.2/lib/seahorse/client/request.rb:72:in `send_request'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/aws-sdk-cloudwatchlogs-1.38.0/lib/aws-sdk-cloudwatchlogs/client.rb:988:in `describe_log_groups'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluent-plugin-cloudwatch-logs-0.11.2/lib/fluent/plugin/out_cloudwatch_logs.rb:511:in `check_log_group_existence'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluent-plugin-cloudwatch-logs-0.11.2/lib/fluent/plugin/out_cloudwatch_logs.rb:502:in `log_group_exists?'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluent-plugin-cloudwatch-logs-0.11.2/lib/fluent/plugin/out_cloudwatch_logs.rb:211:in `block in write'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluent-plugin-cloudwatch-logs-0.11.2/lib/fluent/plugin/out_cloudwatch_logs.rb:203:in `each'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluent-plugin-cloudwatch-logs-0.11.2/lib/fluent/plugin/out_cloudwatch_logs.rb:203:in `write'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.12.0/lib/fluent/plugin/output.rb:1136:in `try_flush'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.12.0/lib/fluent/plugin/output.rb:1448:in `flush_thread_run'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.12.0/lib/fluent/plugin/output.rb:462:in `block (2 levels) in start'
  2021-02-10 03:36:43 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.12.0/lib/fluent/plugin_helper/thread.rb:78:in `block in thread_create'

Steps to replicate

    <label @OUTPUT>
      <match **>
        @type stdout
      </match>
      <match **>
        @type cloudwatch_logs
        @id out_cloudwatch_logs_containers
        region "#{ENV.fetch('AWS_REGION')}"
        log_group_name "/eks/fluentd-testing/containers"
        log_stream_name_key stream_name
        remove_log_stream_name_key true
        auto_create_stream true
        <buffer>
          flush_interval 5
          chunk_limit_size 2m
          queued_chunks_limit_size 32
          retry_forever true
        </buffer>
      </match>
    </label>

Expected Behavior or What you need to ask

I am not sure what's causing the error. There is nothing fancy in the log group name. I have tried just using fluentd-testing as well.

Using Fluentd and CloudWatchLogs plugin versions

• Running in Kubernetes. Using this chart. I have the image tag specified as v1.12.0-debian-cloudwatch-1.0.
• Inside the container the fluentd version is 1.12 and the plugin version seems to be 0.11.2

[sagardesai0094]

The error seems to be happening here based on the stack trace. The describe_log_groups function from the AWS SDK is being called with an empty string.

[sagardesai0094]

And for some reason, if I set the LOG_GROUP_NAME environment variable, the log group is created. But the stream name is not what I am specifying in the conf. I even tried specifying an explicit stream name like fluentd-testing-stream. Maybe something is really wrong with my conf?

[cosmo0920]

@kenhys Could you check this issue?

[kenhys]

@sagardesai0094

I could reproduce it.

This problem is caused by log_stream_name_key stream_name configuration.
It seems that the configuration itself is valid, but the incoming record is not expected in this case.
Thus, when the value of stream_name is empty - {"stream_name": ""}, it causes InvalidParameterException.

You can reproduce it by @type sample by yourself.

<source>
  @type sample
  # OK
  #sample {"stream_name": "foobar", "message": "test"}
  #sample {"message": "test"} 

  # NG
  sample {"stream_name": "", "message": "test"} 
  tag sample
</source>

[sagardesai0094]

I thought it might be related to that, so I even tried removing log_stream_name_key stream_name and tried setting an explicit log_stream_name like in the following config:

    <label @OUTPUT>
      <match **>
        @type stdout
      </match>
      <match **>
        @type cloudwatch_logs
        @id out_cloudwatch_logs_containers
        region "#{ENV.fetch('AWS_REGION')}"
        log_group_name "/eks/fluentd-testing/containers"
        # log_stream_name_key stream_name
        log_stream_name fluentd-testing-stream
        # remove_log_stream_name_key true
        auto_create_stream true
        <buffer>
          flush_interval 5
          chunk_limit_size 2m
          queued_chunks_limit_size 32
          retry_forever true
        </buffer>
      </match>
    </label>

However this still doesn't work unless I set the LOG_GROUP_NAME environment variable.

[kenhys]

At least, as far as I know, fluent-plugin-cloudwatch-log does not depend on LOG_GROUP_NAME environment variable, It is strange. 😕

[sagardesai0094]

Sorry, closed by mistake.

[Watson1978]

Thanks for the report, and sorry for the late follow-up.

To summarize the root cause (as @kenhys already pointed out): this is triggered by records where the field referenced by log_stream_name_key is present but empty. With the config log_stream_name_key stream_name, a record such as {"stream_name": "", "message": "test"} resolves the stream name to an empty string "", and CloudWatch Logs rejects empty names with InvalidParameterException. So the configuration itself is valid — the problem is on the incoming-data side.

Currently the plugin only skips records whose resolved stream name is nil; an empty string ("") is not treated the same way, so it reaches the API and fails. This is still the case on the current version (0.15.0).

Reproduction

Minimal config — feed a single record whose stream_name is empty, and run it against real AWS:

<source>
  @type sample
  tag test
  sample {"stream_name": "", "message": "test"}
</source>

<match test>
  @type cloudwatch_logs
  region "#{ENV['AWS_REGION']}"
  log_group_name /eks/fluentd-testing/containers
  log_stream_name_key stream_name
  remove_log_stream_name_key true
  auto_create_stream true
</match>

Running fluentd -c repro.conf with valid AWS credentials raises InvalidParameterException because the empty value is passed to the API. Changing the record to a non-empty value (e.g. {"stream_name": "app-1", "message": "test"}) works fine.

Note: with the current code, the first call that actually fails is describe_log_streams(log_stream_name_prefix: ""), so the reported parameter name may be logStreamNamePrefix rather than logGroupNamePrefix depending on the version / which value is empty — but the underlying cause (an empty dynamic value hitting the API) is the same.

Workaround (for now)

Make sure every record carries a non-empty stream_name before it reaches this output. For example, fill in a default value with record_transformer:

<filter **>
  @type record_transformer
  enable_ruby true
  <record>
    stream_name ${record["stream_name"].to_s.empty? ? "default" : record["stream_name"]}
  </record>
</filter>

Or drop records that have no stream_name with grep:

<filter **>
  @type grep
  <regexp>
    key stream_name
    pattern /.+/
  </regexp>
</filter>

Plan

I'll keep this open as an enhancement: treating an empty resolved stream name the same as nil (log a warning and skip, instead of calling the API) so it fails gracefully instead of raising InvalidParameterException.