Guidance on reading Logs ("Load full Logs" vs. what shows initially when going to Log Screen)

wtstreetglow · July 8, 2022, 11:04am

Hello everyone,

My home assistant setup seems to be working properly but my logs are an absolute disaster. Can anyone give me any guidance on either 1.) cutting down on the amount of information being logged to where they are more readible or 2.) possibly helping me review them to spot big issues that need to fixed within my setup.

I think they are so “chatty” that I am even having a difficult time knowing when a line items seems like a real problem and needs to be fixed vs just a logged line for the system historic documentation reason.

One additional thing to add is that there are only around 5 lines showing on the GUI portion of the log. (the lines showing before you click “load full logs”)

Also, can you all recommend a file viewer to view these? Notepad on windows makes this even more difficult I feel like.

Thank you all for anything you can do to help on this one!!

The logs are located here because they are so nasty to me:

pnbruckner · July 8, 2022, 4:07pm

Well, those are all warnings or errors, so you might want to at least try to do something about them, or at least some of them.

One category of error that is causing a lot of the lines in your log (especially the traceback lines) are templates in your scripts & automations. It seems many of them have a similar problem – i.e.:

Error rendering data template: UndefinedError: 'None' has no attribute 'state'

That’s probably because you’re doing something like this:

states.domain.object_id.state

instead of this:

states('domain.object_id')

The former will cause this error if the entity does not exist, whereas the latter will simply return unknown instead (without causing an error.)

The error messages say you have that problem in these scripts:

daily_briefing
morning_briefing
morning_wakeup_report

and these automations:

good_morning_report
master_bedroom_report

If you clean those up a lot of those errors should go away.

Your system also seems to have a lot of device communication issues. I’m not familiar with the associated integrations, so probably can’t provide much help there.

wtstreetglow · July 8, 2022, 5:12pm

@pnbruckner Thank you for responding here and offering a bit of help. I thought I was doing good with my setup and then realized the logs were a train wreck.

pnbruckner:

Error rendering data template: UndefinedError: 'None' has no attribute 'state'

That’s probably because you’re doing something like this:
states.domain.object_id.state
instead of this:
states('domain.object_id')
The former will cause this error if the entity does not exist, whereas the latter will simply return unknown instead (without causing an error.)

Crap… I have absolutely no doubt that I am doing that alot. I read something about that in the documentation but didn’t understand what it meant. That’s a bummer, yeah, I’ll have to go through and fix that grrr…a lottttt

Thank you making mention of this.

Ok, I have these corrected.

Could you give me an example of what you mean here. I really would like to spend some time correcting the dirtiness that has been created somehow.

pnbruckner · July 8, 2022, 5:34pm

I mean, just read the log. E.g.:

