Improve SQM_VERBOSITY handling

sqm scripts now will take the requested log level for each
sqm_logger call as second argument. If the second argument is
omitted it defaults to VERBOSITY_NORMAL. This commit
also modifies run.sh so thaty on openwrt a call like:
SQM_VERBOSITY=2 /etc/init.d/sqm start
will override the setting of SQM_VERBOSITY in luci-app-sqm,
just like SQM_DEBUG can be used on the command line.

Signed-off-by: Sebastian Moeller <moeller0@gmx.de>

src/functions.sh

@@ -6,14 +6,19 @@
 
 #improve the logread output, but allow silencing it, if verbosity is set to 0
 sqm_logger() {
+    local CUR_VERBOSITY=""
+    [ -z "$2" ] && REQUESTED_LOG_LEVEL=${VERBOSITY_NORMAL} || REQUESTED_LOG_LEVEL=${2}
+
     if [ "$SQM_VERBOSITY" -gt "$VERBOSITY_SILENT" ] ; then
-	if [ "$SQM_SYSLOG" -eq "1" ]; then
-    	    logger -t SQM -s "$*"
-	else
-    	    echo "$@" >&2
+	if [ "${SQM_VERBOSITY}" -ge "${REQUESTED_LOG_LEVEL}" ] ; then
+	    if [ "$SQM_SYSLOG" -eq "1" ]; then
+    		logger -t SQM -s "$*"
+	    else
+    		echo "$@" >&2
+	    fi
+	    #sm: slightly dangerous as this will keep adding to the log file
+	    [ -n "${SQM_DEBUG}" -a "${SQM_DEBUG}" == 1 ] && echo "$@" >> ${SQM_DEBUG_LOG}
 	fi
-	#sm: slightly dangerous as this will keep adding to the log file
-	[ -n "${SQM_DEBUG}" -a "${SQM_DEBUG}" == 1 ] && echo "$@" >> ${SQM_DEBUG_LOG}
     fi
 }
 
@@ -42,7 +47,7 @@ ipt() {
 #sm: wrapper to call tc to allow debug logging 
 tc_wrapper() {
     tc_args=$*
-    [ "$SQM_VERBOSITY" -gt "$VERBOSITY_VERBOSE" ] && sqm_logger "tc arguments: $tc_args"
+    sqm_logger "tc arguments: $tc_args" "${VERBOSITY_TOO_MUCH}"
     [ "${SQM_DEBUG}" == 1 ] && echo "${TC_BINARY} $*" >> ${SQM_DEBUG_LOG}
     ${TC_BINARY} $* >> ${OUTPUT_TARGET} 2>&1
 }
@@ -50,7 +55,7 @@ tc_wrapper() {
 #sm: wrapper to call tc to allow debug logging 
 ip_wrapper() {
     ip_args=$*
-    [ "$SQM_VERBOSITY" -gt "$VERBOSITY_VERBOSE" ] && sqm_logger "ip arguments: $ip_args"
+    sqm_logger "ip arguments: $ip_args" "${VERBOSITY_TOO_MUCH}"
     [ "${SQM_DEBUG}" == 1 ] && echo "${IP_BINARY} $*" >> ${SQM_DEBUG_LOG}
     ${IP_BINARY} $* >> ${OUTPUT_TARGET} 2>&1
 }
@@ -80,7 +85,7 @@ get_ifb_associated_with_if() {
     # CUR_IFB=$( $TC -p filter show parent ffff: dev ${CUR_IF} | grep -o -e ifb'[[:digit:]]\+' )
     #local CUR_IFB=$( $TC -p filter show parent ffff: dev ${CUR_IF} | grep -o -e ifb'[^)]\+' )    # my editor's syntax coloration is limitied so I need a single quote in this line (between eiditor and s)
     local CUR_IFB=$( $TC -p filter show parent ffff: dev ${CUR_IF} | grep -o -E ifb'[^)\ ]+' )    # my editor's syntax coloration is limitied so I need a single quote in this line (between eiditor and s)
-    [ "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ] && sqm_logger "ifb associated with interface ${CUR_IF}: ${CUR_IFB}"
+    sqm_logger "ifb associated with interface ${CUR_IF}: ${CUR_IFB}" "${VERBOSITY_VERBOSE}"
     #sm: we could not detect an associated IFB for CUR_IF
     if [ -z "${CUR_IFB}" ]; 
     then
@@ -94,7 +99,7 @@ get_ifb_associated_with_if() {
 	    sqm_logger "Please report this as an issue at https://github.com/tohojo/sqm-scripts"
 	    sqm_logger "Please copy and paste everything below the cut-here line into your issue report, thanks."
 	else
-	    [ "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ] && sqm_logger "Currently no ifb is associated with ${CUR_IF}, this is normal during starting of the sqm system."
+	    sqm_logger "Currently no ifb is associated with ${CUR_IF}, this is normal during starting of the sqm system." "${VERBOSITY_VERBOSE}"
 	fi
     fi
     echo ${CUR_IFB}
@@ -147,7 +152,7 @@ get_ifb_for_if() {
     # if an ifb is already associated return that
     local CUR_IFB=$( get_ifb_associated_with_if ${CUR_IF} )
     [ -z "$CUR_IFB" ] && CUR_IFB=$( create_new_ifb_for_if ${CUR_IF} )
-    [ -z "$CUR_IFB" ] && sqm_logger "Could not find existing IFB for ${CUR_IF}, nor create a new IFB instead..."
+    [ -z "$CUR_IFB" ] && sqm_logger "Could not find existing IFB for ${CUR_IF}, nor create a new IFB instead..." "${VERBOSITY_NORMAL}"
     echo ${CUR_IFB}
 }
 
@@ -180,7 +185,7 @@ verify_qdisc() {
     $TC qdisc replace dev $ifb $root_string $qdisc #>>${OUTPUT_TARGET} 2>&1
     res=$?
     [ "$res" = "0" ] || not="NOT "
-    [ "$res" != "0" -o "(" "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ")" ] && sqm_logger "QDISC $qdisc is ${not}useable."
+    [ "$res" != "0" -o "(" "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ")" ] && sqm_logger "QDISC $qdisc is ${not}useable." "${VERBOSITY_VERBOSE}"
     delete_ifb $ifb
     return $res
 }
@@ -193,7 +198,7 @@ get_htb_adsll_string() {
         # HTB defaults to MTU 1600 and an implicit fixed TSIZE of 256, but HTB as of around 3.10.0
         # does not actually use a table in the kernel
         ADSLL="mpu ${STAB_MPU} linklayer ${LINKLAYER} overhead ${OVERHEAD} mtu ${STAB_MTU}"
-        [ "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ] && sqm_logger "ADSLL: ${ADSLL}"
+        sqm_logger "ADSLL: ${ADSLL}" "${VERBOSITY_VERBOSE}"
     fi
     echo ${ADSLL}
 }
@@ -203,7 +208,7 @@ get_stab_string() {
     if [ "${LLAM}" = "tc_stab" -a "$LINKLAYER" != "none" ];
     then
         STABSTRING="stab mtu ${STAB_MTU} tsize ${STAB_TSIZE} mpu ${STAB_MPU} overhead ${OVERHEAD} linklayer ${LINKLAYER}"
-        [ "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ] && sqm_logger "STAB: ${STABSTRING}"
+        sqm_logger "STAB: ${STABSTRING}" "${VERBOSITY_VERBOSE}"
     fi
     echo ${STABSTRING}
 }
@@ -219,7 +224,7 @@ get_cake_lla_string() {
         fi
 
         STABSTRING="${STABSTRING} overhead ${OVERHEAD}"
-        [ "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ] && sqm_logger "cake link layer adjustments: ${STABSTRING}"
+        sqm_logger "cake link layer adjustments: ${STABSTRING}" "${VERBOSITY_VERBOSE}"
     fi
     echo ${STABSTRING}
 }
@@ -229,7 +234,7 @@ sqm_stop() {
     $TC qdisc del dev $IFACE ingress #2>> ${OUTPUT_TARGET}
     $TC qdisc del dev $IFACE root #2>> ${OUTPUT_TARGET}
     [ -n "$CUR_IFB" ] && $TC qdisc del dev $CUR_IFB root #2>> ${OUTPUT_TARGET}
-    [ -n "$CUR_IFB" -a "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ] && sqm_logger "${0}: ${CUR_IFB} shaper deleted"
+    [ -n "$CUR_IFB" ] && sqm_logger "${0}: ${CUR_IFB} shaper deleted" "${VERBOSITY_VERBOSE}"
 
     [ -n "$CUR_IFB" ] && ipt -t mangle -D POSTROUTING -o $CUR_IFB -m mark --mark 0x00 -g QOS_MARK_${IFACE}
     ipt -t mangle -D POSTROUTING -o $IFACE -m mark --mark 0x00${IPT_MASK_STRING} -g QOS_MARK_${IFACE}
@@ -245,7 +250,7 @@ sqm_stop() {
 
     [ -n "$CUR_IFB" ] && $IP link set dev ${CUR_IFB} down
     [ -n "$CUR_IFB" ] && $IP link delete ${CUR_IFB} type ifb
-    [ -n "$CUR_IFB" ] && sqm_logger "${0}: ${CUR_IFB} interface deleted"
+    [ -n "$CUR_IFB" ] && sqm_logger "${0}: ${CUR_IFB} interface deleted" "${VERBOSITY_NORMAL}"
 }
 # Note this has side effects on the prio variable
 # and depends on the interface global too
@@ -316,7 +321,7 @@ get_htb_quantum() {
         CUR_QUANTUM=$((${CUR_QUANTUM} * 2))
     fi
 
-    [ "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ] && sqm_logger "CUR_HTB_QUANTUM: ${CUR_QUANTUM}, BANDWIDTH: ${BANDWIDTH}"
+    sqm_logger "CUR_HTB_QUANTUM: ${CUR_QUANTUM}, BANDWIDTH: ${BANDWIDTH}" "${VERBOSITY_VERBOSE}"
 
     echo $CUR_QUANTUM
 }
@@ -326,7 +331,7 @@ get_htb_quantum() {
 # but I fear we actually need the wire size of the whole thing not so much the MTU
 get_mtu() {
     CUR_MTU=$(cat /sys/class/net/$1/mtu)
-    [ "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ] && sqm_logger "IFACE: ${1} MTU: ${CUR_MTU}"
+    sqm_logger "IFACE: ${1} MTU: ${CUR_MTU}" "${VERBOSITY_VERBOSE}"
     echo ${CUR_MTU}
 }
 
@@ -370,7 +375,7 @@ get_flows_count() {
 get_target() {
     local CUR_TARGET=${1}
     local CUR_LINK_KBPS=${2}
-    [ ! -z "$CUR_TARGET" ] && sqm_logger "cur_target: ${CUR_TARGET} cur_bandwidth: ${CUR_LINK_KBPS}"
+    [ ! -z "$CUR_TARGET" ] && sqm_logger "cur_target: ${CUR_TARGET} cur_bandwidth: ${CUR_LINK_KBPS}" "${VERBOSITY_NORMAL}"
     CUR_TARGET_STRING=
     # either e.g. 100ms or auto
     CUR_TARGET_VALUE=$( echo ${CUR_TARGET} | grep -o -e \^'[[:digit:]]\+' )
@@ -402,9 +407,9 @@ get_target() {
                     TMP_INTERVAL_STRING=$( adapt_interval_to_slow_link $TMP_TARGET_US )
                     CUR_TARGET_STRING="target ${TMP_TARGET_US}us ${TMP_INTERVAL_STRING}"
                     AUTO_TARGET="1"
-                    [ "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ] && sqm_logger "get_target defaulting to auto."
+                    sqm_logger "get_target defaulting to auto." "${VERBOSITY_VERBOSE}"
                 else
-                    sqm_logger "required link bandwidth in kbps not passed to get_target()."
+                    sqm_logger "required link bandwidth in kbps not passed to get_target()." "${VERBOSITY_NORMAL}"
                 fi
             fi
             # but still allow explicit use of the keyword auto for backward compatibility
@@ -417,7 +422,7 @@ get_target() {
                         CUR_TARGET_STRING="target ${TMP_TARGET_US}us ${TMP_INTERVAL_STRING}"
                         AUTO_TARGET="1"
                     else
-                        sqm_logger "required link bandwidth in kbps not passed to get_target()."
+                        sqm_logger "required link bandwidth in kbps not passed to get_target()." "${VERBOSITY_NORMAL}"
                     fi
                     ;;
             esac
@@ -428,9 +433,9 @@ get_target() {
                     then
                         CUR_TARGET_STRING=""    # return nothing so the default target is not over-ridden...
                         AUTO_TARGET="1"
-                        [ "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ] && sqm_logger "get_target using qdisc default, no explicit target string passed."
+                        sqm_logger "get_target using qdisc default, no explicit target string passed." "${VERBOSITY_VERBOSE}"
                     else
-                        sqm_logger "required link bandwidth in kbps not passed to get_target()."
+                        sqm_logger "required link bandwidth in kbps not passed to get_target()." "${VERBOSITY_NORMAL}"
                     fi
                     ;;
             esac
@@ -438,7 +443,7 @@ get_target() {
             then
                 if [ -z "${CUR_TARGET_VALUE}" -o -z "${UNIT_VALID}" ];
                 then
-                    [ -z "$AUTO_TARGET" ] && sqm_logger "${CUR_TARGET} is not a well formed tc target specifier; e.g.: 5ms (or s, us), or one of the strings auto or default."
+                    [ -z "$AUTO_TARGET" ] && sqm_logger "${CUR_TARGET} is not a well formed tc target specifier; e.g.: 5ms (or s, us), or one of the strings auto or default." "${VERBOSITY_NORMAL}"
                 fi
             fi
             ;;
@@ -499,10 +504,10 @@ get_limit() {
                                           ;;
         bfifo) [ -z "$CURLIMIT" ] && [ ! -z "$LIMIT" ] && CURLIMIT=$(( ${LIMIT} * $( cat /sys/class/net/${IFACE}/mtu ) ))    # bfifo defaults to txquelength * MTU,
                ;;
-        *) sqm_logger "${QDISC} does not support a limit"
+        *) sqm_logger "${QDISC} does not support a limit" "${VERBOSITY_NORMAL}"
            ;;
     esac
-    [ "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ] && sqm_logger "get_limit: $1 CURLIMIT: ${CURLIMIT}"
+    sqm_logger "get_limit: $1 CURLIMIT: ${CURLIMIT}" "${VERBOSITY_VERBOSE}"
 
     if [ ! -z "$CURLIMIT" ]
     then
@@ -535,10 +540,10 @@ get_ecn() {
             esac
             ;;
         *)
-            sqm_logger "ecn value $1 not handled"
+            sqm_logger "ecn value $1 not handled" "${VERBOSITY_NORMAL}"
             ;;
     esac
-    [ "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ] && sqm_logger "get_ECN: $1 CURECN: ${CURECN} IECN: ${IECN} EECN: ${EECN}"
+    sqm_logger "get_ECN: $1 CURECN: ${CURECN} IECN: ${IECN} EECN: ${EECN}" "${VERBOSITY_VERBOSE}"
     echo ${CURECN}
 
 }

src/run-openwrt.sh

@@ -55,14 +55,16 @@ run_sqm_scripts() {
     export TARGET=$(config_get "$section" target)
     export SQUASH_DSCP=$(config_get "$section" squash_dscp)
     export SQUASH_INGRESS=$(config_get "$section" squash_ingress)
-    export SQM_VERBOSITY=$(config_get "$section" verbosity)
 
     export QDISC=$(config_get "$section" qdisc)
     export SCRIPT=$(config_get "$section" script)
 
 
-    #sm: if SQM_DEBUG was passed in via the command line make it available to the other scripts
+    #sm: if SQM_DEBUG or SQM_VERBOSITY were passed in via the command line make them available to the other scripts
     [ -n "$SQM_DEBUG" ] && export SQM_DEBUG || export SQM_DEBUG=$(config_get "$section" debug_logging)
+    [ -n "$SQM_VERBOSITY" ] && export SQM_VERBOSITY || export SQM_VERBOSITY=$(config_get "$section" verbosity)
+    
+    
 
     #sm: only stop-sqm if there is something running
     CUR_STATE_FILE="${SQM_STATE_DIR}/${IFACE}.state"

src/start-sqm

@@ -17,30 +17,30 @@ STATE_FILE="${SQM_STATE_DIR}/${IFACE}.state"
 [ -d "${SQM_STATE_DIR}" ] || mkdir -p "${SQM_STATE_DIR}"
 
 if [ -f "${STATE_FILE}" ]; then
-    [ "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ] && sqm_logger "SQM already activated on ${IFACE}."
+    sqm_logger "SQM already activated on ${IFACE}." "${VERBOSITY_VERBOSE}"
     exit 1
 fi
 
 # in case of spurious hotplug events, try double check whether the interface is really up
 if [ ! -d /sys/class/net/${IFACE} ] ; then
-    [ "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ] && sqm_logger "${IFACE} does currently not exist, not even trying to start SQM on nothing."
+    sqm_logger "${IFACE} does currently not exist, not even trying to start SQM on nothing." "${VERBOSITY_VERBOSE}"
     exit 1
 fi
 
 if [ "${ENABLED:-1}" -ne "1" ]; then
-    [ "$SQM_VERBOSITY" -gt "$VERBOSITY_NORMAL" ] && sqm_logger "SQM config disabled on ${IFACE}."
+    sqm_logger "SQM config disabled on ${IFACE}." "${VERBOSITY_VERBOSE}"
     exit 0
 fi
 
 if [ ! -f "${SQM_LIB_DIR}/$SCRIPT" ]; then
-    sqm_logger "SQM script ${SCRIPT} not found!"
+    sqm_logger "SQM script ${SCRIPT} not found!" "${VERBOSITY_NORMAL}"
     exit 1
 fi
 
 . "${SQM_LIB_DIR}/$SCRIPT"
 
-[ "${SQM_DEBUG}" == 1 ] && echo -e "\n$( date ): Starting SQM script: ${SCRIPT} on ${IFACE}, in: ${DOWNLINK} Kbps, out: ${UPLINK} Kbps" >> ${SQM_DEBUG_LOG}
-sqm_logger "${0}: Starting SQM script: ${SCRIPT} on ${IFACE}, in: ${DOWNLINK} Kbps, out: ${UPLINK} Kbps"
+[ "${SQM_DEBUG}" == 1 ] && echo -e "\n\n\n$( date ): Starting SQM script: ${SCRIPT} on ${IFACE}, in: ${DOWNLINK} Kbps, out: ${UPLINK} Kbps\n" >> ${SQM_DEBUG_LOG}
+sqm_logger "${0}: Starting SQM script: ${SCRIPT} on ${IFACE}, in: ${DOWNLINK} Kbps, out: ${UPLINK} Kbps" "${VERBOSITY_NORMAL}"
 sqm_start && write_state_file ${STATE_FILE} ${ALL_SQM_VARS}
 
 exit 0

src/stop-sqm

@@ -15,15 +15,15 @@
 . ${SQM_LIB_DIR}/defaults.sh    #sm: this should allow debugging output for sqm_logger...
 STATE_FILE="${SQM_STATE_DIR}/${IFACE}.state"
 
-[ "${SQM_DEBUG}" == 1 ] && echo -e "\n\n\n$( date ): Stopping SQM on ${IFACE}" >> ${SQM_DEBUG_LOG}
-sqm_logger "${0}: Stopping SQM on ${IFACE}"
+[ "${SQM_DEBUG}" == 1 ] && echo -e "\n\n\n$( date ): Stopping SQM on ${IFACE}\n" >> ${SQM_DEBUG_LOG}
+sqm_logger "${0}: Stopping SQM on ${IFACE}" "${VERBOSITY_NORMAL}"
 
 # make sure to only delete the ifb associated with the current interface
 CUR_IFB=$( get_ifb_associated_with_if ${IFACE} )
 [ -z "$CUR_IFB" ] && CUR_IFB=$( ifb_name ${IFACE} )
 
 if [ ! -f "${SQM_LIB_DIR}/$SCRIPT" ]; then
-    sqm_logger "SQM script ${SCRIPT} not found!"
+    sqm_logger "SQM script ${SCRIPT} not found!" "${VERBOSITY_NORMAL}"
     exit 1
 fi