diff mbox series

[netifd] netifd-proto.sh: Add PROTO_DEBUG and proto_debug_*()

Message ID 20201229233319.164640-1-me@irrelefant.net
State New
Headers show
Series [netifd] netifd-proto.sh: Add PROTO_DEBUG and proto_debug_*() | expand

Commit Message

Leonardo Mörlein Dec. 29, 2020, 11:33 p.m. UTC
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 <me@irrelefant.net>
---
 scripts/netifd-proto.sh | 112 ++++++++++++++++++++++++++++++++++++++++
 1 file changed, 112 insertions(+)
diff mbox series

Patch

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() {