2022-07-06 19:04:48 ERROR (MainThread) [homeassistant.components.tts] ID3 tag error: can't sync to MPEG frame
2022-07-06 19:04:50 ERROR (Thread-18) [homeassistant.components.cast.media_player] Failed to cast media http://192.168.1.25:8123/api/tts_proxy/da39a3ee5e6b4b0d3255bfef95601890afd80709_en-us_e9beb360ac_google_cloud.mp3 from internal_url (http://192.168.1.25:8123). Please make sure the URL is: Reachable from the cast device and either a publicly resolvable hostname or an IP address
2022-07-06 19:13:12 ERROR (MainThread) [homeassistant.core] Error executing service: <ServiceCall media_player.turn_on (c:01G7AWKMDVDXAP1MBAYDFF0CRV): entity_id=['media_player.kitchen_display']>
2022-07-06 19:17:56 ERROR (MainThread) [homeassistant.core] Error executing service: <ServiceCall media_player.turn_on (c:01G7AWWA3W6C4HVMYWDSJV49SC): entity_id=['media_player.kitchen_display']>
2022-07-06 20:52:22 ERROR (MainThread) [homeassistant.core] Error executing service: <ServiceCall media_player.turn_on (c:01G7B296N4K0ZBJXXFSZYP1D42): entity_id=['media_player.kitchen_display']>
2022-07-06 20:54:03 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547525773392] Error handling message: Unauthorized (unauthorized)
2022-07-06 20:54:05 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547525773392] Error handling message: Unauthorized (unauthorized)
2022-07-06 20:54:05 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547525773392] Error handling message: Unauthorized (unauthorized)
2022-07-06 20:54:05 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547525773392] Error handling message: Unauthorized (unauthorized)
2022-07-06 20:57:02 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547525773392] Error handling message: Unauthorized (unauthorized)
2022-07-06 20:57:02 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547525773392] Error handling message: Unauthorized (unauthorized)
2022-07-06 20:57:03 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547525773392] Error handling message: Unauthorized (unauthorized)
2022-07-06 20:57:20 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547525773392] Error handling message: Unauthorized (unauthorized)
2022-07-06 20:57:20 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547525773392] Error handling message: Unauthorized (unauthorized)
2022-07-06 20:57:20 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547525773392] Error handling message: Unauthorized (unauthorized)
2022-07-07 02:19:56 ERROR (Thread-20) [pychromecast.socket_client] [Garage speaker(192.168.1.31):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.31', 8009)), retrying in 5.0s
2022-07-07 02:48:49 ERROR (Thread-18) [pychromecast.socket_client] [Kitchen Display(192.168.1.24):8009] Error reading from socket.
2022-07-07 02:48:49 ERROR (Thread-18) [pychromecast.socket_client] [Kitchen Display(192.168.1.24):8009] Failed to connect to service ServiceInfo(type='mdns', data='google-nest-hub-c3deeedff13adca948dca4908a5e8c20._googlecast._tcp.local.'), retrying in 5.0s
2022-07-07 02:50:49 ERROR (Thread-14) [pychromecast.socket_client] [Guest Bathroom speaker(192.168.1.61):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.61', 8009)), retrying in 5.0s
2022-07-07 03:16:29 ERROR (MainThread) [homeassistant.components.xiaomi_miio] Timeout fetching First Floor Vacuum data
2022-07-07 03:17:22 ERROR (Thread-15) [pychromecast.socket_client] [Guest Bedroom speaker(192.168.1.38):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.38', 8009)), retrying in 5.0s
2022-07-07 03:20:16 ERROR (Thread-19) [pychromecast.socket_client] [Master Bedroom speaker(192.168.1.41):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.41', 8009)), retrying in 5.0s
2022-07-07 03:33:43 ERROR (Thread-21) [pychromecast.socket_client] [Master Bathroom speaker(192.168.1.42):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.42', 8009)), retrying in 5.0s
2022-07-07 03:42:30 ERROR (MainThread) [homeassistant.components.xiaomi_miio] Timeout fetching Second Floor Vacuum data
2022-07-07 04:03:00 ERROR (Thread-13) [pychromecast.socket_client] [Office Wifi(192.168.1.49):8009] Error reading from socket.
2022-07-07 04:03:00 ERROR (Thread-13) [pychromecast.socket_client] [Office Wifi(192.168.1.49):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.49', 8009)), retrying in 5.0s
2022-07-07 04:06:43 ERROR (Thread-24) [pychromecast.socket_client] [Everywhere Inside Except TVs(192.168.1.37):32161] Error reading from socket.
2022-07-07 04:06:43 ERROR (Thread-23) [pychromecast.socket_client] [Everywhere except TVs(192.168.1.37):32145] Error reading from socket.
2022-07-07 04:06:43 ERROR (Thread-24) [pychromecast.socket_client] [Everywhere Inside Except TVs(192.168.1.37):32161] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.37', 32161)), retrying in 5.0s
2022-07-07 04:06:43 ERROR (Thread-23) [pychromecast.socket_client] [Everywhere except TVs(192.168.1.37):32145] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.37', 32145)), retrying in 5.0s
2022-07-07 04:07:25 ERROR (Thread-22) [pychromecast.socket_client] [Gym speaker(192.168.1.37):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.37', 8009)), retrying in 5.0s
2022-07-07 04:07:29 ERROR (Thread-23) [pychromecast.socket_client] [Everywhere except TVs(192.168.1.42):32145] Error reading from socket.
2022-07-07 04:07:29 ERROR (Thread-24) [pychromecast.socket_client] [Everywhere Inside Except TVs(192.168.1.42):32161] Error reading from socket.
2022-07-07 04:07:30 ERROR (Thread-23) [pychromecast.socket_client] [Everywhere except TVs(192.168.1.37):32145] Failed to connect to service ServiceInfo(type='mdns', data='Google-Cast-Group-1B067B9CB8B6420A851364FE12125B7A-1._googlecast._tcp.local.'), retrying in 5.0s
2022-07-07 04:07:32 ERROR (Thread-24) [pychromecast.socket_client] [Everywhere Inside Except TVs(192.168.1.42):32161] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.42', 32161)), retrying in 5.0s
2022-07-07 04:37:02 ERROR (Thread-12) [pychromecast.socket_client] [Dining Room Wifi(192.168.1.48):8009] Error reading from socket.
2022-07-07 04:37:02 ERROR (Thread-12) [pychromecast.socket_client] [Dining Room Wifi(192.168.1.48):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.48', 8009)), retrying in 5.0s

And then there’s this, which I have no idea about:

2022-07-07 04:40:35 ERROR (MainThread) [homeassistant.components.geo_location] Entity id already exists - ignoring: geo_location.lightning_strike_e1b268f5ea5752e414d1b0c3437793d99d9f8ad7

and these:

2022-07-07 11:06:06 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /host/info request
2022-07-07 11:06:06 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /supervisor/info request
2022-07-07 11:06:06 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /os/info request
2022-07-07 11:06:06 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /core/info request
2022-07-07 11:06:06 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /store request
2022-07-07 11:06:06 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /info request

You say these are not showing up on the logs page without hitting “load full logs”? That doesn’t make sense. All warnings and errors should just show up (unless you’ve dismissed them already by clicking on the CLEAR button.)

wtstreetglow · July 8, 2022, 5:52pm

So things like this

2022-07-06 20:54:05 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547525773392] Error handling message: Unauthorized (unauthorized)

How do you even begin to figure out what it is related to? To me, there is nothing identifiable in that message.

Things like these are google home devices. Absolutely no clue why they would be erroring out. The only thing I can think to do is look at the ip addresses and hope to find a connection with something.

2022-07-07 02:19:56 ERROR (Thread-20) [pychromecast.socket_client] [Garage speaker(192.168.1.31):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.31', 8009)), retrying in 5.0s

And then there’s this, which I have no idea about:

The above is from an integration that tracks lightning strikes nearby. I have put in a github issue for this one with its creator.

2022-07-07 11:06:06 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /host/info request
2022-07-07 11:06:06 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /supervisor/info request
2022-07-07 11:06:06 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /os/info request
2022-07-07 11:06:06 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /core/info request
2022-07-07 11:06:06 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /store request
2022-07-07 11:06:06 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /info request

Again, no clue on the above, there seems to be nothing identifiable in those again.

A good number of them were not unless they were possibly condensed into 1 line item in the “gui” version before hitting “Load Full Logs”

I will post a screenshot here after a couple of days to tidy up the thread. I really should’ve done that right off the bat but I was too interested in cleaning up this mess.

Here is my “logger” configuraiton file as I am trying to clean up some things with it. It’s my understanding the logger config, hides it completely, even if I hit “full logs” so I don’t think it has anything to do with the paragraph of yours that I linked above but I am including here for completeness for others that will see this thread.

Thank you @pnbruckner for being willing to help some. I promise I’m not a blockhead like it may seem.

Below is the logger config:

  default: error
  logs:
    homeassistant.core: warning
    homeassistant.loader: error
    homeassistant.components.recorder: error # to spot db issues
    homeassistant.config_entries: error
    homeassistant.setup: error
    homeassistant.components.roku: critical
    homeassistant.helpers.entity: critical
    homeassistant.components.automation: error
    homeassistant.components.waze_travel_time: error
    homeassistant.components.statistics.sensor: critical
    homeassistant.components.nws: error
    homeassistant.helpers.event: critical
    bellows: error
    zigpy: error
    homeassistant.components.zha.core: error

And lastly, below are my installed integrations:

pnbruckner · July 8, 2022, 6:27pm

No problem. Yeah, things like these can be difficult to diagnose. And many of those errors come from integrations I have no experience with.

AFAIK, you can configure the logger to filter stuff from getting into home-assistant.log. But, those settings don’t apply to the Log page in the GUI. You can’t filter errors and warnings from showing up in the GUI, which Paulus tells me is by design (or, at least that’s what he said at one time. I’m not sure if anything has changed in that regard since then.)

I notice you don’t have any debug options in your logger config. When you’re having issues with things, it’s good to set that integration’s log level to debug. Not all integrations are great about creating debug messages, but most do. So, e.g.

  logs:
    homeassistant.components.hassio: debug
    homeassistant.components.cast: debug
    pychromecast: debug

If you set, say, x.y to some logging level, that applies to messages “tagged” with that name (i.e., what’s shown inside the square brackets), as well as everything “under” it – e.g., x.y.z.

Note that debug messages don’t show up in the GUI by default (or INFO messages, for that matter.) You have to look in home-assistant.log to see them. (Honestly, not sure if they show up in the GUI when you click load full log. I’ve actually never tried that. I always look directly in, or grep, home-assistant.log.)

wtstreetglow · July 9, 2022, 1:45pm

@pnbruckner Just coming back here for completeness on my end and for whomever may read this thread in the future. Below is the “GUI” area of my home assistant setup that we were speaking of earlier.

I have posted another thread specifically about the chromecast errors so let’s see what happens with that.

I am also getting a uPNP 800 Error when attempting to send media from plex server to a sonos. I have posted a secondary thread about that one also.

Thank you again for the guidance you gave me.