Simplify the log grouping logic

This commit is contained in:
Pierre committed 2026-10-04 14:29:14 +02:00
1 parent f57e23d76a
commit 3aa0120e3d
10 files changed
+82 -84

No files matched your search

+19 -17
View File
@@ -43,23 +43,25 @@ class ServiceCaller(ConditionalAction):
class EventsForwarder(hass.Hass, LoggerInterface): class EventsForwarder(hass.Hass, LoggerInterface):
def initialize(self): def initialize(self):
self.initialize_logger_interface(self.get_ad_api()) with self.log_group("App Initialization"):
self.mute_logger(self.args.get('mute', False)) self.initialize_logger_interface(self.get_ad_api())
self.forwarders = {} self.mute_logger(self.args.get('mute', False))
self.services_caller = {} self.forwarders = {}
self.event_handlers = [] self.services_caller = {}
for key, block in self.args.get('forwarders', {}).items(): self.event_handlers = []
try: for key, block in self.args.get('forwarders', {}).items():
senders = [EventSender(self, config) try:
for config in block.get('events_to_send', {}).values()] senders = [EventSender(self, config)
callers = [ServiceCaller(self, config) for config in block.get('events_to_send', {}).values()]
for config in block.get('services_to_call', {}).values()] callers = [ServiceCaller(self, config)
self.forwarders[key] = senders for config in block.get('services_to_call', {}).values()]
self.services_caller[key] = callers self.forwarders[key] = senders
self.event_handlers.append(EventHandler( self.services_caller[key] = callers
self, block['events_to_listen'], self.on_event, key)) self.event_handlers.append(EventHandler(
except ParsingException as error: self, block['events_to_listen'], self.on_event, key))
self.log_error(f"Invalid forwarder {key}: {error}") except ParsingException as error:
self.log_error(f"Invalid forwarder {key}: {error}")
self.log_info("Initialisation completed")
def on_event(self, event_name, event_data, forwarder_key): def on_event(self, event_name, event_data, forwarder_key):
for sender in self.forwarders.get(forwarder_key, []): for sender in self.forwarders.get(forwarder_key, []):
+11 -5
View File
@@ -57,7 +57,13 @@ class Evaluator():
self.__no_log_prefix = parser.parse_args('no_log_prefix',False) #as no_log_prefix is used to feedback parser error, it need to be defined first self.__no_log_prefix = parser.parse_args('no_log_prefix',False) #as no_log_prefix is used to feedback parser error, it need to be defined first
condition_name = parser.parse_args('condition_name',None,['log_prefix']) condition_name = parser.parse_args('condition_name',None,['log_prefix'])
self.__trace_name = ', '.join(map(str, condition_name)) if isinstance(condition_name, list) else str(condition_name or 'condition') log_group = parser.parse_args('log_group',None)
if log_group is not None:
self.__log_group = str(log_group)
elif isinstance(condition_name, list):
self.__log_group = ', '.join(map(str, condition_name))
else:
self.__log_group = str(condition_name or 'condition')
if condition_name: if condition_name:
if isinstance(condition_name,list): if isinstance(condition_name,list):
for name in condition_name: for name in condition_name:
@@ -163,17 +169,17 @@ class Evaluator():
raise e raise e
def __log_group(self): def __log_group_scope(self):
# SmartObject itself implements LoggerInterface, but many evaluators are # SmartObject itself implements LoggerInterface, but many evaluators are
# constructed with only the app as their API and no logger_interface kwarg. # constructed with only the app as their API and no logger_interface kwarg.
logger = self.__logger_interface or self.__appdaemon_api logger = self.__logger_interface or self.__appdaemon_api
group_scope = getattr(logger, 'log_group', None) group_scope = getattr(logger, 'log_group', None)
if callable(group_scope): if callable(group_scope):
return group_scope('smartcondition', self.__trace_name) return group_scope(self.__log_group)
return nullcontext() return nullcontext()
def evaluate(self,log = True): def evaluate(self,log = True):
with self.__log_group(): with self.__log_group_scope():
try: result = self.__evaluate() try: result = self.__evaluate()
except EvaluationException as e: except EvaluationException as e:
self.__log(f"{e}",level = "ERROR") self.__log(f"{e}",level = "ERROR")
@@ -503,7 +509,7 @@ class Evaluator():
self.__last_evaluation_result = new_result self.__last_evaluation_result = new_result
def __trigger_callbacks(self,trigger_reason,triggered_from_activation = False): def __trigger_callbacks(self,trigger_reason,triggered_from_activation = False):
with self.__log_group(): with self.__log_group_scope():
return self.__trigger_callbacks_in_group(trigger_reason, triggered_from_activation) return self.__trigger_callbacks_in_group(trigger_reason, triggered_from_activation)
def __trigger_callbacks_in_group(self,trigger_reason,triggered_from_activation = False): def __trigger_callbacks_in_group(self,trigger_reason,triggered_from_activation = False):
+4 -4
View File
@@ -184,16 +184,16 @@ class SmartObject(hass.Hass,LoggerInterface):
# → attributes_override → dataset restore → on_initialize_smart_object() # → attributes_override → dataset restore → on_initialize_smart_object()
def initialize(self): def initialize(self):
self.initialize_logger_interface(self.get_ad_api()) self.initialize_logger_interface(self.get_ad_api())
with self.log_group('initialization', self.name) as group: with self.log_group('App Initialization') as group:
self.log(f"Initialization started [group=initialization:{group['id']}]") self.log(f"Initialization started [group={group['kind']}:{group['id']}]")
try: try:
succeeded = self._initialize_smart_object() succeeded = self._initialize_smart_object()
except BaseException: except BaseException:
self.log(f"Initialization failed [group=initialization:{group['id']}]", level='ERROR') self.log(f"Initialization failed [group={group['kind']}:{group['id']}]", level='ERROR')
raise raise
status = 'completed' if succeeded else 'failed' status = 'completed' if succeeded else 'failed'
level = 'INFO' if succeeded else 'ERROR' level = 'INFO' if succeeded else 'ERROR'
self.log(f"Initialization {status} [group=initialization:{group['id']}]", level=level) self.log(f"Initialization {status} [group={group['kind']}:{group['id']}]", level=level)
def _initialize_smart_object(self): def _initialize_smart_object(self):
try: try:
+15 -2
View File
@@ -78,8 +78,8 @@ class LoggerGroupingTests(unittest.TestCase):
evaluator = smartcondition.Evaluator.__new__(smartcondition.Evaluator) evaluator = smartcondition.Evaluator.__new__(smartcondition.Evaluator)
evaluator._Evaluator__logger_interface = None evaluator._Evaluator__logger_interface = None
evaluator._Evaluator__appdaemon_api = app evaluator._Evaluator__appdaemon_api = app
evaluator._Evaluator__trace_name = 'smart_conditions' evaluator._Evaluator__log_group = 'smart_conditions'
with evaluator._Evaluator__log_group(): with evaluator._Evaluator__log_group_scope():
app.log_info('Callback trigger by sensor.example(0 => 1)') app.log_info('Callback trigger by sensor.example(0 => 1)')
app.log_info('[smart_conditions][Evaluating] Triggered by condition') app.log_info('[smart_conditions][Evaluating] Triggered by condition')
marker_a = app.rows[0][1].split('[group=')[1].rstrip(']') marker_a = app.rows[0][1].split('[group=')[1].rstrip(']')
@@ -87,6 +87,19 @@ class LoggerGroupingTests(unittest.TestCase):
self.assertEqual(marker_a, marker_b) self.assertEqual(marker_a, marker_b)
self.assertTrue(marker_a.startswith('smartcondition:')) self.assertTrue(marker_a.startswith('smartcondition:'))
def test_log_group_takes_priority_over_condition_name(self):
app = FakeApp()
evaluator = smartcondition.Evaluator(app, {}, activated=False,
condition_name='condition-a', log_group='group-a')
self.assertEqual(evaluator._Evaluator__log_group, 'group-a')
self.assertEqual(evaluator._Evaluator__log_to_string('message'), '[condition-a] message')
with evaluator._Evaluator__log_group_scope() as group:
self.assertEqual(group['label'], 'group-a')
fallback = smartcondition.Evaluator(app, {}, activated=False,
condition_name=['condition-a', 'condition-b'])
self.assertEqual(fallback._Evaluator__log_group, 'condition-a, condition-b')
def test_nested_scopes_inherit_outer_group_and_reset_after_exception(self): def test_nested_scopes_inherit_outer_group_and_reset_after_exception(self):
app = FakeApp() app = FakeApp()
with app.log_group('value_selector', 'sensor.a') as outer: with app.log_group('value_selector', 'sensor.a') as outer:
+12 -4
View File
@@ -542,10 +542,18 @@ class BinarySensor(VirtualSensorBase):
self.output_sensor.set_state(state = new_value) self.output_sensor.set_state(state = new_value)
def on_sensor_change(self,prev_result,result): def on_sensor_change(self,prev_result,result):
if result == SmartCondition.Result.Unavailable: self.output_sensor.set_state(state = 'unavailable') target_state = None
elif result == SmartCondition.Result.Succeeded: self.output_sensor.set_state(state = 'on') if result == SmartCondition.Result.Unavailable: target_state = 'unavailable'
elif result == SmartCondition.Result.Failed: self.output_sensor.set_state(state = 'off') elif result == SmartCondition.Result.Succeeded: target_state = 'on'
# else: Disabled means we keep the previous value elif result == SmartCondition.Result.Failed: target_state = 'off'
else: target_state = None #Disabled means we keep the previous value
if target_state != None:
self.output_sensor.set_state(state = target_state)
self.log_info(f"{self.sensor_name} = {target_state}")
else:
self.log_info(f"SmartCondition of {self.sensor_name} is disabled")
def generate_dependencies_list(self): def generate_dependencies_list(self):
dependencies = list() dependencies = list()
+1 -1
View File
@@ -21,7 +21,7 @@ The explorer groups lines by the app name in the standard AppDaemon log format.
**AD Logs** turns red when the loaded logs contain an ERROR or CRITICAL entry. **Clear logs** empties the configured log files and clears the current explorer history. **AD Logs** turns red when the loaded logs contain an ERROR or CRITICAL entry. **Clear logs** empties the configured log files and clears the current explorer history.
The standard AppDaemon text logs do not contain causal links or reliable initialization boundaries. The details panel will say so for ordinary entries. Existing messages that already contain trace or initialization metadata can still be grouped or linked; the explorer does not create that metadata. No AppDaemon Python changes are needed for this raw-log view. Lines carrying the same `[group=<name>:<id>]` marker are grouped together, and the supplied name is shown in the explorer. Ordinary AppDaemon lines without a group marker remain individual log entries. Trace metadata can still be used for causal links where present.
## Settings ## Settings
+14 -16
View File
@@ -26,7 +26,7 @@
&& (level === 'all' || normalLevel(e) === level) && (level === 'all' || normalLevel(e) === level)
&& `${e.app} ${e.entity || ''} ${e.message}`.toLowerCase().includes(q)); && `${e.app} ${e.entity || ''} ${e.message}`.toLowerCase().includes(q));
} }
const cleanMessage = e => e.message.replace(/ \[event=[\w-]+ trace=[\w-]+\]/g, '').replace(/ \[init=[\w-]+\]/g, '').replace(/ \[group=(?:initialization|smartcondition|value_selector):[a-f0-9]{12}\]/gi, ''); const cleanMessage = e => e.message.replace(/ \[event=[\w-]+ trace=[\w-]+\]/g, '').replace(/ \[init=[^\]]+\]/g, '').replace(/ \[group=[^\]]+:[a-f0-9]{12}\]/gi, '');
const formatTime = (entry, includeYear = false) => { const formatTime = (entry, includeYear = false) => {
if (!Number.isFinite(entry.time)) return entry.timestamp; if (!Number.isFinite(entry.time)) return entry.timestamp;
try { try {
@@ -68,13 +68,12 @@
}); });
return container; return container;
} }
function blockTitle(items, groupKey) { function blockTitle(items) {
const first = items[0]; const first = items[0];
const kind = groupKey?.startsWith('initialization:') || first.initialization_id ? 'initialization' : items.find(entry => entry.group_kind)?.group_kind; const kind = items.find(entry => entry.group_kind)?.group_kind;
const names = { initialization: 'Initialization', smartcondition: 'Smart condition', value_selector: 'Value selector' }; const name = kind || (items.length > 1 || first.trace_id ? 'Event' : 'Log');
const name = names[kind] || (items.length > 1 || first.trace_id ? 'Event' : 'Log'); const label = items.map(entry => entry.group_label).find(Boolean) || first.entity || first.app;
const label = kind === 'initialization' ? first.app : items.map(entry => entry.group_label || cleanMessage(entry).match(/^\[([^\]]+)\]/)?.[1]).find(Boolean) || first.entity || first.app; return node('div', kind ? name : `${name} · ${label}`, 'block-title');
return node('div', `${name} · ${label}`, 'block-title');
} }
function row(e) { function row(e) {
const item = node('div', undefined, `row${selected === e.event_id ? ' selected' : ''}${recentEvents.has(e.event_id) ? ' recent-log' : ''}`); const item = node('div', undefined, `row${selected === e.event_id ? ' selected' : ''}${recentEvents.has(e.event_id) ? ' recent-log' : ''}`);
@@ -188,25 +187,24 @@
detail.querySelector('.rows')?.remove(); detail.querySelector('.rows')?.remove();
if (!detail.open) return; if (!detail.open) return;
const rows = node('div', undefined, 'rows'); const rows = node('div', undefined, 'rows');
const units = [], initGroups = new Map(); const units = [], groupUnits = new Map();
logs.forEach(e => { logs.forEach(e => {
if (e.initialization_id) { if (e.group_id) {
if (!initGroups.has(e.initialization_id)) { const unit = { id: e.initialization_id, entries: [] }; initGroups.set(e.initialization_id, unit); units.push(unit); } const key = `group:${e.group_id}`;
initGroups.get(e.initialization_id).entries.push(e); if (!groupUnits.has(key)) { const unit = { key, entries: [] }; groupUnits.set(key, unit); units.push(unit); }
groupUnits.get(key).entries.push(e);
} else { } else {
const key = e.group_id ? `group:${e.group_id}` : e.kind === 'log' && e.trace_id ? `trace:${e.trace_id}` : undefined; const key = e.kind === 'log' && e.trace_id ? `trace:${e.trace_id}` : undefined;
const previous = units[units.length - 1]; const previous = units[units.length - 1];
if (key && previous && !previous.id && previous.key === key) previous.entries.push(e); if (key && previous && !previous.id && previous.key === key) previous.entries.push(e);
else units.push({ key, entries: [e] }); else units.push({ key, entries: [e] });
} }
}); });
const startTime = unit => unit.id const startTime = unit => unit.entries[0].time;
? (entries.find(e => e.app === app && e.initialization_id === unit.id && e.kind === 'initialization_started') || unit.entries[0]).time
: unit.entries[0].time;
units.sort((a, b) => startTime(a) - startTime(b)); units.sort((a, b) => startTime(a) - startTime(b));
if (units.length > 150) rows.append(node('div', `${units.length - 150} older rows/groups: narrow the time range or search.`, 'more')); if (units.length > 150) rows.append(node('div', `${units.length - 150} older rows/groups: narrow the time range or search.`, 'more'));
units.slice(-150).forEach(unit => { units.slice(-150).forEach(unit => {
appendEventRows(rows, unit.entries, unit.id ? `initialization:${unit.id}` : undefined); appendEventRows(rows, unit.entries, unit.key);
}); });
detail.append(rows); detail.append(rows);
const position = logScrollPositions.get(app); const position = logScrollPositions.get(app);
+1 -28
View File
@@ -223,14 +223,7 @@ export class LogExplorer implements vscode.Disposable {
} }
private publish() { private publish() {
const publication = ++this.publication; const publication = ++this.publication;
const entries = [...this.entries.values()].sort((a, b) => { const entries = [...this.entries.values()].sort((a, b) => a.time - b.time);
const time = a.time - b.time;
if (time) { return time; }
// Include raw app.log() lines written in the same second as initialization markers.
const priority = (entry: LogEntry) => /Initialization (?:started|completed|failed)/.test(entry.message)
? (entry.message.includes('started') ? -1 : 1) : 0;
return priority(a) - priority(b);
});
// Legacy errors duplicated across main/error logs are merged only on exact match. // Legacy errors duplicated across main/error logs are merged only on exact match.
const seen = new Set<string>(); const seen = new Set<string>();
const unique = entries.filter(e => { const unique = entries.filter(e => {
@@ -238,26 +231,6 @@ export class LogExplorer implements vscode.Disposable {
if (seen.has(key)) { return false; } seen.add(key); return true; if (seen.has(key)) { return false; } seen.add(key); return true;
}); });
this.onErrorCountChanged?.(unique.filter(e => (e.kind === 'log' || e.kind.startsWith('initialization_')) && (e.level === 'ERROR' || e.level === 'CRITICAL')).length); this.onErrorCountChanged?.(unique.filter(e => (e.kind === 'log' || e.kind.startsWith('initialization_')) && (e.level === 'ERROR' || e.level === 'CRITICAL')).length);
// Direct app.log() calls have no LoggerInterface tag. Infer their initialization
// group while an explicit per-app initialize() scope is open.
const activeInitialization = new Map<string, string>();
for (const entry of unique) {
const marker = entry.message.match(/Initialization (started|completed|failed) \[group=initialization:([a-f0-9]{12})\]/i);
if (marker?.[1] === 'started') { activeInitialization.set(entry.app, marker[2]); }
const activeId = activeInitialization.get(entry.app);
if (activeId && !entry.group_id) {
entry.group_id = activeId;
entry.group_kind = 'initialization';
entry.initialization_id = activeId;
entry.phase = 'initialization';
entry.group_inferred = true;
}
if (entry.group_kind === 'initialization') {
entry.initialization_id = entry.initialization_id || entry.group_id;
entry.phase = 'initialization';
}
if (marker && (marker[1] === 'completed' || marker[1] === 'failed')) { activeInitialization.delete(entry.app); }
}
const zone = vscode.workspace.getConfiguration('appdaemon').get<string>('logTimezone', 'Europe/Berlin'); const zone = vscode.workspace.getConfiguration('appdaemon').get<string>('logTimezone', 'Europe/Berlin');
this.activeWebview?.postMessage({ type: 'entries', entries: unique, warnings: [...this.warnings], limit: 10000, timezone: zone }); this.activeWebview?.postMessage({ type: 'entries', entries: unique, warnings: [...this.warnings], limit: 10000, timezone: zone });
void this.resolveSources(unique, publication); void this.resolveSources(unique, publication);
+5 -7
View File
@@ -3,8 +3,8 @@ export interface LogEntry {
kind: string; cause_ids: string[]; probable_cause_ids?: string[]; kind: string; cause_ids: string[]; probable_cause_ids?: string[];
entity?: string; values?: Record<string, unknown>; entity?: string; values?: Record<string, unknown>;
source?: { path: string; line: number }; source?: { path: string; line: number };
initialization_id?: string; phase?: string; status?: string; status?: string;
group_id?: string; group_kind?: string; group_inferred?: boolean; group_id?: string; group_kind?: string;
file?: string; raw?: string; time: number; trace_id?: string; file?: string; raw?: string; time: number; trace_id?: string;
[key: string]: unknown; [key: string]: unknown;
} }
@@ -38,12 +38,10 @@ export function parseLine(line: string, file: string, offset: number, zone = 'Eu
} }
const m = line.match(/^(\d{2}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}(?:\.\d+)?)\s+(DEBUG|INFO|WARNING|ERROR|CRITICAL)\s+([^:]+):\s?(.*)$/); const m = line.match(/^(\d{2}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}(?:\.\d+)?)\s+(DEBUG|INFO|WARNING|ERROR|CRITICAL)\s+([^:]+):\s?(.*)$/);
if (!m) { return undefined; } if (!m) { return undefined; }
const init = m[4].match(/\[init=([\w-]+)\]/); const group = m[4].match(/\[group=([^\]\r\n]+):([a-f0-9]{12})\]/i);
const group = m[4].match(/\[group=(initialization|smartcondition|value_selector):([a-f0-9]{12})\]/i);
const id = m[4].match(/\[event=([\w-]+) trace=([\w-]+)\]/); const id = m[4].match(/\[event=([\w-]+) trace=([\w-]+)\]/);
const groupKind = group?.[1]?.toLowerCase(); const groupKind = group?.[1]?.trim();
const initializationId = groupKind === 'initialization' ? group?.[2] : init?.[1]; return { event_id: id?.[1] || `${file}:${offset}`, trace_id: id?.[2], group_id: group?.[2], group_kind: groupKind, timestamp: m[1], time: rawTime(m[1], zone), app: m[3].trim(), level: m[2], message: m[4], kind: 'log', cause_ids: [], file, raw: line };
return { event_id: id?.[1] || `${file}:${offset}`, trace_id: id?.[2], initialization_id: initializationId, phase: initializationId ? 'initialization' : undefined, group_id: group?.[2], group_kind: groupKind, timestamp: m[1], time: rawTime(m[1], zone), app: m[3].trim(), level: m[2], message: m[4], kind: 'log', cause_ids: [], file, raw: line };
} }
/** Preserve valid UTF-8 spans, including files containing mixed legacy bytes. */ /** Preserve valid UTF-8 spans, including files containing mixed legacy bytes. */
Binary file not shown.