History, logbook, recorder not working after update from 0.64x-0.65.5?

As topic says. Is that a known problem?

Thanks

There should be some errors in the log.
Please post them.

2018-03-15 12:04:51 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6)
2018-03-15 12:04:51 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6) (retrying in 3 seconds)
2018-03-15 12:04:55 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6)
2018-03-15 12:04:55 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6) (retrying in 3 seconds)
2018-03-15 12:04:58 WARNING (MainThread) [homeassistant.setup] Setup of recorder is taking over 10 seconds.
2018-03-15 12:04:59 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6)
2018-03-15 12:04:59 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6) (retrying in 3 seconds)
2018-03-15 12:05:02 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6)
2018-03-15 12:05:02 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6) (retrying in 3 seconds)
2018-03-15 12:05:06 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6)
2018-03-15 12:05:06 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6) (retrying in 3 seconds)
2018-03-15 12:05:10 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6)
2018-03-15 12:05:10 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6) (retrying in 3 seconds)
2018-03-15 12:05:13 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6)
2018-03-15 12:05:13 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6) (retrying in 3 seconds)
2018-03-15 12:05:17 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6)
2018-03-15 12:05:17 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6) (retrying in 3 seconds)
2018-03-15 12:05:21 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6)
2018-03-15 12:05:21 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6) (retrying in 3 seconds)
2018-03-15 12:05:25 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6)
2018-03-15 12:05:25 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.DatabaseError) database disk image is malformed [SQL: ‘CREATE INDEX ix_states_event_id ON states (event_id)’] (Background on this error at: http://sqlalche.me/e/4xp6) (retrying in 3 seconds)
2018-03-15 12:05:25 ERROR (MainThread) [homeassistant.setup] Setup failed for recorder: Component failed to initialize.
2018-03-15 12:05:25 ERROR (MainThread) [homeassistant.setup] Unable to setup dependencies of history. Setup failed for dependencies: recorder
2018-03-15 12:05:25 ERROR (MainThread) [homeassistant.setup] Setup failed for history: Could not setup all dependencies.
2018-03-15 12:05:26 ERROR (MainThread) [homeassistant.setup] Unable to setup dependencies of logbook. Setup failed for dependencies: recorder
2018-03-15 12:05:26 ERROR (MainThread) [homeassistant.setup] Setup failed for logbook: Could not setup all dependencies.
2018-03-15 12:05:32 WARNING (MainThread) [homeassistant.components.climate.generic_thermostat] No previously saved temperature, setting to 7.0
2018-03-15 12:05:32 WARNING (MainThread) [homeassistant.components.climate.generic_thermostat] No previously saved temperature, setting to 22.0
2018-03-15 12:05:32 WARNING (MainThread) [homeassistant.components.climate.generic_thermostat] No previously saved temperature, setting to 22.0
2018-03-15 12:05:32 WARNING (MainThread) [homeassistant.components.climate.generic_thermostat] No previously saved temperature, setting to 22.0
2018-03-15 12:05:32 WARNING (MainThread) [homeassistant.components.climate.generic_thermostat] No previously saved temperature, setting to 22.0
2018-03-15 12:05:32 WARNING (MainThread) [homeassistant.components.climate.generic_thermostat] No previously saved temperature, setting to 22.0
2018-03-15 12:05:32 WARNING (MainThread) [homeassistant.components.climate.generic_thermostat] No previously saved temperature, setting to 22.0
2018-03-15 12:05:48 WARNING (Thread-4) [netdisco.ssdp] Found malformed XML at http://192.168.1.111:9080: status=ok
2018-03-15 15:24:19 WARNING (Thread-22) [netdisco.ssdp] Found malformed XML at http://192.168.1.47:2873/dms.xml: <?xml version="1.0" encoding="utf-8"?>

1
0


dlna:X_DLNADOCDMS-1.50</dlna:X_DLNADOC>
urn:schemas-upnp-org:device:MediaServer:1
FollowTVServer:00:09:DF:A2:0E:74
ACCESS CO., LTD.
http://www.access-company.com/
NFLC SDK v1.5
1.0
http://www.access-company.com/
pnpx:X_hardwareIdVEN_0033&DEV_0001&REV_01</pnpx:X_hardwareId>
pnpx:X_compatibleIdMS_DigitalMediaDeviceClass_DMS_V001</pnpx:X_compatibleId>
pnpx:X_deviceCategoryMediaDevices</pnpx:X_deviceCategory>
df:X_deviceCategoryMultimedia.DMS</df:X_deviceCategory>
df:X_modelIdNFLC-DMS</df:X_modelId>
uuid:13cc3100-3201-1c5c-8000-0009dfa20e74


urn:schemas-upnp-org:service:ContentDirectory:1
urn:upnp-org:serviceId:ContentDirectory
/dms_cds.xml
control/ContentDirectory
event/ContentDirectory


urn:schemas-upnp-org:service:ConnectionManager:1
urn:upnp-org:serviceId:ConnectionManager
/dms_cms.xml
control/ConnectionManager
event/ConnectionManager


urn:schemas-xsrs-org:service:X_SchedudRecording:1
urn:xsrs-org:serviceId:X_SchedudRecording
/dms_srs.xml
control/ScheduledRecording
event/ScheduledRecording


urn:microsoft.com:service:X_MS_MediaReceiverRegistrar:1
urn:microsoft.com:serviceId:X_MS_MediaReceiverRegistrar
/XBOX_ext.xml
control/X_MS_MediaReceiverRegistrar
event/X_MS_MediaReceiverRegistrar




image/jpeg
48
48
24
/icon/DMS-small.jpg


image/jpeg
120
120
24
/icon/DMS-large.jpg


image/png
48
48
24
/icon/DMS-small.png


image/png
120
120
24
/icon/DMS-large.png



2018-03-15 16:45:08 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.teknikskab_humidity is taking over 10 seconds
2018-03-15 18:46:40 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal read error on socket transport
Traceback (most recent call last):
File “/usr/lib/python3.5/asyncio/selector_events.py”, line 723, in _read_ready
data = self._sock.recv(self.max_size)
TimeoutError: [Errno 110] Connection timed out
2018-03-15 20:00:00 WARNING (MainThread) [homeassistant.core] Unable to find service scene/turn_off
2018-03-15 21:32:54 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.teknikskab_humidity is taking over 10 seconds
2018-03-15 23:03:19 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.teknikskab_humidity is taking over 10 seconds
2018-03-15 23:40:10 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
File “/usr/lib/python3.5/asyncio/tasks.py”, line 241, in _step
result = coro.throw(exc)
File “/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/device_tracker/init.py”, line 356, in async_update_config
dev_id, device)
File “/usr/lib/python3.5/asyncio/futures.py”, line 380, in iter
yield self # This tells Task to wait for completion.
File “/usr/lib/python3.5/asyncio/tasks.py”, line 304, in _wakeup
future.result()
File “/usr/lib/python3.5/asyncio/futures.py”, line 293, in result
raise self._exception
File “/usr/lib/python3.5/concurrent/futures/thread.py”, line 55, in run
result = self.fn(*self.args, **self.kwargs)
File “/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/device_tracker/init.py”, line 778, in update_config
out.write(dump(device))
UnicodeEncodeError: ‘latin-1’ codec can’t encode character ‘\u015e’ in position 157: ordinal not in range(256)
2018-03-15 23:40:51 WARNING (Thread-13) [netdisco.ssdp] Found malformed XML at http://192.168.1.159:9080: status=ok
2018-03-16 02:44:56 WARNING (Thread-43) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2018-03-16 02:44:58 WARNING (Thread-24) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2018-03-16 02:44:58 WARNING (Thread-40) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2018-03-16 02:45:03 WARNING (Thread-35) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2018-03-16 02:51:10 WARNING (MainThread) [homeassistant.components.device_tracker] Updating device list from nmap_tracker took longer than the scheduled scan interval 0:00:12
2018-03-16 02:58:59 WARNING (Thread-42) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2018-03-16 02:59:01 WARNING (Thread-38) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2018-03-16 02:59:01 WARNING (Thread-39) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2018-03-16 02:59:06 WARNING (Thread-27) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2018-03-16 03:13:53 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.teknikskab_humidity is taking over 10 seconds
2018-03-16 03:16:28 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.teknikskab_temperature is taking over 10 seconds
2018-03-16 03:30:36 WARNING (Thread-34) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2018-03-16 03:30:36 WARNING (Thread-25) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2018-03-16 03:32:06 WARNING (MainThread) [homeassistant.components.device_tracker] Updating device list from nmap_tracker took longer than the scheduled scan interval 0:00:12
2018-03-16 03:38:29 WARNING (Thread-41) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2018-03-16 03:38:29 WARNING (Thread-26) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2018-03-16 03:38:34 WARNING (Thread-37) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2018-03-16 03:38:36 WARNING (Thread-44) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2018-03-16 03:55:44 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.teknikskab_humidity is taking over 10 seconds
2018-03-16 04:14:20 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.teknikskab_temperature is taking over 10 seconds
2018-03-16 05:38:01 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.teknikskab_temperature is taking over 10 seconds
2018-03-16 05:43:11 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.teknikskab_temperature is taking over 10 seconds
2018-03-16 06:56:01 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.teknikskab_temperature is taking over 10 seconds
2018-03-16 07:31:42 WARNING (MainThread) [homeassistant.core] Unable to find service scene/turn_off
2018-03-16 07:47:10 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.teknikskab_humidity is taking over 10 seconds
2018-03-16 08:07:04 WARNING (MainThread) [homeassistant.components.device_tracker] Updating device list from nmap_tracker took longer than the scheduled scan interval 0:00:12
2018-03-16 08:37:47 WARNING (MainThread) [homeassistant.components.device_tracker] Updating device list from nmap_tracker took longer than the scheduled scan interval 0:00:12
2018-03-16 09:08:33 WARNING (MainThread) [homeassistant.components.device_tracker] Updating device list from nmap_tracker took longer than the scheduled scan interval 0:00:12
2018-03-16 09:35:39 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.teknikskab_humidity is taking over 10 seconds
2018-03-16 11:40:40 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.teknikskab_temperature is taking over 10 seconds
2018-03-16 12:56:37 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.teknikskab_humidity is taking over 10 seconds
2018-03-16 14:24:58 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.teknikskab_temperature is taking over 10 seconds

Take a look here:


I’d suggest deleting the database file (home-assistant_v2.db), but you will loose all your history.

Same error. Deleting the file seems to have fixed it.

If you are like mine the problem keeps coming back. Something else is wrong since the python update and entity I’d file. My system is so unstable that recorder dies in a few hours. Opened an issue, but it has been ignored.

I’ll keep an eye on it then. I’m doing a bunch of fiddling with my Hass instance this weekend…so if ii’s gonna break, now would be the time…

I think if this was a global issue, everyone would have it. If you are using something other than hass.io I would look through /var/log/syslog
You might start off with
grep error /var/log/syslog
to see what turns up.
If you are using hass.io, I have no idea what system logs are created if any.

hass.io I’m afraid.

So far is hasn’t come back yet, but I’m doing a bunch of additions, groupings & layout changes, so if it’s going to break again, it should be soon.

@zarthan I am not implying that it is a global issue! But, then number of users with database issues and automations triggering python errors is not non-existant.

I have spent hours looking at my logs, I have tried 2 different Pi’s with 2 different power supplies, 2 new cards, 2 used cards known to be good, several re-installs from scratch and had errors within 30 minutes. Simple curl commands that error out a large part of the time and a recorder that stops within several hours of booting with a fresh database.

Yes, I am running Hassio and I am beginning to reconsider that, even though I love it.
The main log entries are as follows:

018-03-18 19:08:45 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.OperationalError) disk I/O error (Background on this error at: http://sqlalche.me/e/e3q8)
2018-03-18 19:08:45 ERROR (Recorder) [homeassistant.components.recorder] Error in database connectivity: (sqlite3.OperationalError) disk I/O error (Background on this error at: http://sqlalche.me/e/e3q8). (retrying in 3 seconds)
2018-03-18 19:12:45 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.OperationalError) disk I/O error (Background on this error at: http://sqlalche.me/e/e3q8)
2018-03-18 19:12:45 ERROR (Recorder) [homeassistant.components.recorder] Error in database connectivity: (sqlite3.OperationalError) disk I/O error (Background on this error at: http://sqlalche.me/e/e3q8). (retrying in 3 seconds)
2018-03-18 19:15:45 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.OperationalError) disk I/O error (Background on this error at: http://sqlalche.me/e/e3q8)
2018-03-18 19:15:45 ERROR (Recorder) [homeassistant.components.recorder] Error in database connectivity: (sqlite3.OperationalError) disk I/O error (Background on this error at: http://sqlalche.me/e/e3q8). (retrying in 3 seconds)
2018-03-18 19:22:45 ERROR (MainThread) [homeassistant.components.shell_command] Error running command: `/usr/bin/curl "http://192.168.1.121/control?cmd=event,FeelsLike={{state}}"`, return code: -11
NoneType: None
2018-03-18 19:24:30 ERROR (MainThread) [homeassistant.components.shell_command] Error running command: `/usr/bin/curl "http://192.168.1.121/control?cmd=event,RealTemp={{state}}"`, return code: -11
NoneType: None
2018-03-18 19:24:45 ERROR (MainThread) [homeassistant.components.shell_command] Error running command: `/usr/bin/curl "http://192.168.1.121/control?cmd=event,FeelsLike={{state}}"`, return code: -11
NoneType: None

Yes, I am venting… my system will not run for a full day and has not since either late in the 64 train or early in the 65 train. I have posted several times in different forums and have had messages from folks regarding similar issues.

@mattlward,
Some things to consider (as much for future users)
SD cards can have issues (noted that you have tried different ones)
Power supplies can be weaker than needed (noted that you have tried different ones)
Excess writing to SD card can lead to corruption (only use error mode in logging unless troubleshooting)
Consider using the MariaDB. SQLite isn’t as robust as it could be.

I am considering a separate database. I have to get a more modern nas before I can make it happen. I do not think my old D-link DNS-343 can do it.

I have a series of automations that send data to some wemos units with displays. When they are disabled things are much better. But, they work and pass data. Not sure what I could change to make them better. It is a set of 1 automation to 1 shell command and the shell command returns a -11 python error but seems to work.

I have included 1 of the pairs…

- id: "Broadcast Real Temp HTTP"
  alias: 'Broadcast Real Temp HTTP'
  initial_state: 'off'
  hide_entity: false
  trigger:
    - platform: time
      minutes: '/2'
      seconds: '30'
  action:
    - service: shell_command.wu_temp_http
      data_template:
        state: '{{ states.sensor.pws_temp_f.state }}'
shell_command:
  wu_temp_http: /usr/bin/curl "http://192.168.1.121/control?cmd=event,RealTemp={{state}}"

You can run the MariaDB on the same Pi as your hass.io install. Install from the store. I would try eliminating some items from the database. You can exclude items from the recorder using things like the following under the recorder: heading.

  exclude:
    entities:
      - sun.sun   # Don't record sun data

I have my recorder running very slim to keep it running… I think the key is in the automation and shell command posted above, but I do not see a problem and they work.

As soon as the above set is enabled this shows up…

2018-03-18 20:51:29 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/aiohttp/web_protocol.py", line 231, in data_received
    messages, upgraded, tail = self._request_parser.feed_data(data)
  File "aiohttp\_http_parser.pyx", line 295, in aiohttp._http_parser.HttpParser.feed_data
aiohttp.http_exceptions.BadStatusLine: invalid HTTP method
2018-03-18 20:52:45 ERROR (MainThread) [homeassistant.components.shell_command] Error running command: `/usr/bin/curl "http://192.168.1.121/control?cmd=event,FeelsLike={{state}}"`, return code: -11
NoneType: None