Add metadata for which queue in which vhost thats loading

[spuun]

WHAT is this pull request doing?

The logging when a message store is loading acks and segments isn't very clear. This PR adds metadata to the logging so one knows which queue in which vhost that's loading.

HOW can this pull request be tested?

Publish a lot of messages to a queue and restart lavinmq. Observe logs.

[viktorerlingsson]

I like the addition of metadata! 👍
But I'm not as sure about the extra Info logs both before and after loading segments and acks. Feels maybe a little to verbose with at least 4 log entries per queue IMO. Maybe some of them can be Debug level instead?

2024-10-17T07:46:05.232158Z  INFO lmq.message_store[queue: "machines.cluster.upgrade_lavinmq_rolling", vhost: "cloudamqp"] Loading 1 ack files
2024-10-17T07:46:05.232648Z  INFO lmq.message_store[queue: "machines.cluster.upgrade_lavinmq_rolling", vhost: "cloudamqp"] Loaded 1 ack files
2024-10-17T07:46:05.232782Z  INFO lmq.message_store[queue: "machines.cluster.upgrade_lavinmq_rolling", vhost: "cloudamqp"] Loading 1 segments
2024-10-17T07:46:05.233981Z  INFO lmq.message_store[queue: "machines.cluster.upgrade_lavinmq_rolling", vhost: "cloudamqp"] Loaded 1 segments

[spuun]

It makes somewhat sense with long queues, and later if we can parallelize queue loading.

I wanted to see that "I'm about to load" and also "I'm done". If you only have "I'm about to load" you can't tell if it's done. If you only have "I'm done" you don't know if some loading is stuck (if to few segment files we won't log any progress).

I guess the acks loading can be less verbose. Maybe just print the done message, not even any progress. Loading acks should be super fast?

[spuun]

Or we should have one "I'll load X acks and Y segments", then progress per entity and one "i'm done loading X and Y"? That will make it two log lines for short queues.

[viktorerlingsson]

It makes somewhat sense with long queues, and later if we can parallelize queue loading.

I wanted to see that "I'm about to load" and also "I'm done". If you only have "I'm about to load" you can't tell if it's done. If you only have "I'm done" you don't know if some loading is stuck (if to few segment files we won't log any progress).

I guess the acks loading can be less verbose. Maybe just print the done message, not even any progress. Loading acks should be super fast?

Hmm, I'm thinking it sort of makes sense if queue loading is parallel, but at the moment we don't progress if something is stuck.
I guess it's nice in some cases to get some more info, but I feel like it doesn't add much value outside of debugging scenarios.

Or we should have one "I'll load X acks and Y segments", then progress per entity and one "i'm done loading X and Y"? That will make it two log lines for short queues.

Hmm, yeah I think that's better! But do we really need to do the "i'm done"-part? It's sort of implied by starting loading of the next queue, isn't it?

Ultimately I guess it doesn't matter that much either way, just thinking that it's gonna be a hassle scrolling through hundreds of lines of logs for every restart if there's a decent amount of queues 🙂 But it shouldn't "cost" much I guess 🤷

[spuun]

Not everything needs to be info. But I think it would be possible to go from minimum 4 lines to minimum 2 lines with the same information.

What looks a little bit weird before this PR is that it may say "Loaded x/y segments" but you never see "y/y" (that it's done), which may be confusing. It may get you think that it didn't load everything. And what about queues that isn't logged at all?

But maybe we should reconsider how we log this. Maybe it should be a warn "Long queue, still loading. x/y segments loaded"?

[viktorerlingsson]

Not everything needs to be info. But I think it would be possible to go from minimum 4 lines to minimum 2 lines with the same information.

👍

What looks a little bit weird before this PR is that it may say "Loaded x/y segments" but you never see "y/y" (that it's done), which may be confusing. It may get you think that it didn't load everything. And what about queues that isn't logged at all?

Yeah, you're right. The y/y line probably makes sense to add at least - for all queues.

But maybe we should reconsider how we log this. Maybe it should be a warn "Long queue, still loading. x/y segments loaded"?

Yeah, what users want to see in the logs is probably different depending on their setup, so finding the perfect solution is probably hard. Someone with just a few big queues won't mind a few extra rows per queue, but someone with 10k tiny queues would get a very big log 🙂
Not sure what the right answer is!