[REA-2863] File is too large for PlainTableReader!

[lukoktonos]

Summary

If the snapshotting of a large (~100 GiB) table gets interrupted before compaction finishes (as can easily happen if one forgets to run ulimit -n to allow readyset to use more file descriptors than the default 1024), Readyset Panics when re-opening persistent state.

Description

See summary

Expected behavior

ReadySet can open persistent state and complete the compaction of any snapshot table

Actual behavior

Readyset permanently fails if rocksdb gets into the state where a file is too big to open for PlainTableReader

Steps to reproduce

1. Snapshot a 100GiB table (in my case, the table had (int, bytea) where bytea was random 64kiB of data for each row)-- not sure if this is the minimal size that will reproduce this.
2. Interrupt compaction before it finishes
3. Restart readyset
4. Should see the panic

ReadySet version

readyset
release-version: unknown-release-version
commit_id:       6316109b9b3eee40328945c498c7d6eeb496c14e
platform:        x86_64-unknown-linux-gnu
rustc_version:   rustc 1.70.0-nightly (f63ccaf25 2023-03-06)
profile:         release
opt_level:       3
ubuntu@ip-10-0-0-66:~$

Upstream DB type and version

Postgres 14.5

Instance Details

• i-0fde78bb18b00860a in sandbox account, us-east-2, m6a.8xlarge connected to RDS aurora serverless postgres

Logs

thread 'tokio-runtime-worker' panicked at 'called `Result::unwrap()` on an `Err` value: Error { message: "Not implemented: File is too large for PlainTableReader!" }', dataflow-state/src/persistent_state.rs:166:30

