From patchwork Tue Dec 29 23:33:19 2020 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-Patchwork-Submitter: =?utf-8?q?Leonardo_M=C3=B6rlein?= X-Patchwork-Id: 1421294 Return-Path: X-Original-To: incoming@patchwork.ozlabs.org Delivered-To: patchwork-incoming@bilbo.ozlabs.org Authentication-Results: ozlabs.org; spf=pass (sender SPF authorized) smtp.mailfrom=lists.openwrt.org (client-ip=2001:8b0:10b:1231::1; helo=merlin.infradead.org; envelope-from=openwrt-devel-bounces+incoming=patchwork.ozlabs.org@lists.openwrt.org; receiver=) Authentication-Results: ozlabs.org; dmarc=none (p=none dis=none) header.from=irrelefant.net Authentication-Results: ozlabs.org; dkim=pass (2048-bit key; secure) header.d=lists.infradead.org header.i=@lists.infradead.org header.a=rsa-sha256 header.s=merlin.20170209 header.b=EduHY6Tt; dkim-atps=neutral Received: from merlin.infradead.org (merlin.infradead.org [IPv6:2001:8b0:10b:1231::1]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256) (No client certificate requested) by ozlabs.org (Postfix) with ESMTPS id 4D59m81CQZz9sVs for ; Wed, 30 Dec 2020 10:36:23 +1100 (AEDT) DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=lists.infradead.org; s=merlin.20170209; h=Sender:Content-Transfer-Encoding: Content-Type:Cc:List-Subscribe:List-Help:List-Post:List-Archive: List-Unsubscribe:List-Id:MIME-Version:Message-Id:Date:Subject:To:From: Reply-To:Content-ID:Content-Description:Resent-Date:Resent-From:Resent-Sender :Resent-To:Resent-Cc:Resent-Message-ID:In-Reply-To:References:List-Owner; bh=+84Mhk6tSP5DJDEIHos9Dib0zlVqPuvIjEo96KUCPWM=; b=EduHY6TtGY8fl06NHBIz7FOiTh ++5EYyTqDGwZjIBpe643g2PaYrAhQn2+kCOGQDl/BZHX7txWpHG3UFKbr0ROjIUevrIhx9A0UeM5j 5kq6+RdFIdvQfo4UWCjrRaVfqh8WYKI9pWyHqnMBeQOYMK8ni1bSqFNy2VsekHipSVydbIafNrl4/ FWkrVi7chFSzX+LgLlRtkEW1M/hosF7vuas2YZchsp9gvwEN3bKJFOK8KL2hyb8WOaFlb/f3T0RuT 2aUdX17IB9JpR2obutoQNWyTVTRLlKi9pomEzZ8oLdlRUle2PlFb7h94YkTxK3YWl6Y0FSMxIBJex Ng+tNC7A==; Received: from localhost ([::1] helo=merlin.infradead.org) by merlin.infradead.org with esmtp (Exim 4.92.3 #3 (Red Hat Linux)) id 1kuOUd-0003xd-A1; Tue, 29 Dec 2020 23:33:31 +0000 Received: from smtprelay04.ispgateway.de ([80.67.18.16]) by merlin.infradead.org with esmtps (Exim 4.92.3 #3 (Red Hat Linux)) id 1kuOUZ-0003xG-2o for openwrt-devel@lists.openwrt.org; Tue, 29 Dec 2020 23:33:28 +0000 Received: from [81.3.6.94] (helo=orange.ffh.zone) by smtprelay04.ispgateway.de with esmtpsa (TLSv1.2:ECDHE-RSA-AES128-GCM-SHA256:128) (Exim 4.92.3) (envelope-from ) id 1kuOTd-0004RQ-UU; Wed, 30 Dec 2020 00:32:30 +0100 From: =?utf-8?q?Leonardo_M=C3=B6rlein?= To: openwrt-devel@lists.openwrt.org Subject: [PATCH netifd] netifd-proto.sh: Add PROTO_DEBUG and proto_debug_*() Date: Wed, 30 Dec 2020 00:33:19 +0100 Message-Id: <20201229233319.164640-1-me@irrelefant.net> X-Mailer: git-send-email 2.29.2 MIME-Version: 1.0 X-Df-Sender: bWVAaXJyZWxlZmFudC5uZXQ= X-CRM114-Version: 20100106-BlameMichelson ( TRE 0.8.0 (BSD) ) MR-646709E3 X-CRM114-CacheID: sfid-20201229_183327_339883_A4C8F366 X-CRM114-Status: GOOD ( 14.23 ) X-Spam-Score: 0.0 (/) X-Spam-Report: SpamAssassin version 3.4.4 on merlin.infradead.org summary: Content analysis details: (0.0 points) pts rule name description ---- ---------------------- -------------------------------------------------- 0.0 RCVD_IN_MSPIKE_H3 RBL: Good reputation (+3) [80.67.18.16 listed in wl.mailspike.net] -0.0 SPF_HELO_PASS SPF: HELO matches SPF record 0.0 SPF_NONE SPF: sender does not publish an SPF Record 0.0 RCVD_IN_MSPIKE_WL Mailspike good senders X-BeenThere: openwrt-devel@lists.openwrt.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: OpenWrt Development List List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: =?utf-8?q?Leonardo_M=C3=B6rlein?= , Felix Fietkau Sender: "openwrt-devel" Errors-To: openwrt-devel-bounces+incoming=patchwork.ozlabs.org@lists.openwrt.org In order to ease the debugging of netifd protos, this commit adds a flag PROTO_DEBUG, that dumps all proto_* and json_* calls in protos. This relies on the fact, that netifd already forwards stderr of protos to the syslog. The feature can be activated by adding PROTO_DEBUG=1 in the beginning of the proto. Furthermore, we add the following two functions usable in the proto: proto_debug_print() - Can be used to print to the syslog adding a proper context to identify the source of the information. The print is ommitted if PROTO_DEBUG=0. proto_debug_dump_json() - Dumps the current jshn.sh stack to the syslog adding a proper context to identify the source of the information. The dump is ommitted if PROTO_DEBUG=0. To print the json_* calls, this commit is based on a patch just submitted to the queue for libubox: [PATCH libubox] sh/jshn.sh: Add JSHN_DEBUG flag Example for the vxlan proto. A debug print and a json dump have been added to the proto to show the behaviour in the example: --- snip syslog --- Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> json_get_vars ip6addr peer6addr tunlink Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> proto_add_host_dependency vx_mesh_vpn mesh_vpn Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> json_get_vars port vid ttl tos mtu macaddr zone rxcsum txcsum Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> proto_init_update vx_mesh_vpn 1 Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> proto_add_tunnel Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> json_add_string mode vxlan6 Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> json_add_string link mesh_vpn Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> json_add_string local fe80::2a4:18ff:fe7e:a10d Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> json_add_string remote fe80::1 Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> proto_debug_print This is a test print. The following dump_json is hacked into the proto: Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> proto_debug_dump_json { "action": 0, "ifname": "vx_mesh_vpn", "link-up": true, "tunnel": { "mode": "vxlan6", "link": "mesh_vpn", "local": "fe80::2a4:18ff:fe7e:a10d", "remote": "fe80::1" } } Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> json_add_object data Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> json_add_int id 12376034 Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> json_add_string macaddr da:2d:59:c4:41:2f Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> json_add_boolean rxcsum 0 Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> json_add_boolean txcsum 0 Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> json_close_object Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> proto_close_tunnel Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> proto_add_data Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> proto_close_data Wed Dec 30 00:04:07 2020 daemon.notice netifd: vx_mesh_vpn (25452): proto_vxlan6_setup(vx_mesh_vpn,) -> proto_send_update vx_mesh_vpn --- snap syslog --- Signed-off-by: Leonardo Mörlein --- scripts/netifd-proto.sh | 112 ++++++++++++++++++++++++++++++++++++++++ 1 file changed, 112 insertions(+) diff --git a/scripts/netifd-proto.sh b/scripts/netifd-proto.sh index 87d337d..76a6b85 100644 --- a/scripts/netifd-proto.sh +++ b/scripts/netifd-proto.sh @@ -4,52 +4,113 @@ PROTO_DEFAULT_OPTIONS="defaultroute peerdns metric" . /usr/share/libubox/jshn.sh . $NETIFD_MAIN_DIR/utils.sh +PROTO_DEBUG_DEPTH=0 +PROTO_DEBUG_STARTED=0 + +proto_debug_print() { + _proto_debug proto_debug_print "$@" + _proto_debug_end +} + +proto_debug_dump_json() { + JSHN_DEBUG=0 + _proto_debug proto_debug_dump_json "$(json_dump)" + JSHN_DEBUG="$PROTO_DEBUG" + _proto_debug_end +} + +_proto_debug_start() { + PROTO_DEBUG_CMD="$1($interface,$ifname) -> " + JSHN_DEBUG_PREFIX="$PROTO_DEBUG_CMD" + JSHN_DEBUG="$PROTO_DEBUG" + PROTO_DEBUG_STARTED=1 +} + +_proto_debug_stop() { + JSHN_DEBUG=0 + JSHN_DEBUG_PREFIX="" + PROTO_DEBUG_STARTED=0 +} + +_proto_debug() { + PROTO_DEBUG_DEPTH=$((PROTO_DEBUG_DEPTH+1)) + JSHN_DEBUG_DEPTH="$PROTO_DEBUG_DEPTH" + if [ -n "$PROTO_DEBUG" ] && [ "$PROTO_DEBUG" -eq 1 ] && \ + [ "$PROTO_DEBUG_DEPTH" -eq 1 ] && [ "$PROTO_DEBUG_STARTED" ]; then + echo "${PROTO_DEBUG_CMD}*" 1>&2 + fi +} + +_proto_debug_end() { + PROTO_DEBUG_DEPTH=$((PROTO_DEBUG_DEPTH-1)) + JSHN_DEBUG_DEPTH="$PROTO_DEBUG_DEPTH" +} + proto_config_add_int() { + _proto_debug proto_config_add_int "$@" config_add_int "$@" + _proto_debug_end } proto_config_add_string() { + _proto_debug proto_config_add_string "$@" config_add_string "$@" + _proto_debug_end } proto_config_add_boolean() { + _proto_debug proto_config_add_boolean "$@" config_add_boolean "$@" + _proto_debug_end } proto_config_add_array() { + _proto_debug proto_config_add_array "$@" config_add_array "$@" + _proto_debug_end } proto_config_add_defaults() { + _proto_debug proto_config_add_defaults "$@" proto_config_add_boolean "defaultroute" proto_config_add_boolean "peerdns" proto_config_add_int "metric" + _proto_debug_end } proto_add_dynamic_defaults() { + _proto_debug proto_add_dynamic_defaults "$@" [ -n "$defaultroute" ] && json_add_boolean defaultroute "$defaultroute" [ -n "$peerdns" ] && json_add_boolean peerdns "$peerdns" [ -n "$metric" ] && json_add_int metric "$metric" + _proto_debug_end } _proto_do_teardown() { json_load "$data" + _proto_debug_start "proto_$1_teardown" eval "proto_$1_teardown \"$interface\" \"$ifname\"" + _proto_debug_end } _proto_do_renew() { json_load "$data" + _proto_debug_start "proto_$1_renew" eval "proto_$1_renew \"$interface\" \"$ifname\"" + _proto_debug_stop } _proto_do_setup() { json_load "$data" _EXPORT_VAR=0 _EXPORT_VARS= + _proto_debug_start "proto_$1_setup" eval "proto_$1_setup \"$interface\" \"$ifname\"" + _proto_debug_stop } proto_init_update() { + _proto_debug proto_init_update "$@" local ifname="$1" local up="$2" local external="$3" @@ -71,60 +132,82 @@ proto_init_update() { [ -n "$ifname" -a "*" != "$ifname" ] && json_add_string "ifname" "$ifname" json_add_boolean "link-up" "$up" [ -n "$3" ] && json_add_boolean "address-external" "$external" + _proto_debug_end } proto_set_keep() { + _proto_debug proto_set_keep "$@" PROTO_KEEP="$1" + _proto_debug_end } proto_close_nested() { + _proto_debug proto_close_nested "$@" [ -n "$PROTO_NESTED_OPEN" ] && json_close_object PROTO_NESTED_OPEN= + _proto_debug_end } proto_add_nested() { + _proto_debug proto_add_nested "$@" PROTO_NESTED_OPEN=1 json_add_object "$1" + _proto_debug_end } proto_add_tunnel() { + _proto_debug proto_add_tunnel "$@" proto_add_nested "tunnel" + _proto_debug_end } proto_close_tunnel() { + _proto_debug proto_close_tunnel "$@" proto_close_nested + _proto_debug_end } proto_add_data() { + _proto_debug proto_add_data "$@" proto_add_nested "data" + _proto_debug_end } proto_close_data() { + _proto_debug proto_close_data "$@" proto_close_nested + _proto_debug_end } proto_add_dns_server() { + _proto_debug proto_add_dns_server "$@" local address="$1" append PROTO_DNS "$address" + _proto_debug_end } proto_add_dns_search() { + _proto_debug proto_add_dns_search "$@" local address="$1" append PROTO_DNS_SEARCH "$address" + _proto_debug_end } proto_add_ipv4_address() { + _proto_debug proto_add_ipv4_address "$@" local address="$1" local mask="$2" local broadcast="$3" local ptp="$4" append PROTO_IPADDR "$address/$mask/$broadcast/$ptp" + _proto_debug_end } proto_add_ipv6_address() { + _proto_debug proto_add_ipv6_address "$@" local address="$1" local mask="$2" local preferred="$3" @@ -133,26 +216,32 @@ proto_add_ipv6_address() { local class="$6" append PROTO_IP6ADDR "$address/$mask/$preferred/$valid/$offlink/$class" + _proto_debug_end } proto_add_ipv4_neighbor(){ + _proto_debug proto_add_ipv4_neighbor "$@" local address="$1" local mac="$2" local proxy="$3" append PROTO_NEIGHBOR "$address/$mac/$proxy" + _proto_debug_end } proto_add_ipv6_neighbor(){ + _proto_debug proto_add_ipv6_neighbor "$@" local address="$1" local mac="$2" local proxy="$3" local router="$4" append PROTO_NEIGHBOR6 "$address/$mac/$proxy/$router" + _proto_debug_end } proto_add_ipv4_route() { + _proto_debug proto_add_ipv4_route "$@" local target="$1" local mask="$2" local gw="$3" @@ -160,9 +249,11 @@ proto_add_ipv4_route() { local metric="$5" append PROTO_ROUTE "$target/$mask/$gw/$metric///$source" + _proto_debug_end } proto_add_ipv6_route() { + _proto_debug proto_add_ipv6_route "$@" local target="$1" local mask="$2" local gw="$3" @@ -172,9 +263,11 @@ proto_add_ipv6_route() { local table="$7" append PROTO_ROUTE6 "$target/$mask/$gw/$metric/$valid/$table/$source" + _proto_debug_end } proto_add_ipv6_prefix() { + _proto_debug proto_add_ipv6_prefix "$@" local prefix="$1" local valid="$2" local preferred="$3" @@ -185,6 +278,7 @@ proto_add_ipv6_prefix() { [ -z "$preferred" ] && preferred="$valid" append PROTO_PREFIX6 "$prefix,$valid,$preferred" fi + _proto_debug_end } _proto_push_ipv4_addr() { @@ -322,6 +416,7 @@ _proto_notify() { } proto_send_update() { + _proto_debug proto_send_update "$@" local interface="$1" proto_close_nested @@ -336,16 +431,20 @@ proto_send_update() { _proto_push_array "neighbor" "$PROTO_NEIGHBOR" _proto_push_ipv4_neighbor _proto_push_array "neighbor6" "$PROTO_NEIGHBOR6" _proto_push_ipv6_neighbor _proto_notify "$interface" + _proto_debug_end } proto_export() { + _proto_debug proto_export "$@" local var="VAR${_EXPORT_VAR}" _EXPORT_VAR="$(($_EXPORT_VAR + 1))" export -- "$var=$1" append _EXPORT_VARS "$var" + _proto_debug_end } proto_run_command() { + _proto_debug proto_run_command "$@" local interface="$1"; shift json_init @@ -364,18 +463,22 @@ proto_run_command() { json_close_array } _proto_notify "$interface" + _proto_debug_end } proto_kill_command() { + _proto_debug proto_kill_command "$@" local interface="$1"; shift json_init json_add_int action 2 [ -n "$1" ] && json_add_int signal "$1" _proto_notify "$interface" + _proto_debug_end } proto_notify_error() { + _proto_debug proto_notify_error "$@" local interface="$1"; shift json_init @@ -387,26 +490,32 @@ proto_notify_error() { done json_close_array _proto_notify "$interface" + _proto_debug_end } proto_block_restart() { + _proto_debug proto_block_restart "$@" local interface="$1"; shift json_init json_add_int action 4 _proto_notify "$interface" + _proto_debug_end } proto_set_available() { + _proto_debug proto_set_available "$@" local interface="$1" local state="$2" json_init json_add_int action 5 json_add_boolean available "$state" _proto_notify "$interface" + _proto_debug_end } proto_add_host_dependency() { + _proto_debug proto_add_host_dependency "$@" local interface="$1" local host="$2" local ifname="$3" @@ -420,13 +529,16 @@ proto_add_host_dependency() { [ -n "$ifname" ] && json_add_string ifname "$ifname" _proto_notify "$interface" -S ) + _proto_debug_end } proto_setup_failed() { + _proto_debug proto_setup_failed "$@" local interface="$1" json_init json_add_int action 7 _proto_notify "$interface" + _proto_debug_end } init_proto() {