snmp-ups: quiesce "unhandled ASN 0x80 received from ..." when we fall back to using the numeric value from last OID section

NEWS.adoc

@@ -218,6 +218,9 @@ https://github.com/networkupstools/nut/milestone/12
      mappings. Suggest how user can help improve the driver if too few data
      points were seen, or if the `mibs=auto` detection only found the fallback
      IETF mapping. [PR #3095]
+   * Quiesced "unhandled ASN 0x80 received from ..." messages when we fall
+     back to using the numeric value from last OID section. [issue #1358,
+     PE #3337]
    * Added new vendor extension mappings for Vertiv Liebert UPS, tested with
      PSI5-750MT120 UPS model and IS-UNITY-DP (Firmware 8.4.7.0) SNMP card.
      [issue #3296, PR #3299]

docs/nut.dict

@@ -1,4 +1,4 @@
-personal_ws-1.1 en 3687 utf-8
+personal_ws-1.1 en 3690 utf-8
 AAC
 AAS
 ABI
@@ -33,6 +33,7 @@ AQ
 ARB
 ARG
 ARS
+ASN
 ATEK
 ATR
 ATT
@@ -1086,6 +1087,7 @@ QVFW
 QWS
 QinHeng
 Quette
+Quiesced
 RBAC
 RBWARNTIME
 RDLCK
@@ -3450,6 +3452,7 @@ unconfigured
 undefine
 undervoltage
 unescaped
+unhandled
 unicast
 unicode
 uninstall

drivers/snmp-ups.c

@@ -179,7 +179,7 @@ static const char *mibname;
 static const char *mibvers;
 
 #define DRIVER_NAME	"Generic SNMP UPS driver"
-#define DRIVER_VERSION	"1.39"
+#define DRIVER_VERSION	"1.40"
 
 /* driver description structure */
 upsdrv_info_t	upsdrv_info = {
@@ -1284,7 +1284,7 @@ static void nut_snmp_free(struct snmp_pdu ** array_to_free)
 }
 
 /* Return a NULL terminated array of snmp_pdu * */
-static struct snmp_pdu **nut_snmp_walk(const char *OID, int max_iteration)
+static struct snmp_pdu **nut_snmp_walk(const char *OID, int max_iteration, int log_unhandled_loudly)
 {
 	int status;
 	struct snmp_pdu *pdu, *response = NULL;
@@ -1377,6 +1377,8 @@ static struct snmp_pdu **nut_snmp_walk(const char *OID, int max_iteration)
 			snmp_free_pdu(response);
 			break;
 		} else {
+			upsdebugx(3, "status = %i, response->errstat = %li", status, response->errstat);
+
 			/* Checked the "type" field of the returned varbind if
 			 * it is a type error exception (only applicable with
 			 * SNMPv2 or SNMPv3 protocol, would not happen with
@@ -1387,8 +1389,13 @@ static struct snmp_pdu **nut_snmp_walk(const char *OID, int max_iteration)
 			 || response->variables->type == SNMP_NOSUCHINSTANCE
 			 || response->variables->type == SNMP_ENDOFMIBVIEW
 			) {
-				upslogx(LOG_WARNING, "[%s] Warning: type error exception (OID = %s)",
+				if (log_unhandled_loudly) {
+					upslogx(LOG_WARNING, "[%s] Warning: type error exception (OID = %s)",
+						upsname?upsname:device_name, OID);
+				} else {
+					upsdebugx(2, "[%s] Warning: type error exception (OID = %s)",
 						upsname?upsname:device_name, OID);
+				}
 				snmp_free_pdu(response);
 				break;
 			}
@@ -1405,7 +1412,7 @@ static struct snmp_pdu **nut_snmp_walk(const char *OID, int max_iteration)
 			sizeof(struct snmp_pdu*) * ((size_t)nb_iteration+1)
 			);
 		if (new_ret_array == NULL) {
-			upsdebugx(1, "%s: Failed to realloc thread", __func__);
+			upsdebugx(1, "%s: Failed to realloc ret_array", __func__);
 			break;
 		}
 		else {
@@ -1423,7 +1430,7 @@ static struct snmp_pdu **nut_snmp_walk(const char *OID, int max_iteration)
 	return ret_array;
 }
 
-struct snmp_pdu *nut_snmp_get(const char *OID)
+static struct snmp_pdu *do_nut_snmp_get(const char *OID, int log_unhandled_loudly)
 {
 	struct snmp_pdu ** pdu_array;
 	struct snmp_pdu * ret_pdu;
@@ -1433,7 +1440,7 @@ struct snmp_pdu *nut_snmp_get(const char *OID)
 
 	upsdebugx(3, "%s(%s)", __func__, OID);
 
-	pdu_array = nut_snmp_walk(OID,1);
+	pdu_array = nut_snmp_walk(OID, 1, log_unhandled_loudly);
 
 	if(pdu_array == NULL) {
 		return NULL;
@@ -1446,6 +1453,11 @@ struct snmp_pdu *nut_snmp_get(const char *OID)
 	return ret_pdu;
 }
 
+struct snmp_pdu *nut_snmp_get(const char *OID)
+{
+	return do_nut_snmp_get(OID, 1);
+}
+
 static bool_t decode_str(struct snmp_pdu *pdu, char *buf, size_t buf_len, info_lkp_t *oid2info)
 {
 	size_t len = 0;
@@ -1605,7 +1617,7 @@ bool_t nut_snmp_get_oid(const char *OID, char *buf, size_t buf_len)
 	return ret;
 }
 
-bool_t nut_snmp_get_int(const char *OID, long *pval)
+static bool_t do_nut_snmp_get_int(const char *OID, long *pval, int log_unhandled_loudly)
 {
 	char tmp_buf[SU_LARGEBUF];
 	struct snmp_pdu *pdu;
@@ -1614,7 +1626,7 @@ bool_t nut_snmp_get_int(const char *OID, long *pval)
 
 	upsdebugx(3, "Entering %s()", __func__);
 
-	pdu = nut_snmp_get(OID);
+	pdu = do_nut_snmp_get(OID, log_unhandled_loudly);
 	if (pdu == NULL)
 		return FALSE;
 
@@ -1639,8 +1651,8 @@ bool_t nut_snmp_get_int(const char *OID, long *pval)
 	case ASN_OBJECT_ID:
 		snprint_objid (tmp_buf, sizeof(tmp_buf), pdu->variables->val.objid, pdu->variables->val_len / sizeof(oid));
 		upsdebugx(2, "Received an OID value: %s", tmp_buf);
-		/* Try to get the value of the pointed OID */
-		if (nut_snmp_get_int(tmp_buf, &value) == FALSE) {
+		/* Try to get the value of the pointed OID, quietly */
+		if (do_nut_snmp_get_int(tmp_buf, &value, 0) == FALSE) {
 			char	*oid_leaf;
 			upsdebugx(3, "Failed to retrieve OID value, using fallback");
 			/* Otherwise return the last part of the returned OID (ex: 1.2.3 => 3) */
@@ -1650,8 +1662,19 @@ bool_t nut_snmp_get_int(const char *OID, long *pval)
 		}
 		break;
 	default:
-		upslogx(LOG_ERR, "[%s] unhandled ASN 0x%x received from %s",
-			upsname?upsname:device_name, pdu->variables->type, OID);
+		/* This is often seen with "ASN 0x80" meaning "context-specific"
+		 * (ASN_CONTEXT) with no further bits. In practice in may mean
+		 * trying to read from an OID that is itself the value, which
+		 * the fallback above handles for us. For analysis, see:
+		 *   https://github.com/networkupstools/nut/issues/1358
+		 */
+		if (log_unhandled_loudly) {
+			upslogx(LOG_ERR, "[%s] unhandled ASN 0x%x received from %s",
+				upsname?upsname:device_name, pdu->variables->type, OID);
+		} else {
+			upsdebugx(3, "[%s] unhandled ASN 0x%x received from %s",
+				upsname?upsname:device_name, pdu->variables->type, OID);
+		}
 		return FALSE;
 	}
 
@@ -1663,6 +1686,11 @@ bool_t nut_snmp_get_int(const char *OID, long *pval)
 	return TRUE;
 }
 
+bool_t nut_snmp_get_int(const char *OID, long *pval)
+{
+	return do_nut_snmp_get_int(OID, pval, 1);
+}
+
 bool_t nut_snmp_set(const char *OID, char type, const char *value)
 {
 	int status;
@@ -3739,7 +3767,7 @@ bool_t su_ups_get(snmp_info_t *su_info_p)
 					upsdebugx(2, "=> truncating alarms present to INT_MAX");
 					value = INT_MAX;
 				}
-				pdu_array = nut_snmp_walk(su_info_p->OID, (int)value);
+				pdu_array = nut_snmp_walk(su_info_p->OID, (int)value, 1);
 				if(pdu_array == NULL) {
 					upsdebugx(2, "=> Walk failed");
 					return FALSE;

drivers/snmp-ups.h

@@ -344,7 +344,7 @@ typedef struct {
 #define SU_TYPE_DAISY_MASTER_ONLY	(1UL << 24)	/* Only valid for daisychain master (device.1) */
 
 /* "flags" bit 25 */
-#define SU_FLAG_MAPPING_HANDLED	(1UL << 25)	/* raised internally if any (sub)driver handling loop care about this report; if not, may be a point for improvement... */
+#define SU_FLAG_MAPPING_HANDLED	(1UL << 25)	/* raised internally if any (sub)driver handling loop cared about this report and retrieved something successfully; if not, may be a point for improvement... */
 
 #define SU_AMBIENT_TEMPLATE	(1UL << 26)	/* ambient template definition */