Identify call router request in logs

[Serpentian]

Currently it's difficult for users to distinguish call errors, written to log, as they're not identified:

2024-12-18 18:59:25.955 [29638] main/326/main replicaset.lua:614 E> Exception during calling 'vshard.storage.call' on 'filedb_001_2([email protected]:5003)': Timeout exceeded

It was proposed to add trace_id opt to to router call's, so that all logs from that call are logged with that trace_id. Something like that:

2024-12-18 18:59:25.955 [29638] main/326/main replicaset.lua:614 E> Exception during calling 'vshard.storage.call' (trace_id = <...>) on 'filedb_001_2([email protected]:5003)': Timeout exceeded

---

Even if trace_id is not passed, I propose to automatically set it, we can use monotonically growing number (we should take care of integer overflow). It will majorly boost the readability of the logs.

[Gerold103]

we should take care of integer overflow

I wouldn't care about an integer overflow. If you use just a regular Lua number, it is a double, which fits up to 2^53 without precision loss. That means 100 days of making a new request every nanosecond. If you use long long (in Lua you can declare it same as in C, like 123LL), then its overflow will take approx 600 years (making request every nanosecond).

[sergepetrenko]

I think trace_id should be understood by tarantool core. We can make it an iproto call parameter, and then all the modules (vshard, crud) and connectors may start supporting it as well.

At the very least, trace_id may be printed with every log line, like it's done for fiber_id. And later we could even aggregate some call statistics by trace. For example, number of tuples viewed/modified/inserted, cpu time used and so on.

[Gerold103]

Actually amazing idea, @sergepetrenko! Would you open a ticket in core?

[sergepetrenko]

Sure thing: tarantool/tarantool#11059