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

Prepack fails #493

Closed
jensens opened this issue Mar 17, 2022 · 2 comments
Closed

Prepack fails #493

jensens opened this issue Mar 17, 2022 · 2 comments
Labels
duplicate

Comments

@jensens
Copy link

jensens commented Mar 17, 2022

I got a failure on prepack like this, any ideas what happens?

plone@ae69f39c46bb:/plone/buildout$ ./bin/zodbpack --prepack relstorage-pack.cfg 
2022-03-17 09:38:22,688 [relstorage._util] DEBUG Using value 0.31 from environ 'RS_PERF_LOG_TRACE_MIN'=0.31 (default=0.31)
2022-03-17 09:38:22,688 [relstorage._util] DEBUG Using value 1.24 from environ 'RS_PERF_LOG_DEBUG_MIN'=1.24 (default=1.24)
2022-03-17 09:38:22,688 [relstorage._util] DEBUG Using value 3.03 from environ 'RS_PERF_LOG_INFO_MIN'=3.03 (default=3.03)
2022-03-17 09:38:22,688 [relstorage._util] DEBUG Using value 9.24 from environ 'RS_PERF_LOG_WARNING_MIN'=9.24 (default=9.24)
2022-03-17 09:38:22,688 [relstorage._util] DEBUG Using value 20.1 from environ 'RS_PERF_LOG_ERROR_MIN'=20.1 (default=20.1)
2022-03-17 09:38:22,688 [relstorage._util] DEBUG Using value WARN from environ 'RS_PERF_LOG_DETAILS_LEVEL'='WARN' (default='WARN')
2022-03-17 09:38:22,688 [relstorage._util] DEBUG Using value on from environ 'RS_PERF_LOG_ENABLE'='on' (default='on')
2022-03-17 09:38:22,688 [relstorage._util] DEBUG Using value 0.1 from environ 'RS_PERF_STATSD_SAMPLE_RATE'=0.1 (default=0.1)
2022-03-17 09:38:22,790 [relstorage._util] DEBUG Using value None from environ 'RS_CACHE_POLL_TIMEOUT'=None (default=None)
2022-03-17 09:38:22,792 [relstorage._util] DEBUG Using value None from environ 'RS_MAX_POOLED_STORE_CONNECTIONS'=None (default=None)
2022-03-17 09:38:22,808 [zodbpack] INFO Opening storage (RelStorageFactory)...
2022-03-17 09:38:22,820 [relstorage._util] DEBUG Using value 4096 from environ 'RS_PACK_CURSOR_ARRAYSIZE'=4096 (default=4096)
2022-03-17 09:38:22,820 [relstorage._util] DEBUG Using value 4096 from environ 'RS_PACK_STORE_BATCH_SIZE'=4096 (default=4096)
2022-03-17 09:38:22,820 [relstorage._util] DEBUG Using value 120 from environ 'RS_PACK_COMMIT_FREQUENCY'=120 (default=120)
2022-03-17 09:38:22,820 [relstorage._util] DEBUG Using value 1024 from environ 'RS_PACK_DOWNLOAD_BATCH_SIZE'=1024 (default=1024)
2022-03-17 09:38:22,820 [relstorage._util] DEBUG Using value 1000 from environ 'RS_PACK_HP_DELETE_BATCH_SIZE'=1000 (default=1000)
2022-03-17 09:38:22,861 [relstorage.adapters.drivers] DEBUG Using driver <relstorage.adapters.postgresql.drivers.psycopg2.Psycopg2Driver object at 0x7fd8b27ad100> for requested name 'auto'
2022-03-17 09:38:22,862 [relstorage.adapters.schema] DEBUG Reading stored procedures from /home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/postgresql/procs and /home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/postgresql/procs/hf
2022-03-17 09:38:22,894 [relstorage.adapters.postgresql.drivers] DEBUG Message from the RDBMS: NOTICE:  relation "zoid_seq" already exists, skipping
2022-03-17 09:38:22,908 [zodbpack] INFO Packing storage (RelStorageFactory).
2022-03-17 09:38:22,915 [relstorage.storage.pack] INFO pack: beginning pre-pack
2022-03-17 09:38:22,928 [relstorage.storage.pack] INFO Analyzing transactions committed Wed Mar 16 09:37:01 2022 or before (TID 281167272481376409)
2022-03-17 09:38:22,928 [relstorage.adapters.packundo] INFO pre_pack: filling the pack_object table
2022-03-17 09:38:31,386 [relstorage.adapters.packundo] INFO pre_pack: Filled the pack_object table
2022-03-17 09:38:31,391 [relstorage.adapters.packundo] DEBUG pre_pack: Collecting objects to examine.
2022-03-17 09:38:37,419 [relstorage.adapters.packundo] DEBUG pre_pack: Downloaded objects to examine (memory delta: 0 KB; download time: 5.80; sort time 0.03)
2022-03-17 09:38:37,425 [relstorage.adapters.packundo] INFO pre_pack: analyzing references from 310043 object(s) (memory delta: 0 KB)
2022-03-17 09:38:41,621 [relstorage.adapters.packundo] ERROR pre_pack: failed
Traceback (most recent call last):
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/packundo.py", line 1445, in pre_pack
    self._pre_pack_main(load_connection, store_connection,
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/packundo.py", line 1524, in _pre_pack_main
    self.fill_object_refs(load_connection, store_connection, get_references)
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/packundo.py", line 1325, in fill_object_refs
    refs_found = self._add_refs_for_oids(load_batcher, store_batcher,
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/packundo.py", line 1382, in _add_refs_for_oids
    store_batcher.insert_into(
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/batch.py", line 149, in insert_into
    self._flush_if_needed()
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/batch.py", line 100, in _flush_if_needed
    return self.flush()
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/batch.py", line 273, in flush
    count += self._do_inserts()
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/batch.py", line 364, in _do_inserts
    self.cursor.execute(stmt, params)
psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "object_refs_added_pkey"
DETAIL:  Key (zoid)=(7363180) already exists.

Traceback (most recent call last):
  File "./bin/zodbpack", line 272, in <module>
    sys.exit(relstorage.zodbpack.main())
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/zodbpack.py", line 99, in main
    storage.pack(t if not options.check_refs else None,
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/storage/__init__.py", line 915, in pack
    result = pack.pack(t, referencesf, prepack_only, skip_prepack)
  File "src/perfmetrics/metric.py", line 72, in perfmetrics._metric._AbstractMetricImpl.__call__
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/storage/pack.py", line 208, in pack
    tid_int = self.__pre_pack(t, referencesf)
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/storage/pack.py", line 135, in __pre_pack
    self.packundo.pre_pack(tid_int, get_references)
  File "src/perfmetrics/metric.py", line 72, in perfmetrics._metric._AbstractMetricImpl.__call__
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/packundo.py", line 1445, in pre_pack
    self._pre_pack_main(load_connection, store_connection,
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/packundo.py", line 1524, in _pre_pack_main
    self.fill_object_refs(load_connection, store_connection, get_references)
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/packundo.py", line 1325, in fill_object_refs
    refs_found = self._add_refs_for_oids(load_batcher, store_batcher,
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/packundo.py", line 1382, in _add_refs_for_oids
    store_batcher.insert_into(
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/batch.py", line 149, in insert_into
    self._flush_if_needed()
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/batch.py", line 100, in _flush_if_needed
    return self.flush()
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/batch.py", line 273, in flush
    count += self._do_inserts()
  File "/home/plone/.buildout/shared-eggs/RelStorage-3.4.5-py3.8-linux-x86_64.egg/relstorage/adapters/batch.py", line 364, in _do_inserts
    self.cursor.execute(stmt, params)
psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "object_refs_added_pkey"
DETAIL:  Key (zoid)=(7363180) already exists.
@mbarde
Copy link

mbarde commented Mar 24, 2023

Had the same issue and solved it via TRUNCATE object_refs_added;, which should be safe to do according to https://relstorage.readthedocs.io/en/latest/migration/migrate-to-1.4.html

@jamadden
Copy link
Member

Closing as duplicate of #448 and #482 . We need a reproducer for this.

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

No branches or pull requests
3 participants
@jensens @jamadden @mbarde