Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

(0.14.2) WSL1: sqlite3.DatabaseError: database disk image is malformed #6804

Closed
pybokeh opened this issue Feb 25, 2022 · 3 comments
Closed

(0.14.2) WSL1: sqlite3.DatabaseError: database disk image is malformed #6804

pybokeh opened this issue Feb 25, 2022 · 3 comments
Labels
type: bug Something isn't working

Comments

@pybokeh
Copy link

pybokeh commented Feb 25, 2022 •
edited
Loading

Summary

Local dagster/dagit environment using Ubuntu 20.04 WSL1.

Have a job consisting of 8 ops. When I execute the job through dagit's Launchpad, one or more of the ops would just run continuously/forever. In the terminal, I would get the sqlite-related error:

Exception in thread Thread-2:
Traceback (most recent call last):
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1802, in _execute_context
    self.dialect.do_execute(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 732, in do_execute
    cursor.execute(statement, parameters)
sqlite3.DatabaseError: database disk image is malformed

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/lib/python3.8/threading.py", line 932, in _bootstrap_inner
Exception while writing logger call to event log: (sqlite3.DatabaseError) database disk image is malformed
[SQL: INSERT INTO event_logs (run_id, event, dagster_event_type, timestamp, step_key, asset_key, partition) VALUES (?, ?, ?, ?, ?, ?, ?)]
[parameters: ('d8186a0b-856c-4a0d-9cbc-5666203cf8f0', '{"__class__": "EventLogEntry", "dagster_event": {"__class__": "DagsterEvent", "event_specific_data": {"__class__": "HandledOutputData", "manager_key" ... (1294 characters truncated) ... y": "count_tfid_transform_    self.run()
train", "timestamp": 1645758689.810493, "user_message": "Handled output \\"tfid_vect\\" using IO manager \\"io_manager\\""}', 'HANDLED_OUTPUT', '2022-02-25 03:11:29.810493', 'count_tfid_transform_train', None, None)]
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/watchdog/observers/api.py", line 199, in run
(Background on this error at: https://sqlalche.me/e/14/4xp6)
    self.dispatch_events(self.event_queue, self.timeout)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/watchdog/observers/api.py", line 372, in dispatch_events
    handler.dispatch(event)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/watchdog/events.py", line 403, in dispatch
    super().dispatch(event)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/watchdog/events.py", line 272, in dispatch
Exception while writing logger call to event log: (sqlite3.DatabaseError) database disk image is malformed
[SQL: INSERT INTO event_logs (run_id, event, dagster_event_type, timestamp, step_key, asset_key, partition) VALUES (?, ?, ?, ?, ?, ?, ?)]
[parameters: ('d8186a0b-856c-4a0d-9cbc-5666203cf8f0', '{"__class__": "EventLogEntry", "dagster_event": null, "error_info": null, "level": 10, "message": "text_classify - d8186a0b-856c-4a0d-9cbc-5666203cf8 ... (290 characters truncated) ... .8146846, "user_message": "Writing file at: /home/some_user/.dagster/outputs/storage/d8186a0b-856c-4a0d-9cbc-5666203cf8f0/label_encode_train/y_encoded"}', None, '2022-02-25 03:11:29.814685', 'label_encode_train', None, None)]
(Background on this error at: https://sqlalche.me/e/14/4xp6)
    {
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/core/storage/event_log/sqlite/sqlite_event_log.py", line 441, in on_modified
    self._process_log()
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/core/storage/event_log/sqlite/sqlite_event_log.py", line 423, in _process_log
    events = self._event_log_storage.get_logs_for_run(self._run_id, self._cursor)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/core/storage/event_log/sql_event_log.py", line 278, in get_logs_for_run
    events_by_id = self.get_logs_for_run_by_log_id(run_id, cursor, of_type, limit)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/core/storage/event_log/sql_event_log.py", line 233, in get_logs_for_run_by_log_id
    results = conn.execute(query).fetchall()
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1289, in execute
    return meth(self, multiparams, params, _EMPTY_EXECUTION_OPTS)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/sql/elements.py", line 325, in _execute_on_connection
    return connection._execute_clauseelement(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1481, in _execute_clauseelement
    ret = self._execute_context(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1845, in _execute_context
    self._handle_dbapi_exception(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 2026, in _handle_dbapi_exception
    util.raise_(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 207, in raise_
    raise exception
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1802, in _execute_context
    self.dialect.do_execute(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 732, in do_execute
    cursor.execute(statement, parameters)
sqlalchemy.exc.DatabaseError: (sqlite3.DatabaseError) database disk image is malformed
[SQL: SELECT event_logs.id, event_logs.event
FROM event_logs
WHERE event_logs.run_id = ? ORDER BY event_logs.id ASC
 LIMIT ? OFFSET ?]
[parameters: ('d8186a0b-856c-4a0d-9cbc-5666203cf8f0', -1, 70)]
(Background on this error at: https://sqlalche.me/e/14/4xp6)
Exception while writing logger call to event log: (sqlite3.DatabaseError) database disk image is malformed
[SQL: INSERT INTO event_logs (run_id, event, dagster_event_type, timestamp, step_key, asset_key, partition) VALUES (?, ?, ?, ?, ?, ?, ?)]
[parameters: ('d8186a0b-856c-4a0d-9cbc-5666203cf8f0', '{"__class__": "EventLogEntry", "dagster_event": {"__class__": "DagsterEvent", "event_specific_data": {"__class__": "StepFailureData", "error": {"__cl ... (12998 characters truncated) ... ep_key": "count_tfid_transform_train", "timestamp": 1645758689.8315787, "user_message": "Execution of step \\"count_tfid_transform_train\\" failed."}', 'STEP_FAILURE', '2022-02-25 03:11:29.831579', 'count_tfid_transform_train', None, None)]
Exception while writing logger call to event log: (sqlite3.DatabaseError) database disk image is malformed
[SQL: INSERT INTO event_logs (run_id, event, dagster_event_type, timestamp, step_key, asset_key, partition) VALUES (?, ?, ?, ?, ?, ?, ?)]
[parameters: ('d8186a0b-856c-4a0d-9cbc-5666203cf8f0', '{"__class__": "EventLogEntry", "dagster_event": null, "error_info": null, "level": 40, "message": "text_classify - d8186a0b-856c-4a0d-9cbc-5666203cf8 ... (230 characters truncated) ... : 1645758690.112273, "user_message": "Step count_tfid_transform_train finished without success or failure event. Downstream steps will not execute."}', None, '2022-02-25 03:11:30.112273', None, None, None)]
(Background on this error at: https://sqlalche.me/e/14/4xp6)
Exception while writing logger call to event log: (sqlite3.DatabaseError) database disk image is malformed
[SQL: INSERT INTO event_logs (run_id, event, dagster_event_type, timestamp, step_key, asset_key, partition) VALUES (?, ?, ?, ?, ?, ?, ?)]
[parameters: ('d8186a0b-856c-4a0d-9cbc-5666203cf8f0', '{"__class__": "EventLogEntry", "dagster_event": {"__class__": "DagsterEvent", "event_specific_data": {"__class__": "PipelineFailureData", "error": {" ... (10379 characters truncated) ...  null, "timestamp": 1645758690.1417816, "user_message": "Execution of run for \\"text_classify\\" failed. An exception was thrown during execution."}', 'PIPELINE_FAILURE', '2022-02-25 03:11:30.141782', None, None, None)]
(Background on this error at: https://sqlalche.me/e/14/4xp6)
Process SpawnProcess-1:
Traceback (most recent call last):
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1802, in _execute_context
    self.dialect.do_execute(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 732, in do_execute
    cursor.execute(statement, parameters)
sqlite3.DatabaseError: database disk image is malformed

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/lib/python3.8/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/usr/lib/python3.8/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/grpc/impl.py", line 188, in start_run_in_subprocess
    _run_in_subprocess(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/grpc/impl.py", line 175, in _run_in_subprocess
    instance.report_engine_event(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/core/instance/__init__.py", line 1366, in report_engine_event
    self.handle_new_event(event_record)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/core/instance/__init__.py", line 1292, in handle_new_event
    self._event_storage.store_event(event)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/core/storage/event_log/sqlite/sqlite_event_log.py", line 231, in store_event
    conn.execute(insert_event_statement)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1289, in execute
    return meth(self, multiparams, params, _EMPTY_EXECUTION_OPTS)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/sql/elements.py", line 325, in _execute_on_connection
    return connection._execute_clauseelement(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1481, in _execute_clauseelement
    ret = self._execute_context(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1845, in _execute_context
    self._handle_dbapi_exception(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 2026, in _handle_dbapi_exception
    util.raise_(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 207, in raise_
    raise exception
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1802, in _execute_context
    self.dialect.do_execute(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 732, in do_execute
    cursor.execute(statement, parameters)
sqlalchemy.exc.DatabaseError: (sqlite3.DatabaseError) database disk image is malformed
[SQL: INSERT INTO event_logs (run_id, event, dagster_event_type, timestamp, step_key, asset_key, partition) VALUES (?, ?, ?, ?, ?, ?, ?)]
[parameters: ('d8186a0b-856c-4a0d-9cbc-5666203cf8f0', '{"__class__": "EventLogEntry", "dagster_event": {"__class__": "DagsterEvent", "event_specific_data": {"__class__": "EngineEventData", "error": null,  ... (430 characters truncated) ... d": "d8186a0b-856c-4a0d-9cbc-5666203cf8f0", "step_key": null, "timestamp": 1645758690.1599178, "user_message": "Process for run exited (pid: 7888)."}', 'ENGINE_EVENT', '2022-02-25 03:11:30.159918', None, None, None)]
(Background on this error at: https://sqlalche.me/e/14/4xp6)
Exception in thread grpc-server-cleanup:
Traceback (most recent call last):
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1802, in _execute_context
    self.dialect.do_execute(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 732, in do_execute
    cursor.execute(statement, parameters)
sqlite3.DatabaseError: database disk image is malformed

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/lib/python3.8/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.8/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/grpc/server.py", line 256, in _cleanup_thread
    self._check_for_orphaned_runs()
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/grpc/server.py", line 276, in _check_for_orphaned_runs
    instance.report_engine_event(message, run, cls=self.__class__)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/core/instance/__init__.py", line 1366, in report_engine_event
    self.handle_new_event(event_record)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/core/instance/__init__.py", line 1292, in handle_new_event
    self._event_storage.store_event(event)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/core/storage/event_log/sqlite/sqlite_event_log.py", line 230, in store_event
    with self.run_connection(run_id) as conn:
  File "/usr/lib/python3.8/contextlib.py", line 113, in __enter__
    return next(self.gen)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/core/storage/event_log/sqlite/sqlite_event_log.py", line 196, in _connect
    self._initdb(engine)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/core/storage/event_log/sqlite/sqlite_event_log.py", line 150, in _initdb
    db_revision, head_revision = check_alembic_revision(alembic_config, connection)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/dagster/core/storage/sql.py", line 52, in check_alembic_revision
    db_revision = migration_context.get_current_revision()
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/alembic/runtime/migration.py", line 431, in get_current_revision
    heads = self.get_current_heads()
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/alembic/runtime/migration.py", line 478, in get_current_heads
    if not self._has_version_table():
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/alembic/runtime/migration.py", line 491, in _has_version_table
    return sqla_compat._connectable_has_table(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/alembic/util/sqla_compat.py", line 125, in _connectable_has_table
    return inspect(connectable).has_table(tablename, schemaname)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/reflection.py", line 283, in has_table
    return self.dialect.has_table(conn, table_name, schema)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/dialects/sqlite/base.py", line 2018, in has_table
    info = self._get_table_pragma(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/dialects/sqlite/base.py", line 2540, in _get_table_pragma
    cursor = connection.exec_driver_sql(statement)
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1669, in exec_driver_sql
    return self._exec_driver_sql(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1578, in _exec_driver_sql
    ret = self._execute_context(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1845, in _execute_context
    self._handle_dbapi_exception(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 2026, in _handle_dbapi_exception
    util.raise_(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 207, in raise_
    raise exception
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1802, in _execute_context
    self.dialect.do_execute(
  File "/home/some_user/envs/dagster_dev/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 732, in do_execute
    cursor.execute(statement, parameters)
sqlalchemy.exc.DatabaseError: (sqlite3.DatabaseError) database disk image is malformed
[SQL: PRAGMA main.table_info("alembic_version")]
(Background on this error at: https://sqlalche.me/e/14/4xp6)

Killed dagit. Deleted folders containing sqlite databases to ensure a fresh new start. Re-started dagit and tried again, then one of the ops failed (also not one of the ops that failed during the first run). Killed dagit. Again, deleted the sqlite databases to ensure fresh start, re-started dagit. Same problem occurs with one or more random ops running continuously. So it appears it isn't any one particular op that is causing the issue.

FWIW, some more details about the job: the job consists of ops that read local csv files, encode certain columns using scikit-learn encoders, and pass data between ops. The ops yield Output(). I also have another job, that is very plain, vanilla, hello world type of example where ops return just string. This simple job runs fine with no sqlite errors. The job that is failing is similar to this example which is btw my wip repo.

dagster.yaml file contains:

telemetry:
  enabled: false

I've tried using ConsolidatedSqliteEventLogStorage in dagster.yaml, but problem still remained. Also added LocalArtifactStorage, but problem still remained.

Problem might be remotely or somewhat related to this issue as when I launch dagit, it outputs the following at the very beginning of the terminal:

E0224 22:50:24.117848800   14069 socket_utils_common_posix.cc:223] check for SO_REUSEPORT: {"created":"@1645761024.117833900","description":"Protocol not available","errno":92,"file":"src/core/lib/iomgr/socket_utils_common_posix.cc","file_line":202,"os_error":"Protocol not available","syscall":"getsockopt(SO_REUSEPORT)"}
2022-02-24 22:50:24 -0500 - dagit - INFO - Serving dagit on http://127.0.0.1:3001 in process 14067
E0224 22:51:47.735481600   14138 fork_posix.cc:76]           Other threads are currently calling into gRPC, skipping fork() handlers
E0224 22:51:47.810687300   14138 fork_posix.cc:76]           Other threads are currently calling into gRPC, skipping fork() handlers

EDIT: Forgot to mention why this issue may be related to my other WSL1 issue or at least the problem has to do with WSL1, when I run this exact same job in native Windows environment, I do not get this problem at all.

EDIT2: Will report back if problem occurs still if I upgrade to WSL2.

Message from the maintainers:

Impacted by this bug? Give it a 👍. We factor engagement into prioritization.
@pybokeh pybokeh added the type: bug Something isn't working label Feb 25, 2022
@pybokeh
Copy link
Author

pybokeh commented Feb 25, 2022 •
edited
Loading

Switched to WSL2 and problem does not occur. Switched back to WSL1, problem re-occurs. For those wondering why I or my colleagues don't just use WSL2, have to perform an annoying hack to get WSL2 working with company's VPN so it would be great if can get dagster working with WSL1.

EDIT: I switched to a Postgres backend. Have not experienced any issues so far.

@yuhan
Copy link
Contributor

yuhan commented Apr 5, 2022

The issue seems related to incompatibility between WSL2 and Sqlite - microsoft/WSL#2395
I'm closing the issue for now as it's unlikely that we'll have a solution in foreseeable future. Please reopen if there is something we can address on our end.

@yuhan yuhan closed this as completed Apr 5, 2022
@pybokeh
Copy link
Author

pybokeh commented Apr 7, 2022

Thanks @yuhan ! Just for clarification, I am not having this problem using WSL2, just WSL1.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
type: bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@pybokeh @yuhan