Application crashes with RocksIOError #184
Comments
|
If you really have only one process using the Usually the process will clean this up when exiting, and I haven't had any problems even after performing a |
|
@ask I tried that, just before starting up the worker, but still no joy. Do you have any other recommendations? |
|
Some additional information: |
|
If it helps, I start the worker with: |
|
Thanks! I managed to reproduce, and strangely the datadir is populated with a single If I rename them to something else: # was opm.pmdb.service.plants
plants_table = app.Table('plants',
default=dict,
key_type=str,
value_type=dict)
# was opm.pmdb.service.objects
objects_table = app.Table('objects',
default=dict,
key_type=str,
value_type=dict)it works - no lock errors and the expected number of table directories: At first I thought it had something to do with |
Checklist
masterbranch of Faust.Steps to reproduce
topic1 = app.topic('source_topic_1'...)andtopic2 = app.topic('source_topic_2'...)table1 = app.Table('table1'...)andtable2 = app.Table('table2'...)@app.agent(topic1),@app.agent(topic2)in Faust, populating tables in the process.rocksdb://storeThe app is configured as follows:
app = faust.App( 'opm', autodiscover=True, broker='kafka://127.0.0.1', origin='opm', store='rocksdb://', topic_partitions=1, version=21, key_serializer='json', value_serializer='json' )I have two agents, processing two Kafka source topics:
import faust from opm.app import app from opm.pmdb_service.models import PMObjectsRecord, PMPlantsRecord plants_topic = app.topic('opm.pmdb.PMPlants', value_type=PMPlantsRecord) objects_topic = app.topic('opm.pmdb.PMObjects', value_type=PMObjectsRecord) plants_table = app.Table('opm.pmdb_service.plants', default=dict, key_type=str, value_type=dict) objects_table = app.Table('opm.pmdb_service.objects', default=dict, key_type=str, value_type=dict) @app.agent(plants_topic) async def process_plants(plants: faust.Stream[PMPlantsRecord]): async for plant in plants: plants_table[plant.payload.ID] = plant.payload @app.agent(objects_topic) async def process_objects(objects: faust.Stream[PMObjectsRecord]): async for object in objects: objects_table[object.payload.ID] = object.payloadAs far as I can see, i only have one process running, so there shouldn't be multiple processes contending for the lock:
and
I've also tried the following to resolve the problem:
Expected behavior
Application does not crash.
Actual behavior
Application crashes due to error:
reason=RocksIOError(b'IO error: lock : opm-data/v21/tables/opm.pmdb_service.db/LOCK: No locks availableFull traceback
[2018-10-16 09:17:22,161: INFO]: [^Worker]: Starting... [2018-10-16 09:17:22,164: INFO]: [^-App]: Starting... [2018-10-16 09:17:22,164: INFO]: [^--MonitorService]: Starting... [2018-10-16 09:17:22,164: INFO]: [^CacheBackend]: Starting... [2018-10-16 09:17:22,164: INFO]: [^--WebService]: Starting... [2018-10-16 09:17:22,167: INFO]: [^---ServerThread]: Starting... [2018-10-16 09:17:22,167: INFO]: [^--Web]: Serving on http://localhost:6066/ [2018-10-16 09:17:22,168: INFO]: [^--Producer]: Starting... [2018-10-16 09:17:22,200: INFO]: [^--Consumer]: Starting... [2018-10-16 09:17:22,211: INFO]: [^--LeaderAssignor]: Starting... [2018-10-16 09:17:22,211: INFO]: [^--Producer]: Creating topic opm-v21-__assignor-__leader [2018-10-16 09:17:22,211: INFO]: [^--ReplyConsumer]: Starting... [2018-10-16 09:17:22,211: INFO]: [^AgentManagerService]: Starting... [2018-10-16 09:17:22,212: INFO]: [^--Agent: opm.pmdb_servic[.]process_plants]: Starting... [2018-10-16 09:17:22,214: INFO]: [^---OneForOneSupervisor]: Starting... [2018-10-16 09:17:22,215: INFO]: [^--Agent: opm.pmdb_servi[.]process_objects]: Starting... [2018-10-16 09:17:22,215: INFO]: [^---OneForOneSupervisor]: Starting... [2018-10-16 09:17:22,215: INFO]: [^--Conductor]: Starting... [2018-10-16 09:17:22,215: INFO]: [^--TableManager]: Starting... [2018-10-16 09:17:24,217: INFO]: [^--Producer]: Creating topic opm-v21-__assignor-__leader [2018-10-16 09:17:24,218: INFO]: [^--Producer]: Creating topic opm-v21-opm.pmdb_service.objects-changelog [2018-10-16 09:17:24,218: INFO]: [^--Producer]: Creating topic opm-v21-opm.pmdb_service.plants-changelog [2018-10-16 09:17:24,219: INFO]: Updating subscribed topics to: frozenset({'opm.pmdb.PMPlants', 'opm-v21-opm.pmdb_service.plants-changelog', 'opm-v21-__assignor-__leader', 'opm-v21-opm.pmdb_service.objects-changelog', 'opm.pmdb.PMObjects'}) [2018-10-16 09:17:24,222: INFO]: Subscribed to topic(s): {'opm.pmdb.PMPlants', 'opm-v21-opm.pmdb_service.plants-changelog', 'opm-v21-__assignor-__leader', 'opm-v21-opm.pmdb_service.objects-changelog', 'opm.pmdb.PMObjects'} [2018-10-16 09:17:24,234: INFO]: Discovered coordinator 1001 for group opm-v21 [2018-10-16 09:17:24,235: INFO]: Revoking previously assigned partitions set() for group opm-v21 [2018-10-16 09:17:24,235: INFO]: [^--Fetcher]: Stopping... [2018-10-16 09:17:24,235: INFO]: [^--Fetcher]: -Stopped! [2018-10-16 09:17:24,273: INFO]: (Re-)joining group opm-v21 [2018-10-16 09:17:24,275: INFO]: Joined group 'opm-v21' (generation 3) with member_id faust-1.2.1-31699158-ed24-4829-b2e1-14a1c56f75f4 [2018-10-16 09:17:24,275: INFO]: Elected group leader -- performing partition assignments using faust [2018-10-16 09:17:24,279: INFO]: Successfully synced group opm-v21 with generation 3 [2018-10-16 09:17:24,279: INFO]: Setting newly assigned partitions ┌Topic Partition Set─────────────────────────┬────────────┐ │ topic │ partitions │ ├────────────────────────────────────────────┼────────────┤ │ opm-v21-__assignor-__leader │ {0} │ │ opm-v21-opm.pmdb_service.plants-changelog │ {0} │ │ opm-v21-opm.pmdb_service.objects-changelog │ {0} │ │ opm.pmdb.PMPlants │ {0} │ │ opm.pmdb.PMObjects │ {0} │ └────────────────────────────────────────────┴────────────┘ for group opm-v21 [2018-10-16 09:17:24,280: INFO]: [^--Fetcher]: Stopping... [2018-10-16 09:17:24,280: INFO]: [^--Fetcher]: -Stopped! [2018-10-16 09:17:24,280: INFO]: [^--TableManager]: Triggered recovery in background [2018-10-16 09:17:24,280: INFO]: [^--TableManager]: New assignments found [2018-10-16 09:17:24,293: INFO]: [^---Store: opm.pmdb_service.objects]: DB for partition 0 is locked! Retry in 1s... [2018-10-16 09:17:25,296: INFO]: [^---Store: opm.pmdb_service.objects]: DB for partition 0 is locked! Retry in 1s... [2018-10-16 09:17:26,299: INFO]: [^---Store: opm.pmdb_service.objects]: DB for partition 0 is locked! Retry in 1s... [2018-10-16 09:17:27,302: INFO]: [^---Store: opm.pmdb_service.objects]: DB for partition 0 is locked! Retry in 1s... [2018-10-16 09:17:28,305: ERROR]: [^--TableManager]: Crashed reason=RocksIOError(b'IO error: lock : opm-data/v21/tables/opm.pmdb_service.db/LOCK: No locks available',) Traceback (most recent call last): File "/home/hartmut/.local/share/virtualenvs/opm-JvQpWqh_/lib/python3.6/site-packages/faust/stores/rocksdb.py", line 210, in _db_for_partition return self._dbs[partition] KeyError: 0 During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/home/hartmut/.local/share/virtualenvs/opm-JvQpWqh_/lib/python3.6/site-packages/mode/services.py", line 700, in _execute_task await task File "/home/hartmut/.local/share/virtualenvs/opm-JvQpWqh_/lib/python3.6/site-packages/faust/tables/manager.py", line 196, in _recover await table.on_partitions_assigned(assigned) File "/home/hartmut/.local/share/virtualenvs/opm-JvQpWqh_/lib/python3.6/site-packages/faust/tables/base.py", line 409, in on_partitions_assigned await self.data.on_partitions_assigned(self, assigned) File "/home/hartmut/.local/share/virtualenvs/opm-JvQpWqh_/lib/python3.6/site-packages/faust/stores/rocksdb.py", line 273, in on_partitions_assigned self._db_for_partition(tp.partition) File "/home/hartmut/.local/share/virtualenvs/opm-JvQpWqh_/lib/python3.6/site-packages/faust/stores/rocksdb.py", line 212, in _db_for_partition db = self._dbs[partition] = self._open_for_partition(partition) File "/home/hartmut/.local/share/virtualenvs/opm-JvQpWqh_/lib/python3.6/site-packages/faust/stores/rocksdb.py", line 216, in _open_for_partition return self.options.open(self.partition_path(partition)) File "/home/hartmut/.local/share/virtualenvs/opm-JvQpWqh_/lib/python3.6/site-packages/faust/stores/rocksdb.py", line 104, in open return rocksdb.DB(str(path), self.as_options(), read_only=read_only) File "rocksdb/_rocksdb.pyx", line 1437, in rocksdb._rocksdb.DB.__cinit__ File "rocksdb/_rocksdb.pyx", line 84, in rocksdb._rocksdb.check_status rocksdb.errors.RocksIOError: b'IO error: lock : opm-data/v21/tables/opm.pmdb_service.db/LOCK: No locks available' [2018-10-16 09:17:28,310: INFO]: [^--Web]: Closing server [2018-10-16 09:17:28,310: INFO]: [^--Web]: Waiting for server to close handle [2018-10-16 09:17:28,310: INFO]: [^--Web]: Shutting down web application [2018-10-16 09:17:28,310: INFO]: [^--Web]: Waiting for handler to shut down [2018-10-16 09:17:28,310: INFO]: [^--Web]: Cleanup [2018-10-16 09:17:28,310: INFO]: [^Worker]: Stopping... [2018-10-16 09:17:28,310: INFO]: [^-App]: Stopping... [2018-10-16 09:17:28,310: INFO]: [^--TableManager]: Stopping... [2018-10-16 09:17:28,310: INFO]: [^--Fetcher]: Stopping... [2018-10-16 09:17:28,310: INFO]: [^--Fetcher]: -Stopped! [2018-10-16 09:17:28,310: INFO]: [^--TableManager]: Aborting ongoing recovery to start over [2018-10-16 09:17:28,310: INFO]: [^--Table: opm.pmdb_service.plants]: Stopping... [2018-10-16 09:17:28,310: INFO]: [^---Store: opm.pmdb_service.plants]: Stopping... [2018-10-16 09:17:28,311: INFO]: [^---Store: opm.pmdb_service.plants]: -Stopped! [2018-10-16 09:17:28,311: INFO]: [^--Table: opm.pmdb_service.plants]: -Stopped! [2018-10-16 09:17:28,311: INFO]: [^--Table: opm.pmdb_service.objects]: Stopping... [2018-10-16 09:17:28,311: INFO]: [^---Store: opm.pmdb_service.objects]: Stopping... [2018-10-16 09:17:28,311: INFO]: [^---Store: opm.pmdb_service.objects]: -Stopped! [2018-10-16 09:17:28,311: INFO]: [^--Table: opm.pmdb_service.objects]: -Stopped! [2018-10-16 09:17:28,311: INFO]: [^--TableManager]: -Stopped! [2018-10-16 09:17:28,311: INFO]: [^--Conductor]: Stopping... [2018-10-16 09:17:28,311: INFO]: [^--Conductor]: Terminating cancelled task: <coroutine object Conductor._subscriber at 0x7efdfe237570> [2018-10-16 09:17:28,312: INFO]: [^--Conductor]: -Stopped! [2018-10-16 09:17:28,312: INFO]: [^AgentManagerService]: Stopping... [2018-10-16 09:17:28,312: INFO]: [^--Agent: opm.pmdb_servic[.]process_plants]: Stopping... [2018-10-16 09:17:28,312: INFO]: [^---OneForOneSupervisor]: Stopping... [2018-10-16 09:17:28,312: INFO]: [^---OneForOneSupervisor]: Terminating cancelled task: <coroutine object SupervisorStrategy._supervisor at 0x7efdfe237d00> [2018-10-16 09:17:28,312: INFO]: [^---OneForOneSupervisor]: -Stopped! [2018-10-16 09:17:28,313: INFO]: [^--Agent: opm.pmdb_servic[.]process_plants]: -Stopped! [2018-10-16 09:17:28,313: INFO]: [^--Agent: opm.pmdb_servi[.]process_objects]: Stopping... [2018-10-16 09:17:28,313: INFO]: [^---OneForOneSupervisor]: Stopping... [2018-10-16 09:17:28,313: INFO]: [^---OneForOneSupervisor]: Terminating cancelled task: <coroutine object SupervisorStrategy._supervisor at 0x7efdfe237e60> [2018-10-16 09:17:28,313: INFO]: [^---OneForOneSupervisor]: -Stopped! [2018-10-16 09:17:28,313: INFO]: [^--Agent: opm.pmdb_servi[.]process_objects]: -Stopped! [2018-10-16 09:17:28,313: INFO]: [^AgentManagerService]: -Stopped! [2018-10-16 09:17:28,313: INFO]: [^--ReplyConsumer]: Stopping... [2018-10-16 09:17:28,313: INFO]: [^--ReplyConsumer]: -Stopped! [2018-10-16 09:17:28,313: INFO]: [^--LeaderAssignor]: Stopping... [2018-10-16 09:17:28,313: INFO]: [^--LeaderAssignor]: -Stopped! [2018-10-16 09:17:28,313: INFO]: [^--Consumer]: Stopping... [2018-10-16 09:17:28,315: INFO]: LeaveGroup request succeeded [2018-10-16 09:17:28,316: INFO]: [^--Consumer]: -Stopped! [2018-10-16 09:17:28,316: INFO]: [^--Producer]: Stopping... [2018-10-16 09:17:28,316: INFO]: [^--Producer]: -Stopped! [2018-10-16 09:17:28,316: INFO]: [^--WebService]: Stopping... [2018-10-16 09:17:28,316: INFO]: [^---ServerThread]: Stopping... [2018-10-16 09:17:28,316: INFO]: [^---ServerThread]: -Stopped! [2018-10-16 09:17:28,316: INFO]: [^--WebService]: -Stopped! [2018-10-16 09:17:28,316: INFO]: [^CacheBackend]: Stopping... [2018-10-16 09:17:28,317: INFO]: [^CacheBackend]: -Stopped! [2018-10-16 09:17:28,317: INFO]: [^--MonitorService]: Stopping... [2018-10-16 09:17:28,317: INFO]: [^--MonitorService]: -Stopped! [2018-10-16 09:17:28,317: INFO]: [^-App]: -Stopped! [2018-10-16 09:17:28,317: INFO]: [^Worker]: -Stopped! [2018-10-16 09:17:28,317: INFO]: [^Worker]: Gathering service tasks... [2018-10-16 09:17:28,317: INFO]: [^Worker]: Gathering all futures... ^C-INT- -INT- -INT- -INT- -INT- -INT- [2018-10-16 09:17:28,864: INFO]: [^Worker]: Stopping on signal received... [2018-10-16 09:17:29,419: INFO]: [^Worker]: Closing event loop [2018-10-16 09:17:29,420: CRITICAL]: [^Worker]: We experienced a crash! Reraising original exception...Versions
v3.6.6v1.2.1Ubuntu 18.042.0.0-cp15.8The text was updated successfully, but these errors were encountered: