Improve frontend error messages written to system log #17616

steverep · 2023-08-18T05:30:13Z

Proposed change

This overhauls messages sent to the system log for frontend errors, hopefully making them much more useful, complete, and less confusing to users.

Adds a listener for unhandled promise rejections (error events are not fired in async code, so we're currently not covering all bases)
Logs the stack trace mapped to original source, which all the major engines store in a non-standard property (instead of to the minified and mangled bundle)
Logs the originating browser and OS with versions at the start of each message (helps developers debug, and users to understand and identify the originating device)
Handles cause properties, aggregate errors, and non-Error instances
Moves the listener setup to the logging mixin instead of core script
Bulk of code is loaded dynamically only if an event handler runs

Sample Output from Multiple Browsers

2023-08-17 22:38:55.321 ERROR (MainThread) [frontend.js.latest.202308020] Unhandled promise rejection from Mobile Safari 16.6 on iOS 16.6
TypeError: undefined is not an object (evaluating 'e.fakeProp.name')
name (src/components/ha-icon-picker.ts:34:31)
map ([native code]::)
map (src/components/ha-icon-picker.ts:33:27)
2023-08-17 22:38:55.924 ERROR (MainThread) [frontend.js.latest.202308020] Uncaught error from Mobile Safari 16.6 on iOS 16.6
Error: This is my fake error
_setValue (src/components/ha-icon-picker.ts:188:18)
handleEvent (src/lit-html.ts:2018:28)
dispatchEvent ([native code]::)
event (src/common/dom/fire_event.ts:76:21)
ev.stopPropagation (src/components/ha-combo-box.ts:318:16)
handleEvent (src/lit-html.ts:2018:28)
dispatchEvent ([native code]::)
x (node_modules/@polymer/polymer/lib/mixins/property-effects.js:328:56)
inst (node_modules/@polymer/polymer/lib/mixins/property-effects.js:353:22)
Caused by: TypeError: undefined is not an object (evaluating 'e.detail.fakeProp.value')
_valueChanged (src/components/ha-icon-picker.ts:186:40)
handleEvent (src/lit-html.ts:2018:28)
dispatchEvent ([native code]::)
event (src/common/dom/fire_event.ts:76:21)
ev.stopPropagation (src/components/ha-combo-box.ts:318:16)
handleEvent (src/lit-html.ts:2018:28)
dispatchEvent ([native code]::)
x (node_modules/@polymer/polymer/lib/mixins/property-effects.js:328:56)
inst (node_modules/@polymer/polymer/lib/mixins/property-effects.js:353:22)
2023-08-18 01:43:53.521 ERROR (MainThread) [frontend.js.latest.202308020] Unhandled promise rejection from Firefox 116.0 on Windows 10
{
  "code": "not_found",
  "message": "No prefs"
}
2023-08-18 01:44:30.296 ERROR (MainThread) [frontend.js.latest.202308020] Unhandled promise rejection from Firefox 116.0 on Windows 10
TypeError: e.fakeProp is undefined
icon (src/components/ha-icon-picker.ts:34:17)
map (src/components/ha-icon-picker.ts:33:27)
2023-08-18 01:44:34.992 ERROR (MainThread) [frontend.js.latest.202308020] Uncaught error from Firefox 116.0 on Windows 10
Error: This is my fake error
_setValue (src/components/ha-icon-picker.ts:188:12)
call (src/lit-html.ts:2018:28)
dispatchEvent (src/common/dom/fire_event.ts:76:7)
ev.stopPropagation (src/components/ha-combo-box.ts:318:16)
call (src/lit-html.ts:2018:28)
dispatchEvent (node_modules/@polymer/polymer/lib/mixins/property-effects.js:328:42)
dispatchNotifyEvent (node_modules/@polymer/polymer/lib/mixins/property-effects.js:353:2)
fn (node_modules/@polymer/polymer/lib/mixins/property-effects.js:176:11)
runEffectsForProperty (node_modules/@polymer/polymer/lib/mixins/property-effects.js:263:17)
Caused by: TypeError: e.detail.fakeProp is undefined
_valueChanged (src/components/ha-icon-picker.ts:186:6)
call (src/lit-html.ts:2018:28)
dispatchEvent (src/common/dom/fire_event.ts:76:7)
ev.stopPropagation (src/components/ha-combo-box.ts:318:16)
call (src/lit-html.ts:2018:28)
dispatchEvent (node_modules/@polymer/polymer/lib/mixins/property-effects.js:328:42)
dispatchNotifyEvent (node_modules/@polymer/polymer/lib/mixins/property-effects.js:353:2)
fn (node_modules/@polymer/polymer/lib/mixins/property-effects.js:176:11)
runEffectsForProperty (node_modules/@polymer/polymer/lib/mixins/property-effects.js:263:17)
2023-08-18 01:44:34.994 ERROR (MainThread) [frontend.js.latest.202308020] Uncaught error from Firefox 116.0 on Windows 10
Error: This is my fake error
_setValue (src/components/ha-icon-picker.ts:188:12)
call (src/lit-html.ts:2018:28)
dispatchEvent (src/common/dom/fire_event.ts:76:7)
_clearValue (src/components/ha-combo-box.ts:220:14)
call (src/lit-html.ts:2018:28)
Caused by: TypeError: e.detail.fakeProp is undefined
_valueChanged (src/components/ha-icon-picker.ts:186:6)
call (src/lit-html.ts:2018:28)
dispatchEvent (src/common/dom/fire_event.ts:76:7)
_clearValue (src/components/ha-combo-box.ts:220:14)
call (src/lit-html.ts:2018:28)
2023-08-18 01:47:43.179 ERROR (MainThread) [frontend.js.latest.202308020] Unhandled promise rejection from Chrome 116.0.0.0 on Windows 10
TypeError: Cannot read properties of undefined (reading 'name')
name (src/components/ha-icon-picker.ts:34:31)
map (src/components/ha-icon-picker.ts:33:27)
_openedChanged (src/components/ha-icon-picker.ts:177:19)
2023-08-18 01:47:46.699 ERROR (MainThread) [frontend.js.latest.202308020] Uncaught error from Chrome 116.0.0.0 on Windows 10
Error: This is my fake error
_setValue (src/components/ha-icon-picker.ts:188:12)
call (src/lit-html.ts:2018:28)
dispatchEvent (src/common/dom/fire_event.ts:76:7)
ev.stopPropagation (src/components/ha-combo-box.ts:318:16)
call (src/lit-html.ts:2018:28)
dispatchEvent (node_modules/@polymer/polymer/lib/mixins/property-effects.js:328:42)
dispatchNotifyEvent (node_modules/@polymer/polymer/lib/mixins/property-effects.js:353:2)
fn (node_modules/@polymer/polymer/lib/mixins/property-effects.js:176:11)
runEffectsForProperty (node_modules/@polymer/polymer/lib/mixins/property-effects.js:263:17)
Caused by: TypeError: Cannot read properties of undefined (reading 'value')
_valueChanged (src/components/ha-icon-picker.ts:186:40)
call (src/lit-html.ts:2018:28)
dispatchEvent (src/common/dom/fire_event.ts:76:7)
ev.stopPropagation (src/components/ha-combo-box.ts:318:16)
call (src/lit-html.ts:2018:28)
dispatchEvent (node_modules/@polymer/polymer/lib/mixins/property-effects.js:328:42)
dispatchNotifyEvent (node_modules/@polymer/polymer/lib/mixins/property-effects.js:353:2)
fn (node_modules/@polymer/polymer/lib/mixins/property-effects.js:176:11)
runEffectsForProperty (node_modules/@polymer/polymer/lib/mixins/property-effects.js:263:17)
2023-08-18 01:47:46.702 ERROR (MainThread) [frontend.js.latest.202308020] Uncaught error from Chrome 116.0.0.0 on Windows 10
Error: This is my fake error
_setValue (src/components/ha-icon-picker.ts:188:12)
call (src/lit-html.ts:2018:28)
dispatchEvent (src/common/dom/fire_event.ts:76:7)
_clearValue (src/components/ha-combo-box.ts:220:14)
call (src/lit-html.ts:2018:28)
Caused by: TypeError: Cannot read properties of undefined (reading 'value')
_valueChanged (src/components/ha-icon-picker.ts:186:40)
call (src/lit-html.ts:2018:28)
dispatchEvent (src/common/dom/fire_event.ts:76:7)
_clearValue (src/components/ha-combo-box.ts:220:14)
call (src/lit-html.ts:2018:28)
2023-08-18 01:47:59.583 ERROR (MainThread) [frontend.js.latest.202308020] Unhandled promise rejection from Chrome 116.0.0.0 on Windows 10
{
  "code": "not_found",
  "message": "No prefs"
}

Type of change

Dependency upgrade
Bugfix (non-breaking change which fixes an issue)
New feature (thank you!)
Breaking change (fix/feature causing existing functionality to break)
Code quality improvements to existing code or addition of tests

Example configuration

Additional information

This PR fixes or closes issue: fixes #
This PR is related to issue or discussion:
Link to documentation pull request:

Checklist

The code change is tested and works locally.
There is no commented out code in this PR.
Tests have been added to verify that the new code works.

If user exposed functionality or configuration variables are added/changed:

Documentation added/updated for www.home-assistant.io

src/data/system_log.ts

bramkragten · 2023-08-18T08:43:41Z

src/state/logging-mixin.ts

+    protected hassConnected() {
+      super.hassConnected();


I think the reason we did this in core, was that we would catch error as soon and as low as possible, I see that that makes no sense because there is no connection yet, so they can not be send to core anyway, but I think the idea was that we would store those errors and send them as soon as there would be a connection, or if the error would be in the connection itself show it on screen.

Yeah I thought about that as well, but I think the logging listeners should stay separate rather than complicating them with startup logic. I think a follow up enhancement would be to add startup listeners early on, and then remove them here after the connection is complete.

Just storing them and expecting to log later is flawed since many such errors would likely prevent the connection from completing or even defining the custom element. It's also not necessarily straightforward to handle. For example, I tried to also test errors inside other mixins, but those didn't even get logged to the console let alone handled by the listeners.

src/resources/log-message.ts

bramkragten · 2023-08-18T09:00:18Z

Nice!

steverep · 2023-09-01T00:00:59Z

@frenck consider adding this to release notes for 2023.9. Because of the additional logging of promise rejections, users might see new errors in the log that aren't actually new, but should still be reported.

Improve frontend error messages written to system log

bca4c47

home-assistant bot added the cla-signed label Aug 18, 2023

github-actions bot added Dependencies Pull requests that update a dependency file Build Related to building the code labels Aug 18, 2023

bramkragten reviewed Aug 18, 2023

View reviewed changes

src/data/system_log.ts Outdated Show resolved Hide resolved

bramkragten reviewed Aug 18, 2023

View reviewed changes

src/resources/log-message.ts Show resolved Hide resolved

bramkragten reviewed Aug 18, 2023

View reviewed changes

src/resources/log-message.ts Outdated Show resolved Hide resolved

steverep added 3 commits August 18, 2023 15:59

Use trim instead of trimEnd

124de2e

Explicitly set log level type

94b4a05

Generate aggregate error messages async

67e5572

bramkragten approved these changes Aug 21, 2023

View reviewed changes

bramkragten merged commit 46a036d into dev Aug 21, 2023
9 checks passed

bramkragten deleted the logger-stack-trace branch August 21, 2023 11:01

steverep mentioned this pull request Sep 1, 2023

scrollTop Virtualizer error in HA core logs #17745

Closed

3 tasks

dshokouhi mentioned this pull request Sep 17, 2023

Error message: "Failed to call service system_log/write. unknown error" after update 2023.9.2 #17954

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Improve frontend error messages written to system log #17616

Improve frontend error messages written to system log #17616

steverep commented Aug 18, 2023

bramkragten Aug 18, 2023

steverep Aug 18, 2023

bramkragten commented Aug 18, 2023

steverep commented Sep 1, 2023

Improve frontend error messages written to system log #17616

Improve frontend error messages written to system log #17616

Conversation

steverep commented Aug 18, 2023

Proposed change

Sample Output from Multiple Browsers

Type of change

Example configuration

Additional information

Checklist

bramkragten Aug 18, 2023

Choose a reason for hiding this comment

steverep Aug 18, 2023

Choose a reason for hiding this comment

bramkragten commented Aug 18, 2023

steverep commented Sep 1, 2023