Vector: The `aws_ec2_metadata` transform is reported as not working

[binarylogic]

In our chat we have a user reporting that the aws_ec2_metadata transform is not working. They see the instance metadata requests being made but the log is not augmented with the data:

Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.004 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/placement/availability-zone
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.004 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/local-hostname
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.005 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/local-ipv4
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.005 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/mac
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.005 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/network/interfaces/macs/06:a5:31:79:0f:ac/subnet-id
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.006 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/network/interfaces/macs/06:a5:31:79:0f:ac/vpc-id
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.025 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/placement/availability-zone
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.025 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/placement/availability-zone
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.026 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/local-hostname
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.026 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/local-hostname
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.026 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/local-ipv4
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.026 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/local-ipv4
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.027 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/mac
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.027 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/mac
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.027 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/network/interfaces/macs/06:a5:31:79:0f:ac/subnet-id
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.027 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/network/interfaces/macs/06:a5:31:79:0f:ac/subnet-id
Apr 27 14:26:26 ip-10-105-195-187 vector[18040]: Apr 27 14:26:26.028 DEBUG aws_ec2_metadata: worker: vector::transforms::aws_ec2_metadata: Sending metadata request. uri=http://169.254.169.254/latest/meta-data/network/interfaces/macs/06:a5:31:79:0f:ac/vpc-id

And here's a config for their transform:

[transforms.ec2_metadata_nginx_json]
  type = "aws_ec2_metadata" # required
  inputs = ["nginx_json_parse_message"] # required
  fields = ["instance-id", "local-hostname", "local-ipv4", "ami-id", "availability-zone", "vpc-id", "subnet-id", "region"] # optional, default
  host = "http://169.254.169.254" # optional, default
  namespace = "" # optional, default
  refresh_interval_secs = 10 # optional, default

It's likely some edge case with their environment, but I think it would be worth a quick manual test on an EC2 instance to verify that this is working.

Additionally, we should consider what kind of logs would help here?

[LucioFranco]

We probably should swap in our internal http client which has some better response/request logging. Otherwise, since there are no error logs all requests sent have succeeded since we bail (we will retry again) on the first error with the metadata transform and we do log that https://github.com/timberio/vector/blob/master/src/transforms/aws_ec2_metadata.rs#L216.

One issue here could be the setting of namespace = "" which is not the same as the optional default. I think in this case we may have an issue inserting events into the event with a key name ".field".

We may want to consider documenting optional defaults better since having them in the config set to something isn't the same as them not being set.

I can quickly get a fix up for the namespace issue within code (just to detect an empty string and treat it as it not being set) and our internal HTTP client.

[szibis]

Yes confirm that problem is namespace = ""

Without setting this all works perfectly.

[szibis]

Always trying to set values by forcing them because defaults always may change and set them directly to prevent any surprises.

[LucioFranco]

@szibis yeah, looks like I am able to replicate the log insert issue in #2480.

[binarylogic]

Closing in favor of #2480. This will be fixed as part of the work that @Hoverbear is doing with our data model.