dataflow-state/src/persistent_state.rs:166:30
stack backtrace:
   0: rust_begin_unwind
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/std/src/panicking.rs:579:5
   1: core::panicking::panic_fmt
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/core/src/panicking.rs:64:14
   2: core::result::unwrap_failed
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/core/src/result.rs:1750:5
   3: core::result::Result<T,E>::unwrap
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/core/src/result.rs:1090:23
   4: <&rocksdb::db::DBCommon<rocksdb::db::SingleThreaded,rocksdb::db::DBWithThreadModeInner> as dataflow_state::persistent_state::Put>::do_put
         	at /readyset/dataflow-state/src/persistent_state.rs:166:9
   5: dataflow_state::persistent_state::Put::save_meta
         	at /readyset/dataflow-state/src/persistent_state.rs:156:9
   6: dataflow_state::persistent_state::increment_epoch
         	at /readyset/dataflow-state/src/persistent_state.rs:185:5
   7: dataflow_state::persistent_state::PersistentState::new_inner
         	at /readyset/dataflow-state/src/persistent_state.rs:1485:20
   8: dataflow_state::persistent_state::PersistentState::new
         	at /readyset/dataflow-state/src/persistent_state.rs:1395:15
   9: readyset_dataflow::domain::initialize_state::{{closure}}::{{closure}}
         	at /readyset/readyset-dataflow/src/domain/mod.rs:705:21
  10: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/blocking/task.rs:42:21
  11: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/task/core.rs:223:17
  12: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/loom/std/unsafe_cell.rs:14:9
  13: tokio::runtime::task::core::Core<T,S>::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/task/core.rs:212:13
  14: tokio::runtime::task::harness::poll_future::{{closure}}
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/task/harness.rs:476:19
  15: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/core/src/panic/unwind_safe.rs:271:9
  16: std::panicking::try::do_call
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/std/src/panicking.rs:487:40
  17: std::panicking::try
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/std/src/panicking.rs:451:19
  18: std::panic::catch_unwind
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/std/src/panic.rs:140:14
  19: tokio::runtime::task::harness::poll_future
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/task/harness.rs:464:18
  20: tokio::runtime::task::harness::Harness<T,S>::poll_inner
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/task/harness.rs:198:27
  21: tokio::runtime::task::harness::Harness<T,S>::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/task/harness.rs:152:15
  22: tokio::runtime::task::raw::RawTask::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/task/raw.rs:200:18
  23: tokio::runtime::task::UnownedTask<S>::run
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/task/mod.rs:431:9
  24: tokio::runtime::blocking::pool::Task::run
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/blocking/pool.rs:159:9
  25: tokio::runtime::blocking::pool::Inner::run
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/blocking/pool.rs:513:17
  26: tokio::runtime::blocking::pool::Spawner::spawn_thread::{{closure}}
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/blocking/pool.rs:471:13
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread 'Domain 0.0.0' panicked at 'called `Result::unwrap()` on an `Err` value: JoinError::Panic(Id(65), ...)', readyset-dataflow/src/domain/mod.rs:712:10
stack backtrace:
   0: rust_begin_unwind
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/std/src/panicking.rs:579:5
   1: core::panicking::panic_fmt
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/core/src/panicking.rs:64:14
   2: core::result::unwrap_failed
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/core/src/result.rs:1750:5
   3: core::result::Result<T,E>::unwrap
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/core/src/result.rs:1090:23
   4: readyset_dataflow::domain::initialize_state::{{closure}}
         	at /readyset/readyset-dataflow/src/domain/mod.rs:686:9
   5: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tracing-0.1.37/src/instrument.rs:272:9
   6: <F as futures_core::future::TryFuture>::try_poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/futures-core-0.3.21/src/future.rs:82:9
   7: <futures_util::future::try_future::into_future::IntoFuture<Fut> as core::future::future::Future>::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.21/src/future/try_future/into_future.rs:34:9
   8: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.21/src/future/future/map.rs:55:37
   9: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.21/src/lib.rs:91:13
  10: <futures_util::future::try_future::MapErr<Fut,F> as core::future::future::Future>::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.21/src/lib.rs:91:13
  11: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::future::future::Future>::poll
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/core/src/panic/unwind_safe.rs:296:9
  12: <futures_util::future::future::catch_unwind::CatchUnwind<Fut> as core::future::future::Future>::poll::{{closure}}
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.21/src/future/future/catch_unwind.rs:36:42
  13: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/core/src/panic/unwind_safe.rs:271:9
  14: std::panicking::try::do_call
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/std/src/panicking.rs:487:40
  15: std::panicking::try
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/std/src/panicking.rs:451:19
  16: std::panic::catch_unwind
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/std/src/panic.rs:140:14
  17: <futures_util::future::future::catch_unwind::CatchUnwind<Fut> as core::future::future::Future>::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.21/src/future/future/catch_unwind.rs:36:9
  18: <F as futures_core::future::TryFuture>::try_poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/futures-core-0.3.21/src/future.rs:82:9
  19: <futures_util::future::try_future::into_future::IntoFuture<Fut> as core::future::future::Future>::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.21/src/future/try_future/into_future.rs:34:9
  20: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.21/src/future/future/map.rs:55:37
  21: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.21/src/lib.rs:91:13
  22: <futures_util::future::try_future::UnwrapOrElse<Fut,F> as core::future::future::Future>::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.21/src/lib.rs:91:13
  23: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/task/core.rs:223:17
  24: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/loom/std/unsafe_cell.rs:14:9
  25: tokio::runtime::task::core::Core<T,S>::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/task/core.rs:212:13
  26: tokio::runtime::task::harness::poll_future::{{closure}}
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/task/harness.rs:476:19
  27: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/core/src/panic/unwind_safe.rs:271:9
  28: std::panicking::try::do_call
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/std/src/panicking.rs:487:40
  29: std::panicking::try
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/std/src/panicking.rs:451:19
  30: std::panic::catch_unwind
         	at /rustc/f63ccaf25f74151a5d8ce057904cd944074b01d2/library/std/src/panic.rs:140:14
  31: tokio::runtime::task::harness::poll_future
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/task/harness.rs:464:18
  32: tokio::runtime::task::harness::Harness<T,S>::poll_inner
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/task/harness.rs:198:27
  33: tokio::runtime::task::harness::Harness<T,S>::poll
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/task/harness.rs:152:15
  34: tokio::runtime::task::LocalNotified<S>::run
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/task/mod.rs:394:9
  35: tokio::runtime::scheduler::current_thread::CoreGuard::block_on::{{closure}}::{{closure}}
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/scheduler/current_thread.rs:584:25
  36: tokio::runtime::coop::with_budget
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/coop.rs:107:5
  37: tokio::runtime::coop::budget
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/coop.rs:73:5
  38: tokio::runtime::scheduler::current_thread::Context::run_task::{{closure}}
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/scheduler/current_thread.rs:285:29
  39: tokio::runtime::scheduler::current_thread::Context::enter
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/scheduler/current_thread.rs:350:19
  40: tokio::runtime::scheduler::current_thread::Context::run_task
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/scheduler/current_thread.rs:285:9
  41: tokio::runtime::scheduler::current_thread::CoreGuard::block_on::{{closure}}
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/scheduler/current_thread.rs:583:34
  42: tokio::runtime::scheduler::current_thread::CoreGuard::enter::{{closure}}
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/scheduler/current_thread.rs:615:57
  43: tokio::macros::scoped_tls::ScopedKey<T>::set
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/macros/scoped_tls.rs:61:9
  44: tokio::runtime::scheduler::current_thread::CoreGuard::enter
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/scheduler/current_thread.rs:615:27
  45: tokio::runtime::scheduler::current_thread::CoreGuard::block_on
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/scheduler/current_thread.rs:530:19
  46: tokio::runtime::scheduler::current_thread::CurrentThread::block_on
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/scheduler/current_thread.rs:154:24
  47: tokio::runtime::runtime::Runtime::block_on
         	at ./.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.28.1/src/runtime/runtime.rs:302:47
  48: readyset_server::worker::Worker::handle_worker_request::{{closure}}::{{closure}}
         	at /readyset/readyset-server/src/worker/mod.rs:337:33
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

This is the max size for PlainTable in rocksdb
  static const uint64_t kMaxFileSize = (1u << 31) - 1;


Rocksdb logs:

428-2023/06/05-01:33:46.608577 361431 [db/compaction/compaction_job.cc:1586] [0] [JOB 4] Generated table #1865: 100300 keys, 6680082120 bytes, temperature: kUnknown
429-2023/06/05-01:33:46.608655 361431 EVENT_LOG_v1 {"time_micros": 1685928826608618, "cf_name": "0", "job": 4, "event": "table_file_creation", "file_number": 1865, "file_size": 6680082120, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 1459204, "largest_seqno": 1559503, "table_properties": {"data_size": 6679177600, "index_size": 778421, "index_partitions": 0, "top_level_index_size": 0, "index_key_is_user_key": 0, "index_value_is_delta_encoded": 0, "filter_size": 125375, "raw_key_size": 1504500, "raw_average_key_size": 15, "raw_value_size": 6677271900, "raw_average_value_size": 66573, "num_data_blocks": 1, "num_entries": 100300, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 0, "filter_policy": "", "column_family_name": "0", "column_family_id": 2, "comparator": "", "merge_operator": "", "prefix_extractor_name": "key", "property_collectors": "", "compression": "", "compression_options": "", "creation_time": 0, "oldest_key_time": 0, "file_creation_time": 0, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "0488e114-7f5f-4c48-b43f-4ef04d10f0ac", "db_session_id": "BRRRUZ9VLRYNNFPW34B1", "orig_file_number": 1865, "seqno_to_time_mapping": "N/A"}}
430:2023/06/05-01:33:46.610730 361431 [WARN] [db/db_impl/db_impl_compaction_flush.cc:3582] Compaction error: Not implemented: File is too large for PlainTableReader!
431:2023/06/05-01:33:46.610741 361431 [WARN] [db/error_handler.cc:395] Background IO error Not implemented: File is too large for PlainTableReader!
432-2023/06/05-01:33:46.610746 361431 [db/error_handler.cc:283] ErrorHandler: Set regular background error
433:2023/06/05-01:33:46.611247 361431 (Original Log Time 2023/06/05-01:33:46.610680) [db/compaction/compaction_job.cc:867] [0] compacted to: files[1490 10 0 0 0 0 0] max score 348.00, MB/sec: 725.2 rd, 725.2 wr, level 0, files in(0, 98) out(1 +0 blob) MB in(0.0, 6370.7 +0.0 blob) out(6370.6 +0.0 blob), read-write-amplify(0.0) write-amplify(0.0) Not implemented: File is too large for PlainTableReader!, records in: 100300, records dropped: 0 output_compression: LZ4
434-2023/06/05-01:33:46.611250 361431 (Original Log Time 2023/06/05-01:33:46.610716) EVENT_LOG_v1 {"time_micros": 1685928826610694, "job": 4, "event": "compaction_finished", "compaction_time_micros": 9211541, "compaction_time_cpu_micros": 4701659, "output_level": 0, "num_output_files": 1, "total_output_size": 6680082120, "num_input_records": 100300, "num_output_records": 100300, "num_subcompactions": 1, "output_compression": "LZ4", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "lsm_state": [1490, 10, 0, 0, 0, 0, 0]}
435:2023/06/05-01:33:46.611252 361431 [ERROR] [db/db_impl/db_impl_compaction_flush.cc:3073] Waiting after background compaction error: Not implemented: File is too large for PlainTableReader!, Accumulated background error counts: 1
436-2023/06/05-01:33:48.194568 361431 [file/delete_scheduler.cc:73] Deleted file ./readyset-100/readyset_100-public-big_table-0.db/001865.sst immediately, rate_bytes_per_sec 0, total_trash_size 0 max_trash_db_ratio 0.250000
437-2023/06/05-01:33:48.194600 361431 EVENT_LOG_v1 {"time_micros": 1685928828194596, "job": 4, "event": "table_file_deletion", "file_number": 1865}
438-2023/06/05-01:33:48.737250 361450 [db/db_impl/db_impl.cc:489] Shutdown: canceling all background work
439-2023/06/05-01:33:48.750233 361450 [db/db_impl/db_impl.cc:692] Shutdown complete
ubuntu@ip-10-0-0-66:~/readyset-100/readyset_100-public-big_table-0.db$

