How to find a bottleneck in simple file->vrl->blackhole config?

[loyd]

Hi, I'm checking a simple flow of reading some key-value dumps, transforming them using VRL, and sending them to blackhole:

[sources.logfmt]
type = "file"
include = ["logfmt"]
read_from = "beginning"

[transforms.prepare_logfmt]
type = "remap"
inputs = ["logfmt"]

source = '''
raw = parse_logfmt!(.message)
. = {}
.actor_group = raw.g
.actor_key = raw.k
.node_no = raw.n
.sequence_no = raw.s
.trace_id = raw.t
.thread_id = raw.th
.platform_time = raw.ts
.direction = raw.d
.class = raw.cl
.message_name = raw.mn
.message_protocol = raw.mp
.message_kind = raw.mk
.message = raw.m
.correlation_id = raw.c
'''

[sinks.blackhole_logfmt]
type = "blackhole"
inputs = ["prepare_logfmt"]

I observe suspiciously low performance (~80-90k/s or ~70MiB/s) with following utilization metrics:

vector_utilization{component_id="blackhole_logfmt",component_kind="sink",component_type="blackhole",host="loydbook"} 0.1193229907855674 1722978231779
vector_utilization{component_id="prepare_logfmt",component_kind="transform",component_type="remap",host="loydbook"} 0.6343437837793554 1722978231779

CPU Usage: 520%, so it's only 17k/s per core.

I don't understand why utilization is so low, and have several questions:

1. Why is the utilization of the transform only 63%?
2. Does this metric calculate the cumulative utilization of all concurrent transformers?
3. What can I use to understand where the bottleneck is?

[jszwedko]

Hey!

• Why is the utilization of the transform only 63%?

My guess, given those utilization numbers, is that it is the file source that is not reading the data fast enough to saturate the downstream components.

• Does this metric calculate the cumulative utilization of all concurrent transformers?

That's correct.

• What can I use to understand where the bottleneck is?

Same as above.

[loyd]

Thanks for the fast response!

Yep, I thought about source and run with two source files:

[sources.logfmt]
type = "file"
include = ["logfmt", "logfmt.copy"]

with no changes.

But now I checked multiple separate source sections and finally reached 150k/s with a near-full (92%) utilization with 820% CPU.

My guess, given those utilization numbers, is that it is the file source that is not reading the data fast enough to saturate the downstream components.

It would be very useful to provide utilization for sources; this term should also be applied to them.

Anyway, although the performance leaves much to be desired, the issue looks resolved. Thanks

[jszwedko]

Great! Yeah, we have thought about adding a utilization-style metric for sources (it would need to be measured differently), but haven't been able to implement it yet.