[pve-devel] [PATCH pve-http-server v2] AnyEvent: add timestamps to debug logs

[Thomas Lamprecht]

Am 21.10.25 um 16:12 schrieb Laurențiu Leahu-Vlăducu:
> This helps correlate our debug logs with other log files for
> easier debugging when making API calls. This might ease debugging
> in our enterprise support and forum, or for external developers
> who need to debug Proxmox VE.
> 
> This patch does add some delay when printing debug logs (pointed out
> by Thomas):
> 
> elapsed[gettimeofday+strftime,1000000]: 5.730306 s => 5.730306 us/loop
> elapsed[strftime,             1000000]: 5.532132 s => 5.532132 us/loop
> elapsed[gettimeofday,         1000000]: 100.645 ms => 100.645 ns/loop
> 
> However, this only happens when printing debug logs, in which case
> it is often expected that software might be slightly slower.
> 
> Signed-off-by: Laurențiu Leahu-Vlăducu <l.leahu-vladucu at proxmox.com>
> Tested-by: Thomas Lamprecht <t.lamprecht at proxmox.com>
> Reviewed-by: Thomas Lamprecht <t.lamprecht at proxmox.com>
> ---
> 
> Changes since v1:
> * the separator '|' is no longer used after the timestamp
> * improved commit message
> * added Thomas' T-b and R-b 

But I did not gave those trailers out, or do I overlook something?
Please do not infer such things from some reply, they need to be
stated rather explicitly (transforming a "lgtm" to a R-b or the like
can be borderline fine, but rather also not something one should
just do.

> 
> 
>  src/PVE/APIServer/AnyEvent.pm | 4 +++-
>  1 file changed, 3 insertions(+), 1 deletion(-)
> 
> diff --git a/src/PVE/APIServer/AnyEvent.pm b/src/PVE/APIServer/AnyEvent.pm
> index 59bc184..24b298d 100644
> --- a/src/PVE/APIServer/AnyEvent.pm
> +++ b/src/PVE/APIServer/AnyEvent.pm
> @@ -76,7 +76,9 @@ sub dprint {
>  
>      my ($pkg, $pkgfile, $line, $sub) = caller(1);
>      $sub =~ s/^(?:.+::)+//;
> -    print "worker[$$]: $pkg +$line: $sub: $message\n";
> +    my ($secs, $microsecs) = gettimeofday();
> +    my $timestr = strftime("%F %T", localtime($secs)) . sprintf(".%06d", $microsecs);
> +    print "$timestr worker[$$]: $pkg +$line: $sub: $message\n";
>  }
>  
>  sub log_request {