From: Thomas Lamprecht <t.lamprecht@proxmox.com>
To: "Proxmox VE development discussion" <pve-devel@lists.proxmox.com>,
"Laurențiu Leahu-Vlăducu" <l.leahu-vladucu@proxmox.com>
Subject: Re: [pve-devel] [PATCH pve-http-server] AnyEvent: add timestamps to debug logs
Date: Mon, 13 Oct 2025 19:01:08 +0200 [thread overview]
Message-ID: <03570e57-30cf-4a1d-81c7-33af9ca19596@proxmox.com> (raw)
In-Reply-To: <20251002162825.311357-1-l.leahu-vladucu@proxmox.com>
Am 02.10.25 um 18:28 schrieb Laurențiu Leahu-Vlăducu:
> This helps correlate our debug logs with other log files for
> easier debugging when making API calls.
>
> Signed-off-by: Laurențiu Leahu-Vlăducu <l.leahu-vladucu@proxmox.com>
> ---
> 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..cdc82b2 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";
would not include the " |" part as it's not really standardized format,
a simple space should be enough (closer to like e.g. journalctl prints).
And FWIW, I benchmarked this, i.e. the gettimeofday and strftime calls
separate and together:
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
So FWIW, this is not really cheap and adds ~5.7 µs delay on every print.
It IMO would be slightly nicer to split the debug option into debug and
foreground options in PVE::Daemon so that one can enable debug output
without running in foreground, as then a simple systemd service override [0]
could be used to allow the debug logs to land in the journal, which already
got efficient and precise time stamping available.
But not sure if it helps the rather limited integrators in your case that
this patch originated from, so if you think it's worth it I can apply this
as is for now.
[0]:
# /etc/systemd/system/pveproxy.service.d/override.conf
[Service]
ExecStart=
ExecStart=/usr/bin/pveproxy start --debug
> }
>
> sub log_request {
_______________________________________________
pve-devel mailing list
pve-devel@lists.proxmox.com
https://lists.proxmox.com/cgi-bin/mailman/listinfo/pve-devel
next prev parent reply other threads:[~2025-10-13 17:00 UTC|newest]
Thread overview: 3+ messages / expand[flat|nested] mbox.gz Atom feed top
2025-10-02 16:28 Laurențiu Leahu-Vlăducu
2025-10-13 17:01 ` Thomas Lamprecht [this message]
2025-10-14 9:49 ` Laurențiu Leahu-Vlăducu
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=03570e57-30cf-4a1d-81c7-33af9ca19596@proxmox.com \
--to=t.lamprecht@proxmox.com \
--cc=l.leahu-vladucu@proxmox.com \
--cc=pve-devel@lists.proxmox.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox