Core: Error during recorder setup 0.108.0 with postgres db

[cpw]

The problem

2020-04-08 13:53:17 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: public_factory() takes 2 positional arguments but 3 were given (retrying in 3 seconds)

Since upgrading from 0.107.6 to 0.108.0 i'm getting this error. Guessing it means my db logging isn't working.

I'm using the recorder component with a postgres db backend.

Environment

• Home Assistant Core release with the issue: 0.108.0
• Last working Home Assistant Core release (if known): 0.107.6
• Operating environment (Home Assistant/Supervised/Docker/venv): venv
• Integration causing this issue: recorder
• Link to integration documentation on our website: recorder

Problem-relevant configuration.yaml

recorder:
  purge_interval: 1
  purge_keep_days: 30
  db_url: postgresql://@/homeassistantdb
  exclude:
    domains:
      - automation
      - weblink
      - updater

Traceback/Error logs

2020-04-08 13:52:50 INFO (MainThread) [homeassistant.setup] Setting up recorder
2020-04-08 13:52:50 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: public_factory() takes 2 positional arguments but 3 were given (retrying in 3 seconds)
[..]
2020-04-08 13:52:53 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: public_factory() takes 2 positional arguments but 3 were given (retrying in 3 seconds)
2020-04-08 13:52:56 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: public_factory() takes 2 positional arguments but 3 were given (retrying in 3 seconds)
2020-04-08 13:52:59 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: public_factory() takes 2 positional arguments but 3 were given (retrying in 3 seconds)
2020-04-08 13:53:00 WARNING (MainThread) [homeassistant.setup] Setup of recorder is taking over 10 seconds.
2020-04-08 13:53:02 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: public_factory() takes 2 positional arguments but 3 were given (retrying in 3 seconds)
2020-04-08 13:53:05 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: public_factory() takes 2 positional arguments but 3 were given (retrying in 3 seconds)
2020-04-08 13:53:08 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: public_factory() takes 2 positional arguments but 3 were given (retrying in 3 seconds)
2020-04-08 13:53:11 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: public_factory() takes 2 positional arguments but 3 were given (retrying in 3 seconds)
2020-04-08 13:53:14 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: public_factory() takes 2 positional arguments but 3 were given (retrying in 3 seconds)
2020-04-08 13:53:17 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: public_factory() takes 2 positional arguments but 3 were given (retrying in 3 seconds)
2020-04-08 13:53:17 INFO (MainThread) [homeassistant.setup] Setup of domain recorder took 27.1 seconds.
2020-04-08 13:53:17 ERROR (MainThread) [homeassistant.setup] Setup failed for recorder: Integration failed to initialize.

Additional information

First start after upgrade to 0.108.0

[mcnutter1]

Same here but with MySQL as a backend. Same error....

Logger: homeassistant.components.recorder
Source: components/recorder/__init__.py:259
Integration: recorder (documentation, issues)
First occurred: 12:56:36 PM (10 occurrences)
Last logged: 12:57:03 PM

Error during connection setup: public_factory() takes 2 positional arguments but 3 were given (retrying in 3 seconds)

[cpw]

OK, more information. This only shows up the _first_ time you restart after the upgrade. Something is going wrong in the symbol binding for sqlalchemy - 1.3.15 changed the public_factory method to add an additional argument, but I think somehow HASS was still exposing the _old_ version of the symbol to sqlalchemy's magic stuff, and thus causing the failure. It seems like it's a problem between HA's dynamic library loading and the sqlalchemy magic.

TLDR: a restart of HA fixes this problem, but I think there's an issue here, when doing the upgrade.

SQLAlchemy change that changed the public_factory signature: https://github.com/sqlalchemy/sqlalchemy/commit/64952ac28b1911410f2b7c08a16492716689126d

[Mechotronic]

I can't start my recorder or MariaDb now. Maria says this on startup:
[s6-init] making user provided files available at /var/run/s6/etc...exited 0.
[s6-init] ensuring user provided files have correct perms...exited 0.
[fix-attrs.d] applying ownership & permissions fixes...
[fix-attrs.d] done.
[cont-init.d] executing container initialization scripts...
[cont-init.d] done.
[services.d] starting services
[services.d] done.
[14:54:57] INFO: Using existing mariadb initial system
[14:54:57] INFO: Starting MariaDB
200408 14:54:58 mysqld_safe Logging to '/data/databases/mariadb.err'.
200408 14:54:58 mysqld_safe Starting mysqld daemon with databases from /data/databases
2020-04-08 14:54:58 0 [Note] mysqld: Aria engine: starting recovery
recovered pages: 0% 32% 51% 80% 100% (0.0 seconds); tables to flush: 2 1 0
(0.0 seconds);
2020-04-08 14:54:58 0 [Note] mysqld: Aria engine: recovery done
2020-04-08 14:54:58 0 [Note] InnoDB: Using Linux native AIO
2020-04-08 14:54:58 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2020-04-08 14:54:58 0 [Note] InnoDB: Uses event mutexes
2020-04-08 14:54:58 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2020-04-08 14:54:58 0 [Note] InnoDB: Number of pools: 1
2020-04-08 14:54:58 0 [Note] InnoDB: Using SSE2 crc32 instructions
2020-04-08 14:54:58 0 [Note] mysqld: O_TMPFILE is not supported on /var/tmp (disabling future attempts)
2020-04-08 14:54:58 0 [Note] InnoDB: Initializing buffer pool, total size = 64M, instances = 1, chunk size = 64M
2020-04-08 14:54:58 0 [Note] InnoDB: Completed initialization of buffer pool
2020-04-08 14:54:58 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-04-08 14:54:58 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=1485078770
2020-04-08 14:54:58 0 [Note] InnoDB: Starting final batch to recover 41 pages from redo log.
200408 14:54:58 [ERROR] mysqld got signal 11 ;

My hassio notifications say this:

[marklister]

systemctl status shows this running while spewing the message:

/usr/bin/python3 -m pip install --quiet sqlalchemy==1.3.15 --upgrade --constraint /home/pi/.local/lib/python3.7/site-packages/homeassistant/package_....

[sassetto]

I had same problem, upgrading from 0.106.0 to 0.108.2, with MySql during first restart. At next restart everything is ok!

[stale[bot]]

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates.
Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍
This issue now has been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.