_{From SyncLinear.com | REA-2863}

[lukoktonos]

The performance results were favorable for switching to block based format.

https://gerrit.readyset.name/c/readyset/+/5206

https://readyset-workspace.slack.com/archives/C05471W2M44/p1687374146825119

[lukoktonos]

It's REA-2714 (mentioned above) — going to perform at least the PlainTable vs BlockBased performance to validate this is OK to switch.

[lukoktonos]

We had a task slated to benchmark other table formats against PlainTable for both write and read latency specifically for this reason - I think @Ethan might have been working on it but I'm not sure where it ended up

[lukoktonos]

Thanks. Not much to go by out there I'm afraid.

[lukoktonos]

commit 3e668db2de9a66e9788371de981377fbb19b17ed
Author: Martin Ek <mail@ekmartin.com>
Date:   Wed May 2 23:13:11 2018 +0200

    Use rocksdb's plain table SST format

Looks like this change was made back in the noria days and there isn't much context as to why it was chosen.

If i had to take a wild guess, the wording in https://github.com/facebook/rocksdb/wiki/PlainTable-Format "PlainTable is a RocksDB's SST file format optimized for low query latency on pure-memory or really low-latency media." sounds appealing for a research project focused on low query latency.

They also had the advantage of running on smaller datasets and avoiding the "file is too large" problem that real world scenarios can run into.

[lukoktonos]

@KwilLuke Can you git-blame to see who might have made the choice to use PlainTable instead of the default?

[lukoktonos]

PlainTable Format is the only rocksdb SST format that has this size restriction, and it is a hard limit due to the data structure using 32-bit integers in indexing.

It seems like we should be able to configure rocksdb to avoid making a file greater than the 2GiB limit in compaction, and from what I can tell we set it to make 256MiB files at most, but there must be something that is at least temporarily making one too large. I'm not exactly sure where yet, and it is a bit slow to reproduce this repeatedly.

As we already have a hunch that BlockBased Table Format may be a better choice (it is the default for rocksdb), I will try using that and confirm that it can handle the failure scenario in this ticket, as well as sanity check the performance a bit, which will cover some of the matrix of REA-2714.

[lukoktonos]

cc: @jasobrown Who I know was interested in RocksDB settings as well.

[lukoktonos]

So, are you looking at implementing REA-2900 first?

No, I was going to work on this one first.

I thought we might already be invoking "PrepareForBulUpload" in our code.

We don't directly call this currently. We do similar options-tweaking that PrepareForBulkUpload does to improve performance, though. I tried calling this and didn't see any significant performance improvement.

[lukoktonos]

So, are you looking at implementing REA-2900 first? I thought we might already be invoking "PrepareForBulUpload" in our code. Seems worthwhile for us to try that out first, I agree.

[lukoktonos]

If we implement REA-2900 before this, it may either resolve this or have a different signature, with compaction failing with the same error after opening PersistentState rather than during.

[lukoktonos]

Fixed in 8a32b30