sqlite3 error on middleware start: no such column: system_settings.stg_birthday
Description
Problem/Justification
None
Impact
None
SmartDraw Connector
Katalon Manual Tests (BETA)
Activity
Fredrik
November 9, 2020 at 6:41 PM
Indeed it does, this ticket can be closed
Vladimir Vinogradenko
November 9, 2020 at 6:26 PM
@Fredrik after a reboot your system should function normally
Fredrik
November 9, 2020 at 5:45 PM
That seems to have done the trick, web ui is now working. Output below
root@truenas:~ # migrate
+ python3 -c 'import os; import middlewared; print(os.path.dirname(middlewared.__spec__.origin))'
+ cd /usr/local/lib/python3.8/site-packages/middlewared
+ alembic upgrade head
INFO [alembic.runtime.migration] Context impl SQLiteImpl.
INFO [alembic.runtime.migration] Will assume non-transactional DDL.
INFO [alembic.runtime.migration] Running upgrade 133f2d9049d2 -> 39a133a04496, empty message
INFO [alembic.runtime.migration] Running upgrade 39a133a04496 -> f3875acb8d76, Fix user shell choices
INFO [alembic.runtime.migration] Running upgrade f3875acb8d76 -> 536cbfca20e6, Drop iSCSI initiator tag column
INFO [alembic.runtime.migration] Running upgrade 536cbfca20e6 -> bc290fddc888, Simplify SMB shares
INFO [alembic.runtime.migration] Running upgrade bc290fddc888 -> f6a18dec20fa, Simplify and clean up idmap backends
INFO [alembic.runtime.migration] Running upgrade f6a18dec20fa -> 4abbf75347b2, Add SMB flag to users and groups
INFO [alembic.runtime.migration] Running upgrade 4abbf75347b2 -> 06bfbd354deb, SSH weak ciphers
INFO [alembic.runtime.migration] Running upgrade 06bfbd354deb -> b5cac06345ea, webdav_enable
INFO [alembic.runtime.migration] Running upgrade b5cac06345ea -> 8f874e6e40bc, Replication readonly
INFO [alembic.runtime.migration] Running upgrade 8f874e6e40bc -> 32f55c715352, Add ad_restrict_pam key
INFO [alembic.runtime.migration] Running upgrade 32f55c715352 -> a06b1946f6a3, empty message
INFO [alembic.runtime.migration] Running upgrade a06b1946f6a3 -> 6602857581db, API Key
INFO [alembic.runtime.migration] Running upgrade 6602857581db -> 38773ca83199, API Key created_at
INFO [alembic.runtime.migration] Running upgrade 38773ca83199 -> 29e866803c47, Overprovision
INFO [alembic.runtime.migration] Running upgrade 29e866803c47 -> 171f5b91c36e, Fix replication foreign keys
INFO [alembic.runtime.migration] Running upgrade 171f5b91c36e -> 58339783792c, TrueCommand Service Model
INFO [alembic.runtime.migration] Running upgrade 58339783792c -> 83dae64197f3, Remove asigra table
INFO [alembic.runtime.migration] Running upgrade 83dae64197f3 -> 2ab85192c49f, Encrypt SSH and certificates private keys
INFO [alembic.runtime.migration] Running upgrade 2ab85192c49f -> 43779dce3a07, Convert SMB bindip not null
INFO [alembic.runtime.migration] Running upgrade 43779dce3a07 -> 22230265ab30, iSCSI Vendor configuration
INFO [alembic.runtime.migration] Running upgrade 22230265ab30 -> 434ea5397cd3, encrypt smbhash
INFO [alembic.runtime.migration] Running upgrade 434ea5397cd3 -> 730c995cbd37, remove nmbclusters sysctl
INFO [alembic.runtime.migration] Running upgrade 730c995cbd37 -> e9e611d7c5a7, make netatalk logging configurable
INFO [alembic.runtime.migration] Running upgrade e9e611d7c5a7 -> a3ac49efb063, birthday
INFO [alembic.runtime.migration] Running upgrade a3ac49efb063 -> b694f05c1169, Run data migration on install / factory reset
INFO [alembic.runtime.migration] Running upgrade b694f05c1169 -> 1432b666093e, Remove replication dedup
INFO [alembic.runtime.migration] Running upgrade 1432b666093e -> ffcd02f6af9f, Remove alerts unique index
INFO [alembic.runtime.migration] Running upgrade ffcd02f6af9f -> 85346ccd33c0, Remove legacy freenas sysctls
INFO [alembic.runtime.migration] Running upgrade 85346ccd33c0 -> 5a365c7248da, Add next_rid column to services_cifs
INFO [alembic.runtime.migration] Running upgrade 5a365c7248da -> 8ac8158773c4, storage_disk primary key
INFO [alembic.runtime.migration] Running upgrade 8ac8158773c4 -> c01e9d77922e, Add SMB secrets
INFO [alembic.runtime.migration] Running upgrade c01e9d77922e -> 71a8d1e504a7, Add Rsyncmod enabled field
INFO [alembic.runtime.migration] Running upgrade 71a8d1e504a7 -> 25962b409a1e, cleanup AD parameters
INFO [alembic.runtime.migration] Running upgrade 25962b409a1e -> 6d3efdc7ba5b, Fix migrations state
INFO [alembic.runtime.migration] Running upgrade 6d3efdc7ba5b -> 28ecea8be3fb, Make sure builtin users are not smb users
INFO [alembic.runtime.migration] Running upgrade 28ecea8be3fb -> a3298f120609, Disk ZFS GUID
Vladimir Vinogradenko
November 9, 2020 at 2:58 PM
@Fredrik can you please run migrate
and show us what it will print?
Fredrik
November 6, 2020 at 7:38 PM
Yes, its the full file
Cannot Reproduce
Details
Details
Assignee
Triage Team
Triage TeamReporter
Fredrik
FredrikComponents
Fix versions
Affects versions
Priority
More fields
Time tracking
More fields
Time trackingKatalon Platform
Linked Test Cases, Katalon Defect Results, Katalon Studio Test Results
Katalon Platform
Linked Test Cases, Katalon Defect Results, Katalon Studio Test Results
Created October 29, 2020 at 12:58 AM
Updated July 1, 2022 at 5:00 PM
Resolved November 9, 2020 at 6:58 PM
After upgrading from freenas 11.3U(4?) to TrueNas 12.0 Release I'm having issues with middleware crashing on startup, causing nothing to work.
Seems to be a missing column in system_settings, stg_birthday (system_settings.stg_birthday)
Logs below:
[2020/10/29 00:45:14] (INFO) middlewared._init_():792 - Starting TrueNAS-12.0-RELEASE middleware
[2020/10/29 00:45:17] (ERROR) asyncio.default_exception_handler():1707 - Task exception was never retrieved
future: <Task finished name='Task-1' coro=<Middleware.__initialize() done, defined at /usr/local/lib/python3.8/site-packages/middlewared/main.py:1434> exception=OperationalError('(sqlite3.OperationalError) no such column: system_settings.stg_birthday')>
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1247, in _execute_context
self.dialect.do_execute(
File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 590, in do_execute
cursor.execute(statement, parameters)
sqlite3.OperationalError: no such column: system_settings.stg_birthday
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/middlewared/main.py", line 1480, in __initialize
await self.__plugins_setup(setup_funcs)
File "/usr/local/lib/python3.8/site-packages/middlewared/main.py", line 901, in __plugins_setup
await call
File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/pwenc.py", line 80, in setup
if not await middleware.call('pwenc.check'):
File "/usr/local/lib/python3.8/site-packages/middlewared/main.py", line 1233, in call
return await self._call(
File "/usr/local/lib/python3.8/site-packages/middlewared/main.py", line 1202, in _call
return await self.run_in_executor(prepared_call.executor, methodobj, *prepared_call.args)
File "/usr/local/lib/python3.8/site-packages/middlewared/main.py", line 1106, in run_in_executor
return await loop.run_in_executor(pool, functools.partial(method, *args, **kwargs))
File "/usr/local/lib/python3.8/site-packages/middlewared/utils/io_thread_pool_executor.py", line 25, in run
result = self.fn(*self.args, **self.kwargs)
File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/pwenc.py", line 51, in check
settings = self.middleware.call_sync('datastore.config', 'system.settings')
File "/usr/local/lib/python3.8/site-packages/middlewared/main.py", line 1249, in call_sync
return self.run_coroutine(methodobj(*prepared_call.args))
File "/usr/local/lib/python3.8/site-packages/middlewared/main.py", line 1289, in run_coroutine
return fut.result()
File "/usr/local/lib/python3.8/concurrent/futures/_base.py", line 432, in result
return self.__get_result()
File "/usr/local/lib/python3.8/concurrent/futures/_base.py", line 388, in __get_result
raise self._exception
File "/usr/local/lib/python3.8/site-packages/middlewared/schema.py", line 973, in nf
return await f(*args, **kwargs)
File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/datastore/read.py", line 185, in config
return await self.query(name, [], options)
File "/usr/local/lib/python3.8/site-packages/middlewared/schema.py", line 973, in nf
return await f(*args, **kwargs)
File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/datastore/read.py", line 156, in query
result = await self.middleware.call("datastore.fetchall", qs)
File "/usr/local/lib/python3.8/site-packages/middlewared/main.py", line 1233, in call
return await self._call(
File "/usr/local/lib/python3.8/site-packages/middlewared/main.py", line 1191, in _call
return await methodobj(*prepared_call.args)
File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/datastore/connection.py", line 74, in fetchall
return await self.middleware.run_in_executor(self.thread_pool, self._fetchall, *args)
File "/usr/local/lib/python3.8/site-packages/middlewared/main.py", line 1106, in run_in_executor
return await loop.run_in_executor(pool, functools.partial(method, *args, **kwargs))
File "/usr/local/lib/python3.8/concurrent/futures/thread.py", line 57, in run
result = self.fn(*self.args, **self.kwargs)
File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/datastore/connection.py", line 77, in _fetchall
cursor = self.connection.execute(query, params or [])
File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 984, in execute
return meth(self, multiparams, params)
File "/usr/local/lib/python3.8/site-packages/sqlalchemy/sql/elements.py", line 293, in _execute_on_connection
return connection._execute_clauseelement(self, multiparams, params)
File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1097, in _execute_clauseelement
ret = self._execute_context(
File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1287, in _execute_context
self._handle_dbapi_exception(
File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1481, in _handle_dbapi_exception
util.raise_(
File "/usr/local/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 178, in raise_
raise exception
File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1247, in _execute_context
self.dialect.do_execute(
File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 590, in do_execute
cursor.execute(statement, parameters)
sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) no such column: system_settings.stg_birthday
[SQL: SELECT system_settings.id, system_settings.stg_guiaddress, system_settings.stg_guiv6address, system_settings.stg_guiport, system_settings.stg_guihttpsport, system_settings.stg_guihttpsredirect, system_settings.stg_language, system_settings.stg_kbdmap, system_settings.stg_birthday, system_settings.stg_timezone, system_settings.stg_wizardshown, system_settings.stg_pwenc_check, system_settings.stg_guicertificate_id, system_settings.stg_crash_reporting, system_settings.stg_usage_collection, system_settings.stg_guihttpsprotocols, system_certificate_1.id, system_certificate_1.cert_type, system_certificate_1.cert_name, system_certificate_1.cert_certificate, system_certificate_1.cert_privatekey, system_certificate_1."cert_CSR", system_certificate_1.cert_signedby_id, system_certificate_1.cert_acme_uri, system_certificate_1.cert_domains_authenticators, system_certificate_1.cert_renew_days, system_certificate_1.cert_acme_id, system_certificate_1.cert_revoked_date, system_certificateauthority_1.id, system_certificateauthority_1.cert_type, system_certificateauthority_1.cert_name, system_certificateauthority_1.cert_certificate, system_certificateauthority_1.cert_privatekey, system_certificateauthority_1."cert_CSR", system_certificateauthority_1.cert_revoked_date, system_certificateauthority_1.cert_signedby_id, system_certificateauthority_2.id, system_certificateauthority_2.cert_type, system_certificateauthority_2.cert_name, system_certificateauthority_2.cert_certificate, system_certificateauthority_2.cert_privatekey, system_certificateauthority_2."cert_CSR", system_certificateauthority_2.cert_revoked_date, system_certificateauthority_2.cert_signedby_id, system_acmeregistration_1.id, system_acmeregistration_1.uri, system_acmeregistration_1.directory, system_acmeregistration_1.tos, system_acmeregistration_1.new_account_uri, system_acmeregistration_1.new_nonce_uri, system_acmeregistration_1.new_order_uri, system_acmeregistration_1.revoke_cert_uri
FROM system_settings LEFT OUTER JOIN system_certificate AS system_certificate_1 ON system_certificate_1.id = system_settings.stg_guicertificate_id LEFT OUTER JOIN system_certificateauthority AS system_certificateauthority_1 ON system_certificateauthority_1.id = system_certificate_1.cert_signedby_id LEFT OUTER JOIN system_certificateauthority AS system_certificateauthority_2 ON system_certificateauthority_2.id = system_certificateauthority_1.cert_signedby_id LEFT OUTER JOIN system_acmeregistration AS system_acmeregistration_1 ON system_acmeregistration_1.id = system_certificate_1.cert_acme_id]
(Background on this error at: http://sqlalche.me/e/e3q8)
Also getting an error on middleware termination but that may simply be caused by startup failing:
[2020/10/29 00:45:13] (INFO) middlewared.terminate():1494 - Terminating
[2020/10/29 00:45:13] (ERROR) middlewared.__terminate():1518 - Failed to terminate alert
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/middlewared/main.py", line 1516, in __terminate
await asyncio.wait_for(service.terminate(), timeout)
File "/usr/local/lib/python3.8/asyncio/tasks.py", line 483, in wait_for
return fut.result()
File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/alert.py", line 237, in terminate
await self.flush_alerts()
File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/alert.py", line 748, in flush_alerts
for alert in self.alerts:
AttributeError: 'AlertService' object has no attribute 'alerts'