Skip to content
This repository has been archived by the owner on Apr 26, 2024. It is now read-only.

sqlite3.OperationalError: duplicate column Issue after upgrading to Synapse v1.6.1 #6463

Closed
menturion opened this issue Dec 4, 2019 · 6 comments
Closed

sqlite3.OperationalError: duplicate column Issue after upgrading to Synapse v1.6.1 #6463

menturion opened this issue Dec 4, 2019 · 6 comments

Comments

@menturion
Copy link

menturion commented Dec 4, 2019 •
edited
Loading

I am getting a "sqlite3.OperationalError: duplicate column" issue after upgrading to Synapse v1.6.1.

See relevant log file excerpt(s) below:

2019-12-03 18:09:57,411 - twisted - 172 - INFO - None - Redirected stdout/stderr to logs
2019-12-03 18:09:57,412 - root - 237 - WARNING - None - ***** STARTING SERVER *****
2019-12-03 18:09:57,412 - root - 238 - WARNING - None - Server /var/www/webroot/synapse/env/lib/python3.7/site-packages/synapse/app/homeserver.py version 1.6.1
2019-12-03 18:09:57,412 - root - 239 - INFO - None - Server hostname: myhostname
2019-12-03 18:09:57,412 - synapse.app.homeserver - 360 - INFO - None - Preparing database: sqlite3...
2019-12-03 18:09:57,459 - synapse.storage.prepare_database - 301 - INFO - None - Upgrading schema to v56
2019-12-03 18:09:57,460 - synapse.storage.prepare_database - 364 - INFO - None - Applying schema 56/add_spans_to_device_lists.sql
2019-12-03 18:09:57,468 - synapse.storage.prepare_database - 364 - INFO - None - Applying schema 56/delete_keys_from_deleted_backups.sql
2019-12-03 18:09:57,469 - synapse.storage.prepare_database - 364 - INFO - None - Applying schema 56/destinations_failure_ts.sql
2019-12-03 18:09:57,470 - synapse.storage.prepare_database - 364 - INFO - None - Applying schema 56/devices_last_seen.sql
2019-12-03 18:09:57,471 - synapse.storage.prepare_database - 364 - INFO - None - Applying schema 56/drop_unused_event_tables.sql
2019-12-03 18:09:57,474 - synapse.storage.prepare_database - 364 - INFO - None - Applying schema 56/event_labels.sql
2019-12-03 18:09:57,474 - synapse.storage.prepare_database - 364 - INFO - None - Applying schema 56/event_labels_background_update.sql
2019-12-03 18:09:57,475 - synapse.storage.prepare_database - 364 - INFO - None - Applying schema 56/fix_room_keys_index.sql
2019-12-03 18:09:57,476 - synapse.storage.prepare_database - 364 - INFO - None - Applying schema 56/hidden_devices.sql
2019-12-03 18:09:57,476 - synapse.storage.prepare_database - 368 - INFO - None - Applying engine-specific schema 56/hidden_devices_fix.sql.sqlite
2019-12-03 18:09:57,478 - synapse.storage.prepare_database - 364 - INFO - None - Applying schema 56/public_room_list_idx.sql
2019-12-03 18:09:57,478 - synapse.storage.prepare_database - 364 - INFO - None - Applying schema 56/redaction_censor.sql
2019-12-03 18:09:57,480 - twisted - 172 - ERROR -  - Traceback (most recent call last):
2019-12-03 18:09:57,480 - twisted - 172 - ERROR -  -   File "/opt/python37/lib/python3.7/runpy.py", line 193, in _run_module_as_main
2019-12-03 18:09:57,481 - twisted - 172 - ERROR -  -     "__main__", mod_spec)
2019-12-03 18:09:57,482 - twisted - 172 - ERROR -  -   File "/opt/python37/lib/python3.7/runpy.py", line 85, in _run_code
2019-12-03 18:09:57,482 - twisted - 172 - ERROR -  -     exec(code, run_globals)
2019-12-03 18:09:57,482 - twisted - 172 - ERROR -  -   File "/var/www/webroot/synapse/env/lib/python3.7/site-packages/synapse/app/homeserver.py", line 669, in <module>
2019-12-03 18:09:57,483 - twisted - 172 - ERROR -  -     main()
2019-12-03 18:09:57,483 - twisted - 172 - ERROR -  -   File "/var/www/webroot/synapse/env/lib/python3.7/site-packages/synapse/app/homeserver.py", line 664, in main
2019-12-03 18:09:57,483 - twisted - 172 - ERROR -  -     hs = setup(sys.argv[1:])
2019-12-03 18:09:57,484 - twisted - 172 - ERROR -  -   File "/var/www/webroot/synapse/env/lib/python3.7/site-packages/synapse/app/homeserver.py", line 364, in setup
2019-12-03 18:09:57,484 - twisted - 172 - ERROR -  -     prepare_database(db_conn, database_engine, config=config)
2019-12-03 18:09:57,484 - twisted - 172 - ERROR -  -   File "/var/www/webroot/synapse/env/lib/python3.7/site-packages/synapse/storage/prepare_database.py", line 82, in prepare_database
2019-12-03 18:09:57,485 - twisted - 172 - ERROR -  -     data_stores=data_stores,
2019-12-03 18:09:57,485 - twisted - 172 - ERROR -  -   File "/var/www/webroot/synapse/env/lib/python3.7/site-packages/synapse/storage/prepare_database.py", line 365, in _upgrade_existing_database
2019-12-03 18:09:57,486 - twisted - 172 - ERROR -  -     executescript(cur, absolute_path)
2019-12-03 18:09:57,486 - twisted - 172 - ERROR -  -   File "/var/www/webroot/synapse/env/lib/python3.7/site-packages/synapse/storage/prepare_database.py", line 504, in executescript
2019-12-03 18:09:57,486 - twisted - 172 - ERROR -  -     txn.execute(statement)
2019-12-03 18:09:57,486 - twisted - 172 - ERROR -  - sqlite3.OperationalError: near "WHERE": syntax error

