Audit diagnostic logging added during G522 bring-up

Downgrade INFO logs that served their purpose during format/bug
discovery to DEBUG (bridge TX per-call, Centurion feature enumeration
per-feature, RGB zone discovery) and drop the HeadsetRGBHostMode
diagnostic write wrapper entirely.

Keep all EQ read paths at INFO — AdvancedParaEQ work is still in the
data-collection phase, writes are gated, and at least one tester
can't surface DEBUG logs. Keep all failure paths (build failures,
_absent cache hits, bridge sub-device errors) and one-shot signals
(device_addr probe result, deferred-init completion) at INFO.

Routine -dd output shrinks notably; INFO becomes mostly actionable
events. Nothing is lost — everything is recoverable at DEBUG.
This commit is contained in:
Ken Sanislo 2026-04-19 13:13:44 -07:00
parent ddf8ca7aaa
commit 9bac78c7a8
4 changed files with 43 additions and 70 deletions

View File

@ -108,7 +108,7 @@ def get_advanced_eq_info(device):
}
logger.info(
"AdvancedParaEQ getEQInfos V2: gain=[%d,%d] steps=%d step_db=%.4f format=%d xy=%s "
"presets_ro=%d presets_custom=%d raw=%s",
"presets_ro=%d presets_custom=%d",
gain_min,
gain_max,
gain_steps,
@ -117,7 +117,6 @@ def get_advanced_eq_info(device):
supports_xy,
ro_presets,
custom_presets,
result.hex(),
)
return info
@ -140,14 +139,13 @@ def get_advanced_eq_info(device):
"step_db": 1.0,
}
logger.info(
"AdvancedParaEQ getEQInfos V%d: bands=%d dbRange=%d caps=0x%02X gain=[%d,%d] raw=%s",
"AdvancedParaEQ getEQInfos V%d: bands=%d dbRange=%d caps=0x%02X gain=[%d,%d]",
version,
band_count,
db_range,
caps,
gain_min,
gain_max,
result.hex(),
)
return info
@ -161,7 +159,7 @@ def get_advanced_eq_active_slot(device, direction=DIRECTION_PLAYBACK):
if len(result) < 1:
logger.info("AdvancedParaEQ getActiveEQ(dir=%d): empty response", direction)
return None
logger.info("AdvancedParaEQ getActiveEQ(dir=%d): slot=%d raw=%s", direction, result[0], result.hex())
logger.info("AdvancedParaEQ getActiveEQ(dir=%d): slot=%d", direction, result[0])
return result[0]
@ -224,12 +222,11 @@ def get_advanced_eq_defaults(device, direction=DIRECTION_PLAYBACK, slot=0):
)
return None
logger.info(
"AdvancedParaEQ getEQDefaults V2 (dir=%d slot=%d): %d band(s) %s raw=%s",
"AdvancedParaEQ getEQDefaults V2 (dir=%d slot=%d): %d band(s) %s",
direction,
slot,
len(bands),
[_band_label(t, f) + f" {round(g, 2)}dB" for t, f, g in bands],
result.hex(),
)
return bands
# V0/V1 legacy 3-byte stride.
@ -243,12 +240,11 @@ def get_advanced_eq_defaults(device, direction=DIRECTION_PLAYBACK, slot=0):
bands.append((FILTER_TYPE_PEAKING, freq, float(gain_db)))
offset += 3
logger.info(
"AdvancedParaEQ getEQDefaults V%d (dir=%d slot=%d): %d band(s) raw=%s",
"AdvancedParaEQ getEQDefaults V%d (dir=%d slot=%d): %d band(s)",
version,
direction,
slot,
len(bands),
result.hex(),
)
return bands
@ -346,13 +342,12 @@ def get_advanced_eq_params(device, direction=DIRECTION_PLAYBACK, slot=0):
)
return None
logger.info(
"AdvancedParaEQ getCustomEQ V2 (dir=%d slot=%d): %d band(s) step_db=%.4f %s raw=%s",
"AdvancedParaEQ getCustomEQ V2 (dir=%d slot=%d): %d band(s) step_db=%.4f %s",
direction,
slot,
len(bands),
step_db,
[f"{_band_label(t, f)} {round(g, 2)}dB" for t, f, g in bands],
result.hex(),
)
return bands
@ -367,12 +362,11 @@ def get_advanced_eq_params(device, direction=DIRECTION_PLAYBACK, slot=0):
bands.append((FILTER_TYPE_PEAKING, freq, float(gain_db)))
offset += 3
logger.info(
"AdvancedParaEQ getCustomEQ V%d (dir=%d slot=%d): parsed %d band(s) %s raw=%s",
"AdvancedParaEQ getCustomEQ V%d (dir=%d slot=%d): parsed %d band(s) %s",
version,
direction,
slot,
len(bands),
bands,
result.hex(),
)
return bands

View File

