[Openvpn-devel,v2,4/4] Log peer-id if loglevel is D_DCO_DEBUG and dco is enabled

Message ID 20221227022404.3468137-4-arne@rfc2549.org
State Changes Requested
Headers show
Series [Openvpn-devel,v2,1/4] Ensure we do not promote a TA_TIMEOUT to a TA_READ event with dco | expand

Commit Message

Arne Schwabe Dec. 27, 2022, 2:24 a.m. UTC
This enables logging the peer id in p2mp mode if dco is enabled
and the log level is high enough

Signed-off-by: Arne Schwabe <arne@rfc2549.org>
---
 src/openvpn/multi.c | 6 ++++++
 1 file changed, 6 insertions(+)

Comments

Gert Doering Dec. 27, 2022, 10:12 a.m. UTC | #1
Hi,

On Tue, Dec 27, 2022 at 03:24:04AM +0100, Arne Schwabe wrote:
> This enables logging the peer id in p2mp mode if dco is enabled
> and the log level is high enough

Ho hum, this does not work for me...

TLS/TCP server, DCO enabled, --verb 6...

2022-12-27 11:05:41 us=111855 something/194.97.140.21:16006 dco_do_write: peer-id 0, len=390
2022-12-27 11:05:41 us=111931 something/194.97.140.21:16006 dco_update_keys: peer_id=0
2022-12-27 11:05:42 us=173611 dco_do_read
2022-12-27 11:05:42 us=173764 ovpn-dco: received OVPN_PACKET_ATTR_PACKET, ifindex: 32018 peer-id: 0, len 22
2022-12-27 11:05:42 us=173825 something/194.97.140.21:16006 TCPv6_SERVER READ [22] from [AF_INET6]::ffff:194.97.140.21:16006: P_ACK_V1 kid=0 [ 5 ] DATA len=0
2022-12-27 11:05:42 us=267059 something/194.97.140.21:16006 dco_update_keys: peer_id=0
2022-12-27 11:05:43 us=423410 something/194.97.140.21:16006 dco_update_keys: peer_id=0
2022-12-27 11:05:58 us=584121 something/194.97.140.21:16006 dco_update_keys: peer_id=0

... there *should* be a peer-id somewhere in that line...

Playing around with the patch a bit, the offending piece seems to be
"mi->context.options.verbosity >= D_DCO_DEBUG" - which is unsurprising,
as D_DCO_DEBUG is not "6" but "LOGLEV(6, 69, M_DEBUG)", which translates
to 

  #define LOGLEV(log_level, mute_level, other) ((log_level) | ENCODE_MUTE_LEVEL(mute_level) | other)

(numerically, D_DCO_DEBUG = 1157628038)


The test for dco_enabled() works.

gert
Gert Doering Jan. 10, 2023, 1:42 p.m. UTC | #2
Hi,

On Tue, Dec 27, 2022 at 11:12:44AM +0100, Gert Doering wrote:
> Playing around with the patch a bit, the offending piece seems to be
> "mi->context.options.verbosity >= D_DCO_DEBUG" - which is unsurprising,
> as D_DCO_DEBUG is not "6" but "LOGLEV(6, 69, M_DEBUG)", which translates
> to 
> 
>   #define LOGLEV(log_level, mute_level, other) ((log_level) | ENCODE_MUTE_LEVEL(mute_level) | other)
> 
> (numerically, D_DCO_DEBUG = 1157628038)

... looking at error.h, there is a "check_debug_level(flags)" thing, so
changing the condition to

+        if (mi->context.c2.tls_multi
+            // && mi->context.options.verbosity >= D_DCO_DEBUG
+            && check_debug_level(D_DCO_DEBUG)
+            && dco_enabled(&mi->context.options))
+        {
+            buf_printf(&out, " peer-id=%d", mi->context.c2.tls_multi->peer_id);
+        }

works - "if --verb 6 or higher, *and* DCO, then have peer-id=%d as part
if the prefix".

Can you resend a v3?

gert

Patch

diff --git a/src/openvpn/multi.c b/src/openvpn/multi.c
index 50d88f19a..f8366be28 100644
--- a/src/openvpn/multi.c
+++ b/src/openvpn/multi.c
@@ -473,6 +473,12 @@  multi_instance_string(const struct multi_instance *mi, bool null, struct gc_aren
             buf_printf(&out, "%s/", cn);
         }
         buf_printf(&out, "%s", mroute_addr_print(&mi->real, gc));
+        if (mi->context.c2.tls_multi
+            && mi->context.options.verbosity >= D_DCO_DEBUG
+            && dco_enabled(&mi->context.options))
+        {
+            buf_printf(&out, " peer-id=%d", mi->context.c2.tls_multi->peer_id);
+        }
         return BSTR(&out);
     }
     else if (null)