2019-12-03 18:11:20,459 - twisted - 172 - INFO - None - Redirected stdout/stderr to logs
2019-12-03 18:11:20,459 - root - 237 - WARNING - None - ***** STARTING SERVER *****
2019-12-03 18:11:20,459 - root - 238 - WARNING - None - Server /var/www/webroot/synapse/env/lib/python3.7/site-packages/synapse/app/homeserver.py version 1.6.1
2019-12-03 18:11:20,459 - root - 239 - INFO - None - Server hostname: myhostname
2019-12-03 18:11:20,459 - synapse.app.homeserver - 360 - INFO - None - Preparing database: sqlite3...
2019-12-03 18:11:20,463 - synapse.storage.prepare_database - 301 - INFO - None - Upgrading schema to v56
2019-12-03 18:11:20,464 - synapse.storage.prepare_database - 364 - INFO - None - Applying schema 56/add_spans_to_device_lists.sql
2019-12-03 18:11:20,464 - twisted - 172 - ERROR -  - Traceback (most recent call last):
2019-12-03 18:11:20,465 - twisted - 172 - ERROR -  -   File "/opt/python37/lib/python3.7/runpy.py", line 193, in _run_module_as_main
2019-12-03 18:11:20,465 - twisted - 172 - ERROR -  -     "__main__", mod_spec)
2019-12-03 18:11:20,465 - twisted - 172 - ERROR -  -   File "/opt/python37/lib/python3.7/runpy.py", line 85, in _run_code
2019-12-03 18:11:20,466 - twisted - 172 - ERROR -  -     exec(code, run_globals)
2019-12-03 18:11:20,466 - twisted - 172 - ERROR -  -   File "/var/www/webroot/synapse/env/lib/python3.7/site-packages/synapse/app/homeserver.py", line 669, in <module>
2019-12-03 18:11:20,467 - twisted - 172 - ERROR -  -     main()
2019-12-03 18:11:20,467 - twisted - 172 - ERROR -  -   File "/var/www/webroot/synapse/env/lib/python3.7/site-packages/synapse/app/homeserver.py", line 664, in main
2019-12-03 18:11:20,467 - twisted - 172 - ERROR -  -     hs = setup(sys.argv[1:])
2019-12-03 18:11:20,468 - twisted - 172 - ERROR -  -   File "/var/www/webroot/synapse/env/lib/python3.7/site-packages/synapse/app/homeserver.py", line 364, in setup
2019-12-03 18:11:20,468 - twisted - 172 - ERROR -  -     prepare_database(db_conn, database_engine, config=config)
2019-12-03 18:11:20,468 - twisted - 172 - ERROR -  -   File "/var/www/webroot/synapse/env/lib/python3.7/site-packages/synapse/storage/prepare_database.py", line 82, in prepare_database
2019-12-03 18:11:20,469 - twisted - 172 - ERROR -  -     data_stores=data_stores,
2019-12-03 18:11:20,469 - twisted - 172 - ERROR -  -   File "/var/www/webroot/synapse/env/lib/python3.7/site-packages/synapse/storage/prepare_database.py", line 365, in _upgrade_existing_database
2019-12-03 18:11:20,469 - twisted - 172 - ERROR -  -     executescript(cur, absolute_path)
2019-12-03 18:11:20,470 - twisted - 172 - ERROR -  -   File "/var/www/webroot/synapse/env/lib/python3.7/site-packages/synapse/storage/prepare_database.py", line 504, in executescript
2019-12-03 18:11:20,470 - twisted - 172 - ERROR -  -     txn.execute(statement)
2019-12-03 18:11:20,470 - twisted - 172 - ERROR -  - sqlite3.OperationalError: duplicate column name: opentracing_context
@richvdh
Copy link
Member

richvdh commented Dec 4, 2019

The original error is a duplicate of #6246.

The 'duplicate column name' error is due to its rerunning add_spans_to_device_lists.sql, which... shouldn't happen.

Can you show the results of the following sql queries on your database file:

select * from schema_version;

select * from applied_schema_deltas where version=56;

@menturion
Copy link
Author

Please find the result below:

sqlite> select * from schema_version;
X|56|1
sqlite> select * from applied_schema_deltas where version=56;
56|56/current_state_events_membership.sql
56|56/current_state_events_membership_mk2.sql
56|56/room_membership_idx.sql

@richvdh
Copy link
Member

richvdh commented Dec 4, 2019

right, I think I know what's happened here, and have opened #6467 to track the underlying problem.

You can work around the duplicate column problem with:

INSERT INTO applied_schema_deltas VALUES (56, '56/add_spans_to_device_lists.sql');

... however, that won't fix the support for sqlite 3.7, for which you'll have to either wait for a fix to #6246 or upgrade sqlite to something a bit more modern.

@richvdh richvdh closed this as completed Dec 4, 2019
@menturion
Copy link
Author

Thanks for the info. I am getting the following error message:

sqlite> INSERT INTO applied_schema_deltas VALUES (56, '56/add_spans_to_device_lists.sql');
Error: no such table: applied_schema_deltas

@richvdh
Copy link
Member

richvdh commented Dec 4, 2019

somehow you managed to select from that table here

are you sure you have pointed sqlite3 at the right database file?

@menturion
Copy link
Author

I am wondering too. I did it as shown above.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@richvdh @menturion