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.

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

Finding objects that causes POSKeyError? #274

Closed
krissik opened this issue Jul 11, 2019 · 8 comments

Comments

@krissik
Copy link

commented Jul 11, 2019

I have a Plone site that use RelStorage. After packing the database I got a lot of POSKeyErrors. My site was not working and I had to restore from backup.
Now I try to find out what happend to my database and I am wondering why zodbpack did not report any error. Even if it run again after I see a lot of POSKeyErrors it did not report any error.

zc.zodbdgc says that

this documentation does not apply to RelStorage which has the same features built-in

How do I use this built-in feature?

While in debug mode of my instance the error looks like that:

>>> app.site
<PloneSite at /site>
>>> app.site.portal_catalog
2019-07-08 09:16:34 WARNING relstorage POSKeyError on oid 155: no tid found; history-free adapter
2019-07-08 09:16:34 ERROR ZODB.Connection Couldn't load state for Products.CMFPlone.CatalogTool.CatalogTool 0x9b
Traceback (most recent call last):
  File "/opt/plone/buildout-cache/eggs/ZODB-5.3.0-py2.7.egg/ZODB/Connection.py", line 796, in setstate
    p, serial = self._storage.load(oid)
  File "/opt/plone/buildout-cache/eggs/perfmetrics-2.0-py2.7.egg/perfmetrics/__init__.py", line 127, in call_with_metric
    return f(*args, **kw)
  File "/opt/plone/buildout-cache/eggs/RelStorage-2.1.1-py2.7-linux-x86_64.egg/relstorage/storage.py", line 587, in load
    raise POSKeyError(oid)
POSKeyError: 0x9b
2019-07-08 09:16:34 WARNING relstorage POSKeyError on oid 155: no tid found; history-free adapter
2019-07-08 09:16:34 ERROR ZODB.Connection Couldn't load state for Products.CMFPlone.CatalogTool.CatalogTool 0x9b
Traceback (most recent call last):
  File "/opt/plone/buildout-cache/eggs/ZODB-5.3.0-py2.7.egg/ZODB/Connection.py", line 796, in setstate
    p, serial = self._storage.load(oid)
  File "/opt/plone/buildout-cache/eggs/perfmetrics-2.0-py2.7.egg/perfmetrics/__init__.py", line 127, in call_with_metric
    return f(*args, **kw)
  File "/opt/plone/buildout-cache/eggs/RelStorage-2.1.1-py2.7-linux-x86_64.egg/relstorage/storage.py", line 587, in load
    raise POSKeyError(oid)
POSKeyError: 0x9b
<Products.CMFPlone.CatalogTool.CatalogTool object at 0x7fad23683d70>
>>> app.site.portal_workflow
2019-07-08 09:18:19 WARNING relstorage POSKeyError on oid 179: no tid found; history-free adapter
2019-07-08 09:18:19 ERROR ZODB.Connection Couldn't load state for Products.CMFPlone.WorkflowTool.WorkflowTool 0xb3
Traceback (most recent call last):
  File "/opt/plone/buildout-cache/eggs/ZODB-5.3.0-py2.7.egg/ZODB/Connection.py", line 796, in setstate
    p, serial = self._storage.load(oid)
  File "/opt/plone/buildout-cache/eggs/perfmetrics-2.0-py2.7.egg/perfmetrics/__init__.py", line 133, in call_with_metric
    return f(*args, **kw)
  File "/opt/plone/buildout-cache/eggs/RelStorage-2.1.1-py2.7-linux-x86_64.egg/relstorage/storage.py", line 587, in load
    raise POSKeyError(oid)
POSKeyError: 0xb3
2019-07-08 09:18:19 WARNING relstorage POSKeyError on oid 179: no tid found; history-free adapter
2019-07-08 09:18:19 ERROR ZODB.Connection Couldn't load state for Products.CMFPlone.WorkflowTool.WorkflowTool 0xb3
Traceback (most recent call last):
  File "/opt/plone/buildout-cache/eggs/ZODB-5.3.0-py2.7.egg/ZODB/Connection.py", line 796, in setstate
    p, serial = self._storage.load(oid)
  File "/opt/plone/buildout-cache/eggs/perfmetrics-2.0-py2.7.egg/perfmetrics/__init__.py", line 127, in call_with_metric
    return f(*args, **kw)
  File "/opt/plone/buildout-cache/eggs/RelStorage-2.1.1-py2.7-linux-x86_64.egg/relstorage/storage.py", line 587, in load
    raise POSKeyError(oid)
POSKeyError: 0xb3
<Products.CMFPlone.WorkflowTool.WorkflowTool object at 0x7fad2369b500>

This stack trace is from my test system (where I restored the corrupted database). On production (where the error occurred) I have RelStorage 2.0.0 and Plone 5.1.2.

@jamadden

This comment has been minimized.

Copy link
Member

commented Jul 11, 2019

Now I try to find out what happend to my database and I am wondering why zodbpack did not report any error.

Packing is not a consistency check.

zc.zodbdgc says that

this documentation does not apply to RelStorage which has the same features built-in

How do I use this built-in feature?

That's described in the next sentence of the paragraph you quote:

Look at the options for the zodbpack script. The --prepack option creates a table containing the same information as we are creating in the reference database.

i.e., run zodbpack --prepack and look at the resulting table of references.

You can use the multi-zodb-check-refs provided by zc.zodbdgc even in a non-multi-database RelStorage setup, it's just likely to be slower than building the --prepack table.

@krissik

This comment has been minimized.

Copy link
Author

commented Jul 11, 2019

Uh ... I totally get this wrong :-( I thought prepack is run before every pack and reports errors.
I will run this now.
What type of content do I have to expect in this table? Every object that will be deleted during pack? Or missing objects? Is there some documentation about it?

Thx for your help.

@jamadden

This comment has been minimized.

Copy link
Member

commented Jul 11, 2019

I thought prepack is run before every pack and reports errors.

It is run before packing, but it has nothing to do with error reporting. Pre-pack does an initial scan and determines what object (revisions) must be kept and which are candidates for deletion, as well as scanning for references between objects. With the --prepack option, you can choose to stop after that step instead of continuing on to delete unreferenced objects. It is only useful in a database with pack-gc on (the default).

What type of content do I have to expect in this table? Every object that will be deleted during pack? Or missing objects? Is there some documentation about it?

There's not really any documentation. This is a low-level implementation detail subject to change between versions, only used for low-level debugging such as this. The main table you're probably going to be interested in is object_refs, which shows what objects refer to what other objects; a query like SELECT zoid FROM object_ref WHERE to_zoid = 179 will give you the OIDs of objects that refer to the missing OID 179.

@krissik

This comment has been minimized.

Copy link
Author

commented Jul 12, 2019

To make sure I get it right, I have some questions:

  • The column state in object_state table is the serialized/pickled python object? So the reason for POSKeyError is that zodb things there must be an object with an id and I have no row in object_state with this id, correct?
restoredzodb=# select * from object_state where zoid=179;
 zoid | tid | state_size | state
------+-----+------------+-------
(0 rows)

  • Every relation of objects is in object_ref table? Where is the name of the object property that holds that relation?
  • Can I delete the relation between objects by deleting a row in object_ref? Or is it built during zodbpack for informational reasons?
  • What is the difference between keep and visited column in pack_object table?

So my situation is:

restoredzodb=# Select zoid From object_ref Where to_zoid=179;
 zoid
------
  147
(1 row)
>>> app._p_jar.get(p64(147))
<PloneSite at site>

The object with id 179 is referenced by my PloneSite. It is portal_workflow tool. There are other tools (e.g. portal_catalog) missing too. I have no explanation why they disappeared. I could create fake objects as described here but I think these tools are too important and nothing will work without them.

@jamadden

This comment has been minimized.

Copy link
Member

commented Jul 12, 2019

So the reason for POSKeyError is that zodb things there must be an object with an id and I have no row in object_state with this id, correct?

Correct. An existing object references another object, but that object doesn't exist in object_state.

Where is the name of the object property that holds that relation?

That's not available. All RelStorage knows is that an object references another object. It doesn't know how; that's specific to the details of the object's implementation.

Can I delete the relation between objects by deleting a row in object_ref? Or is it built during zodbpack for informational reasons?

It's just for packing purposes. The information used by Python is in the object itself, recorded with its serialized state.

What is the difference between keep and visited column in pack_object table?

Packing internal information used during traversing the object reference graph.

@jamadden jamadden added the question label Jul 12, 2019

@krissik

This comment has been minimized.

Copy link
Author

commented Jul 15, 2019

Thanks a lot for your answers!

What is the difference between keep and visited column in pack_object table?

Packing internal information used during traversing the object reference graph.

So visited says it was visited during traversal and keep is the decision whether to delete the object or not? Does this depend on --days parameter of zodbpack? So that I have rows for objects in pack_object that are not visited but kept because there time is not up?

@jamadden

This comment has been minimized.

Copy link
Member

commented Jul 15, 2019

So visited says it was visited during traversal and keep is the decision whether to delete the object or not?

Both statements are correct.

Does this depend on --days parameter of zodbpack?

Yes. In a history-free database, any object created or modified more recently than the pack time automatically gets keep = True and won't be removed.

So that I have rows for objects in pack_object that are not visited but kept because there time is not up?

Not exactly. visited and keep are pretty much unrelated; it's very possible to have keep = True while visited = False (for example, when the object is too new). (In fact, it looks like visited isn't really being used at the moment, it's just informative for a human observer to tell why keep became True: if visited is false, it's because it was a root object, if visited is true, it's because it was reachable from some root).

In a history-free database, every extant object in object_state will get a row in pack_object; those that are newer than the pack time will get keep = True immediately, and every other row will get keep = True if it's reachable from one of the objects that originally had keep = True.

@krissik

This comment has been minimized.

Copy link
Author

commented Jul 17, 2019

Thanks a lot :-)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
2 participants
You can’t perform that action at this time.