abort in remap causes ERROR log spam in 0.25?

[aquarhead]

We've just upgrade to 0.25.1 and now suddenly seeing a bunch of ERROR logs on "Events dropped" (being rate limited)

{"timestamp":"2022-11-09T14:48:14.613851Z","level":"DEBUG","message":"Event mapping aborted.","internal_log_rate_limit":true,"target":"vector::internal_events::remap","span":{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"},"spans":[{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"}]}
{"timestamp":"2022-11-09T14:48:14.613865Z","level":"ERROR","message":"Internal log [Events dropped] has been rate limited 49 times.","target":"vector_common::internal_event::component_events_dropped","span":{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"},"spans":[{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"}]}
{"timestamp":"2022-11-09T14:48:14.613895Z","level":"ERROR","message":"Events dropped","intentional":false,"count":1,"reason":"Event mapping aborted.","internal_log_rate_limit":true,"target":"vector_common::internal_event::component_events_dropped","span":{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"},"spans":[{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"}]}

{"timestamp":"2022-11-09T15:16:13.763091Z","level":"ERROR","message":"Internal log [Events dropped] is being rate limited.","target":"vector_common::internal_event::component_events_dropped","span":{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"},"spans":[{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"}]}
{"timestamp":"2022-11-09T15:16:21.992999Z","level":"ERROR","message":"Internal log [Events dropped] has been rate limited 4 times.","target":"vector_common::internal_event::component_events_dropped","span":{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"},"spans":[{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"}]}
{"timestamp":"2022-11-09T15:16:21.993032Z","level":"ERROR","message":"Events dropped","intentional":false,"count":1,"reason":"Event mapping aborted.","internal_log_rate_limit":true,"target":"vector_common::internal_event::component_events_dropped","span":{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"},"spans":[{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"}]}
{"timestamp":"2022-11-09T15:16:24.050915Z","level":"ERROR","message":"Internal log [Events dropped] is being rate limited.","target":"vector_common::internal_event::component_events_dropped","span":{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"},"spans":[{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"}]}
{"timestamp":"2022-11-09T15:16:33.318782Z","level":"ERROR","message":"Internal log [Events dropped] has been rate limited 5 times.","target":"vector_common::internal_event::component_events_dropped","span":{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"},"spans":[{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"}]}
{"timestamp":"2022-11-09T15:16:33.318826Z","level":"ERROR","message":"Events dropped","intentional":false,"count":1,"reason":"Event mapping aborted.","internal_log_rate_limit":true,"target":"vector_common::internal_event::component_events_dropped","span":{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"},"spans":[{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"}]}
{"timestamp":"2022-11-09T15:16:35.377651Z","level":"ERROR","message":"Internal log [Events dropped] is being rate limited.","target":"vector_common::internal_event::component_events_dropped","span":{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"},"spans":[{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"}]}
{"timestamp":"2022-11-09T15:16:43.606665Z","level":"ERROR","message":"Internal log [Events dropped] has been rate limited 4 times.","target":"vector_common::internal_event::component_events_dropped","span":{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"},"spans":[{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"}]}
{"timestamp":"2022-11-09T15:16:43.606704Z","level":"ERROR","message":"Events dropped","intentional":false,"count":1,"reason":"Event mapping aborted.","internal_log_rate_limit":true,"target":"vector_common::internal_event::component_events_dropped","span":{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"},"spans":[{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"}]}
{"timestamp":"2022-11-09T15:16:45.665458Z","level":"ERROR","message":"Internal log [Events dropped] is being rate limited.","target":"vector_common::internal_event::component_events_dropped","span":{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"},"spans":[{"component_id":"coralogix_prep","component_kind":"transform","component_name":"coralogix_prep","component_type":"remap","name":"transform"}]}

We currently use abort in remap to filter out pods which we do not want to send logs externally (with drop_on_abort = true on the remap transform):

# Check to see if we've been explicitly instructed not to forward to Coralogix.
forward = to_bool!(.kubernetes.pod_annotations."xyz/forward") || true
if !forward { abort }

# Ensure we have the proper Coralogix labels, abort if either are missing.
application = .kubernetes.pod_annotations."xyz/application"
subsystem = .kubernetes.pod_annotations."xyz/subsystem"
if !is_string(application) { abort }
if !is_string(subsystem) { abort }

With some search it seems this is an intended event:

vector/src/internal_events/remap.rs

Lines 49 to 63 in 9348d36

	impl InternalEvent for RemapMappingAbort {
	fn emit(self) {
	debug!(
	message = "Event mapping aborted.",
	internal_log_rate_limit = true
	);
	if self.event_dropped {
	emit!(ComponentEventsDropped::<UNINTENTIONAL> {
	count: 1,
	reason: "Event mapping aborted.",
	});
	}
	}
	}

thus the ERROR logs is also intended? is abort not the correct way to archive filtering? Or, if this is intended use of abort then it shouldn't be creating ERROR log spam by default?

[jszwedko]

Converted this to a bug report since I believe you are right that we shouldn't be logging ERROR logs for abort since that is an intentional action.