@ -714,11 +714,8 @@ class Device:
timeout = base.DEFAULT_TIMEOUT
with base.acquire_timeout(base.handle_lock(handle), handle, timeout):
# Log the outgoing sub-message at INFO so field diagnostics can
# correlate bridge NACKs with the exact payload we sent (e.g. to
# verify mic-gain byte landed in the device's accepted range).
if logger.isEnabledFor(logging.INFO):
logger.info(
if logger.isEnabledFor(logging.DEBUG):
logger.debug(
"bridge TX: sub_idx=%d func=0x%02X sw_id=%d payload=%s",
sub_feat_idx,
sub_function,

View File

@ -209,13 +209,14 @@ class FeaturesArray(dict):
# use the correct payload format on direct USB Centurion devices too.
self.version[feature] = feat_version
self.flags[feature] = feat_type
logger.info(
"Centurion parent feature: %s at index %d, version=%d, flags=0x%02X",
feature,
index,
feat_version,
feat_type,
)
if logger.isEnabledFor(logging.DEBUG):
logger.debug(
"Centurion parent feature: %s at index %d, version=%d, flags=0x%02X",
feature,
index,
feat_version,
feat_type,
)
if feature is CenturionCoreFeature.CENT_PP_BRIDGE:
bridge_index = index
@ -253,7 +254,8 @@ class FeaturesArray(dict):
logger.warning("Failed to read Centurion sub-device feature count")
return
total_count = count_resp[0]
logger.info("Centurion sub-device: FeatureSet reports %d features", total_count)
if logger.isEnabledFor(logging.DEBUG):
logger.debug("Centurion sub-device: FeatureSet reports %d features", total_count)
# Per-index query: GetFeatureId (function 1 = 0x10).
# Response: [remaining, feat_hi, feat_lo, type, version].
@ -282,19 +284,18 @@ class FeaturesArray(dict):
# payload format. get_feature_version(feature) reads self.version[feature].
self.version[feature] = feat_version
self.flags[feature] = feat_type
# Log every sub-device feature at INFO so field diagnostics can see
# both the version (V-gated payload formats) and flags (INTERNAL/HIDDEN
# bits silently suppress settings panels in check_feature).
logger.info(
"Centurion sub-device feature: %s at sub-index %d, version=%d, flags=0x%02X",
feature,
sub_feat_idx,
feat_version,
feat_type,
)
if logger.isEnabledFor(logging.DEBUG):
logger.debug(
"Centurion sub-device feature: %s at sub-index %d, version=%d, flags=0x%02X",
feature,
sub_feat_idx,
feat_version,
feat_type,
)
sub_feat_idx += 1
self._sub_feature_count = sub_feat_idx
logger.info("Centurion sub-device: discovered %d features total", sub_feat_idx)
if logger.isEnabledFor(logging.DEBUG):
logger.debug("Centurion sub-device: discovered %d features total", sub_feat_idx)
def get_feature(self, index: int) -> SupportedFeature | None:
feature = self.inverse.get(index)

View File

@ -1706,8 +1706,8 @@ class HeadsetMicGain(settings.Setting):
info.hex(),
)
min_gain, max_gain = cls.min_value, cls.max_value
else:
logger.info(
elif logger.isEnabledFor(logging.DEBUG):
logger.debug(
"HeadsetMicGain: device reports gain range [%d, %d]",
min_gain,
max_gain,
@ -1992,25 +1992,6 @@ class HeadsetRGBHostMode(settings.Setting):
rw_options = {"read_fnid": 0x70, "write_fnid": 0x80}
validator_class = settings_validator.BooleanValidator
def write(self, value, save=True):
# Diagnostic wrapper: log what GetHostModeState returns immediately
# before AND after the SetHostModeState write, so we can see whether
# (a) the write takes effect on the device or (b) our decoding of the
# response is wrong. solaar show has been reporting this value as
# False even after writes we believed succeeded.
try:
before = self._device.feature_request(self.feature, 0x70)
except Exception as e:
before = f"<err:{e}>"
logger.info("HeadsetRGBHostMode.write: before=%s requested=%s", before, value)
result = super().write(value, save=save)
try:
after = self._device.feature_request(self.feature, 0x70)
except Exception as e:
after = f"<err:{e}>"
logger.info("HeadsetRGBHostMode.write: after=%s write_returned=%s", after, result)
return result
class HeadsetRGBColor(settings.Setting):
"""Pick a color from the shared `special_keys.COLORS` palette and apply it
@ -2137,23 +2118,23 @@ class HeadsetRGBColor(settings.Setting):
# the device to report sane zone IDs and let the device reject nonsense.
tight = list(resp[1 : 1 + zone_count]) if 1 <= zone_count <= len(resp) - 1 else []
if tight and len(tight) == zone_count:
logger.info(
"HeadsetRGBColor: discovered %d zone(s) %s (tight format, raw resp=%s)",
len(tight),
[f"0x{z:02X}" for z in tight],
resp.hex(),
)
if logger.isEnabledFor(logging.DEBUG):
logger.debug(
"HeadsetRGBColor: discovered %d zone(s) %s (tight format)",
len(tight),
[f"0x{z:02X}" for z in tight],
)
device._headset_rgb_zone_ids = tight
return tight
# Try the doc's format (with reserved gap) as fallback
gap = list(resp[5 : 5 + zone_count]) if len(resp) >= 5 + zone_count else []
if gap and len(gap) == zone_count:
logger.info(
"HeadsetRGBColor: discovered %d zone(s) %s (doc format, raw resp=%s)",
len(gap),
[f"0x{z:02X}" for z in gap],
resp.hex(),
)
if logger.isEnabledFor(logging.DEBUG):
logger.debug(
"HeadsetRGBColor: discovered %d zone(s) %s (doc format)",
len(gap),
[f"0x{z:02X}" for z in gap],
)
device._headset_rgb_zone_ids = gap
return gap
# Neither format parsed cleanly; don't cache so next write retries.