Coming from the perspective of a long time linux user, I find logging in home assistant a bit in need of improvement. No criticism, I suspect the current system probably arose out of small SD card and not wanting to over fill the thing.
The problem I perceive is that the log disappears on each start of home assistant. So valuable information that might help debugging is lost.
Proposal 1
I propose that there be a user configurable number of logs to keep. On restart of home assistant the homeassistant.log is renamed to homeassistant.log.1, homeassistant.log.1 is renamed to homeassistant.log.2, and so on up to the maximum set in your configuration.
Optionally the older files could be zipped to save space.
logger:
keep_max:
zip:
Proposal 2
Include pastebinit by default in home assistant core images, and a service to use pastebinit to post your logs to a paste site and return a url to it. This can probably be done easily by a user via command_line.
Proposal 3
Proper logging over a network via syslog.
Now many people, including me, often say in response to requests like this “get coding” or “where is your PR?”. I am not a serious coder, but willing to help and test.
from the perspective of a casual linux user and HA user not sure Proposal 2 would appeal to many (just a gut feeling) and Proposal 3 sounds a bit techy, don’t know what it means exactly.
Proposal 1 sounds reasonable, I’d add moving historic logs to <config>/logs folder (leaving the current one in <config> to avoid questions like “Where’s my log”?)
Actually, instead of number of logs number of days could be even better, especially in cases when one restarts HA frequently during testing or whatever else. And it should be even easier to code
(hass) homeassi:~$ hass --help
usage: hass [-h] [--version] [-c path_to_config_dir] [--safe-mode] [--debug]
[--open-ui] [--skip-pip] [-v] [--pid-file path_to_pid_file]
[--log-rotate-days LOG_ROTATE_DAYS] [--log-file LOG_FILE]
[--log-no-color] [--runner] [--script ...] [--daemon]
Home Assistant: Observe, Control, Automate.
optional arguments:
-h, --help show this help message and exit
--version show program's version number and exit
-c path_to_config_dir, --config path_to_config_dir
Directory that contains the Home Assistant
configuration
--safe-mode Start Home Assistant in safe mode
--debug Start Home Assistant in debug mode
--open-ui Open the webinterface in a browser
--skip-pip Skips pip install of required packages on startup
-v, --verbose Enable verbose logging to file.
--pid-file path_to_pid_file
Path to PID file useful for running as daemon
--log-rotate-days LOG_ROTATE_DAYS
Enables daily log rotation and keeps up to the
specified days
--log-file LOG_FILE Log file to write to. If not set, CONFIG/home-
assistant.log is used
--log-no-color Disable color logs
--runner On restart exit with code 100
--script ... Run one of the embedded scripts
--daemon Run Home Assistant as daemon
I’m running under venv on ubuntu 16.04 LTS, as a service
I get logging to home-assistant.log as per everyone else plus way more to /var/log/syslog (with the default logger: - nothing is set in configuration.yaml):
walaj@JonLabNUC:~$ grep hass /var/log/syslog|tail -10
Apr 12 10:57:38 JonLabNUC hass[21381]: 2020-04-12 10:57:38 INFO (MainThread) [homeassistant.components.mqtt] Updating component: sensor.motion_sensor_158d000221a1ad_battery
Apr 12 10:57:38 JonLabNUC hass[21381]: 2020-04-12 10:57:38 INFO (MainThread) [homeassistant.components.automation] battery_sensor_from_attributes: Executing step call service
Apr 12 10:57:40 JonLabNUC hass[21381]: 2020-04-12 10:57:40 INFO (MainThread) [homeassistant.components.automation] Executing battery_sensor_from_attributes
Apr 12 10:57:40 JonLabNUC hass[21381]: 2020-04-12 10:57:40 INFO (MainThread) [homeassistant.components.automation] battery_sensor_from_attributes: Running script
Apr 12 10:57:40 JonLabNUC hass[21381]: 2020-04-12 10:57:40 INFO (MainThread) [homeassistant.components.automation] battery_sensor_from_attributes: Executing step call service
Apr 12 10:57:40 JonLabNUC hass[21381]: 2020-04-12 10:57:40 INFO (MainThread) [homeassistant.components.mqtt.discovery] Component has already been discovered: sensor plug_158d0002431039_battery, sending update
Apr 12 10:57:40 JonLabNUC hass[21381]: 2020-04-12 10:57:40 INFO (MainThread) [homeassistant.components.automation] battery_sensor_from_attributes: Executing step call service
Apr 12 10:57:40 JonLabNUC hass[21381]: 2020-04-12 10:57:40 INFO (MainThread) [homeassistant.components.mqtt] Got update for entity with hash: ('sensor', 'plug_158d0002431039_battery') '{'name': 'WashingMachine Battery', 'state_topic': 'homeassistant/sensor/plug_158d0002431039_battery/state', 'value_template': '{{ value_json.value | int }}', 'unit_of_measurement': '%', 'device_class': 'battery', 'unique_id': 'plug_158d0002431039_battery', 'json_attributes_topic': 'homeassistant/sensor/plug_158d0002431039_battery/attributes', 'platform': 'mqtt'}'
Apr 12 10:57:40 JonLabNUC hass[21381]: 2020-04-12 10:57:40 INFO (MainThread) [homeassistant.components.mqtt] Updating component: sensor.washingmachine_battery
Apr 12 10:57:40 JonLabNUC hass[21381]: 2020-04-12 10:57:40 INFO (MainThread) [homeassistant.components.automation] battery_sensor_from_attributes: Executing step call service
action:
- service: notify.hvaclog
data_template:
message: "Automation - At {{now().strftime('%m/%d %H:%M:%S')}} <hvac_mode1_changed> triggered by {{ trigger.entity_id }}."
and in a script:
- service: notify.hvaclog
data_template:
message: >-
Set - T-Stat1 set point now at {{ states.input_number.t1_set_point.state | int }} degrees by {{ states('input_text.hvac_trigger') }}.
Its incredibly easy to set up, completely controlled by you and can be toggled on/off with a simple input_boolean (assuming you place the notify_xxx AFTER the relevant code block.
Finally, here is a small bit of the data logged today:
Home Assistant notifications (Log started: 2020-04-08T14:34:51.008347+00:00)
--------------------------------------------------------------------------------
2020-04-12T04:00:05.016090+00:00 ================== 04/12/2020 ==================
2020-04-12T08:41:50.008183+00:00 Automation - At 04/12 04:41:50 <hvac_set_mode_2> triggered by sensor.tstat2_actual_temp to 77.
2020-04-12T08:41:50.026784+00:00 Automation - At 04/12 04:41:50 <hvac_mode2_changed> triggered by input_select.thermostat_mode_2.
2020-04-12T08:41:50.037949+00:00 Action - HVAC-2 Mode: Heat at 78.0℉
2020-04-12T08:41:50.047637+00:00 Script - At 04/12 04:41:50 <update_tstat_mode_2> started.
2020-04-12T08:41:51.230585+00:00 Automation - At 04/12 04:41:51 <hvac_set_mode_2> triggered by sensor.tstat2_currentsetpoint to 78.
2020-04-12T08:41:51.242928+00:00 Action - HVAC-2 Mode: Heat at 78.0℉
2020-04-12T08:41:56.006867+00:00 Set - T-Stat2 to heat mode by auto.hvac_set_mode_2.
2020-04-12T08:42:01.027156+00:00 Script - At 04/12 04:42:01 <update_tstat_temp_2> started.
2020-04-12T08:42:01.035220+00:00 Get - T2 set point was at 79.
For clarity I use a simple nomenclature scheme;
Automations are prefixed as Automation -
Triggered events in automations are prefixed as Action -
Script initiations are prefixed as Script -
and service actions are either Set - or Get -
Makes reading the log a bit easier to follow especially if there are built in Delays or Waits.
Each day it writes a new Day Header.
This is a great idea. It’s so good that I independently suggested it here https://github.com/home-assistant/core/issues/43155#issuecomment-752305609 to try to solve a recent problem with HA regularly crashing but leaving no clue as to why. Surely a simple solution like the existing log is renamed HA.old.log and a new log is created for this new session should be easy to implement and prevent a lot of frustration when trying to diagnose the cause of crashes in Home Assistant.
Oh and I am talking about Home Assistant system logs, not the integrations log that kartcon is talking about above.
Until the feature request is implemented there is an alternative to persist logs. Home Assistant running in Docker makes use of the journald log driver, which means that all the Home Assistant STDOUT and STDERR output ends up in the system journal. From here rsyslog puts it in the different log files, e.g. /var/log/syslog, userlog etc. as defined in the rsyslog rules. These logs are rotated and zipped.
You can change the existing rules, and also add your own rules to e.g. put all messages received from Docker in a separate file:
$template dockerlogs,"/var/log/dockerlog"
if $syslogfacility-text == ["docker"] then -?dockerlogs
But I have a request for the opposite, namely to reduce logging. Currently Home Assistant, and in particular hassio_supervisor and hassio_audio, outputs a lot of debug statements that have no meaning, even more so if your system is stable. The Home Assistant logger filter works great for “core”, but not for these components.
Cherry on the cake is that these debug statements are all logged as errors, which means that it’s also not possible to filter them out in journald or rsyslog.
The person that decided clearing all the logs upon reboot should find another job / hobby.
Devs keep telling us to upload log files when explaining that your system crashed. Otherwise they’re unwilling to help. But it is exactly in that situation home assistant nukes the logs, and we cannot upload the logs.
Why on earth is it not renaming all previous logs to something.log.old or similar upon reboot (possibly deleting something.log.old first)? I have 10+ years of experience with software development and server monitoring. My home assistant keep crashing every now and then and I have no way to troubleshoot it. I have never seen a system with this terrible logging setup.
Secondly, having the SSH-access only available as a web interface is a terrible option. Because exactly when one would like to use SSH to go into the system and inspect log files and/or do some analysis when the system is unresponsive; then the web interface is… well… unresponsive and there is no way to use SSH. If the system IS responsive and working, then we don’t need a hardcore SSH connection. Did someone have bad luck when thinking here as well?
To be fair many SD card setups run out of disk space and I can understand to an extent why they don’t save too much by default.
But take the kodi approach and save the current log AND the one before. Or automate it (theres an idea!) Then at least you get to copy the older one off to pastebin or another computer.
SSH is not just available as a web service. I regularly ssh in from my linux box. Use the ssh and web terminal addon.
Yes, but it is not just criticism. It is constructive feedback of what to do instead to improve the product so that it becomes significantly better. It does not matter if they do it on their free time. I also do development on my free time and I always appreciate constructive feedback. It this case; a very obvious and low hanging fruit that makes the developers look really bad and ignorant if they don’t implement ASAP as many users obviously experience random crashes with no information.
Maybe if home assistant was not written in a language I am unfamiliar with. For someone that knows the language and product, it should not take more than 10 minutes to fix. To me it would take weeks just to find where to do the change.
Plugins tend to not work when HA crashes. I want a native SSH server that starts and live independently from HA. If HA spawned it, it will most likely die with it. I will have a look next crash.
! I’d love a rolling log system like that.
to try to solve a recent problem with HA regularly crashing but leaving no clue as to why. Surely a simple solution like the existing log is renamed HA.old.log and a new log is created for this new session should be easy to implement and prevent a lot of frustration when trying to diagnose the cause of crashes in Home Assistant.