TemporaryStorage: ZODB.POSException.POSKeyError: 0x83

Anyone seen myriades of POSKeyError related to TempStorage and PAS in Plone 5.2?

2019-09-03 08:52:33,975 ERROR   [ZODB.Connection:809][waitress] Couldn't load state for BTrees.OOBTree.OOBTree 0x83
Traceback (most recent call last):
  File "/home/dgho/onkopedia_buildout/eggs/ZODB-5.5.1-py3.7.egg/ZODB/Connection.py", line 791, in setstate
    p, serial = self._storage.load(oid)
  File "/home/dgho/onkopedia_buildout/eggs/ZODB-5.5.1-py3.7.egg/ZODB/mvccadapter.py", line 143, in load
    r = self._storage.loadBefore(oid, self._start)
  File "/home/dgho/onkopedia_buildout/eggs/tempstorage-5.0-py3.7.egg/tempstorage/TemporaryStorage.py", line 187, in loadBefore
    raise POSException.POSKeyError(oid)
ZODB.POSException.POSKeyError: 0x83

I'm guessing https://github.com/zopefoundation/tempstorage/issues/8 is what you're looking for.
And check https://github.com/zopefoundation/Zope/issues/686 as well
And Sessions and POSKeyErrors and https://github.com/zopefoundation/tempstorage/issues/12

Problems like this are known for TempStorage and modern versions of ZODB/Zope (in particular Zope 4). There is a corresponding issue on github.

hm...not completely sure what the proper solution or workaround would be expect getting rid of tempstorage completely. I see a similar issue with logout:

raceback (innermost last):

Module ZPublisher.WSGIPublisher, line 155, in transaction_pubevents
Module ZPublisher.WSGIPublisher, line 337, in publish_module
Module ZPublisher.WSGIPublisher, line 255, in publish
Module ZPublisher.mapply, line 85, in mapply
Module ZPublisher.WSGIPublisher, line 61, in call_object
Module Products.CMFPlone.browser.login.logout, line 22, in __call__
Module Products.PlonePAS.tools.membership, line 700, in logoutUser
Module Products.Transience.TransientObject, line 113, in invalidate
Module Products.Transience.Transience, line 551, in __contains__
Module Products.Transience.Transience, line 319, in _move_item
Module Products.Transience.Transience, line 988, in _housekeep
Module Products.Transience.Transience, line 784, in _gc
Module Products.Transience.Transience, line 1137, in __call__
Module ZODB.Connection, line 791, in setstate
Module ZODB.mvccadapter, line 143, in load
Module tempstorage.TemporaryStorage, line 187, in loadBefore
ZODB.POSException.POSKeyError: 0x09

1 Like

Did you ever figure this one out? I also get that issue on logout after upgrading from Plone 5.0 to 5.2. If anyone knows of a solid solution, it would be a great help. Thank you!

I think I understand why it happens and have an idea how to fix it (both detailed in the issue I have mentioned earlier). BUT using Zope sessions on top of a "TempStorage" has inherent problems. Therefore, Plone avoids the use of Zope sessions already for a long time -- it has replaced the use of the Zope session by the use of cookies. You, too, should do that unless the data you need to maintain across a session does not fit in cookies. Then, you should store the session data in a "normal" storage, not a "TempStorage". Be then aware, however, that Plone's CSRF (= "Cross Site Request Forgery") protection requires that the session data is stored in its own storage named "temporary" (but this storage can be a "normal" storage).

I had turned WSGI off, and when I turned it back on, the problem alleviated. I looked into https://github.com/zopefoundation/Zope/issues/686 from @zopyx's post above. It looks like WSGI has already been updated to avoid tempstorage. Does this seem right, or did I just have some random luck with that?

The "tempstorage" problems are not WSGI/ZServer related. Being a RAM based storage, it was designed to maintain only very limited history. The ZODB tries to let a transaction use the objects state at it was when the transaction started. When sessions are heavily used, there is not enough history to support this mode of operation. Former ZODB versions allowed a class to declare that its instances do not require this mode; "tempstorage" arranged that this feature was turned on for all its stored objects. Newer ZODB versions have dropped this feature. Almost surely, the former behaviour can be restored by implementing "tempstorage"'s loadBefore via load (ignoring the transaction start time).

@dieter, Once again you have come to save the day. Admittedly, I do not ever really think that deeply about the inner workings of ZODB. You are an invaluable source of information. With that said, how would I determine which packages need to be updated in order to eliminate the use of "tempstorage" for my application? I have searched my product for the term "tempstorage" to only find its use in a stale Zope 2.13 egg, but I have since moved on to Zope 4. The only other place where it shows up in my project is in the zope-versions.cfg file, where it pulls in tempstorage v2.12.2. I seem to have two versions of ZODB on my SYSPATH:
'/usr/local/bin/Plone/buildout-cache/eggs/ZODB-5.5.1-py2.7.egg',
'/usr/local/bin/Plone/buildout-cache/eggs/ZODB3-3.11.0-py2.7.egg',

Is that a problem in and of itself? How do I know which is being used? Thanks again for all your help!

Zope has quite a high level of abstraction. This means that basic infrastructure (such as "tempstorage" (or any ZODB storage)) is almost never used directly. I believe that the only place referencing "tempstorage" directly is the Zope configuration file (--> parts/{instance|client1}/zope.conf) in the definition of the temporary ZODB database (this file is typically generated by buildout, more precisely plone.recipe.zope2instance)). If you want to replace the use of "tempstorage" by a "normal" storage, you could change this definition.

If you want to follow my advice to replace the use of the Zope session by cookies, then look for references to SESSION in the source code. The Zope session is accessed via "request['SESSION']" where "request" designates the Zope request object. Plone itself has already dropped the use of the Zope session a long time ago. Thus, only your own code or add-ons may still use it.

I do not think so. What you likely see here is the effect of a change in the naming scheme for different ZODB generations, similar to Zope generations ("Zope2", "Zope3", "Zope"). Formerly, different generations used different distribution names "ZODB3", "ZODB4", ...; nowadays, the major version number is used for this purpose: i.e. all generations use "ZODB" as distribution name. I expect that your ZODB3==3.11.0 is actually an empty package depending on (and thereby "incorporating") ZODB==5.5.1. This is to ease the transition between the old ZODB reference "ZODB3" to the new one "ZODB".

I added the following to my buildout.cfg:
zodb-temporary-storage = off
See: https://github.com/plone/plone.recipe.zope2instance#direct-storage

Now I get this error in the logs:

2020-02-07 13:39:33,775 ERROR   [Zope.ZODBMountPoint:221][MainThread] Failed to mount database. <class 'ZConfig.ConfigurationError'> (No database configured for mount point at /temp_folder)
Traceback (most recent call last):
  File "/usr/local/bin/Plone/buildout-cache/eggs/Products.TemporaryFolder-5.3-py2.7.egg/Products/ZODBMountPoint/MountedObject.py", line 252, in _getOrOpenObject
    conn = self._getMountedConnection(anyjar)
  File "/usr/local/bin/Plone/buildout-cache/eggs/Products.TemporaryFolder-5.3-py2.7.egg/Products/ZODBMountPoint/MountedObject.py", line 147, in _getMountedConnection
    self._getDB()
  File "/usr/local/bin/Plone/buildout-cache/eggs/Products.TemporaryFolder-5.3-py2.7.egg/Products/ZODBMountPoint/MountedObject.py", line 157, in _getDB
    return getConfiguration().getDatabase(self._path)
  File "/usr/local/bin/Plone/buildout-cache/eggs/Zope-4.1.3-py2.7.egg/Zope2/Startup/datatypes.py", line 262, in getDatabase
    name = self.getName(mount_path)
  File "/usr/local/bin/Plone/buildout-cache/eggs/Zope-4.1.3-py2.7.egg/Zope2/Startup/datatypes.py", line 279, in getName
    self._mountPathError(mount_path)
  File "/usr/local/bin/Plone/buildout-cache/eggs/Zope-4.1.3-py2.7.egg/Zope2/Startup/datatypes.py", line 256, in _mountPathError
    % mount_path)
ConfigurationError: No database configured for mount point at /temp_folder

I expected that would switch to "normal" storage, but perhaps that is not correct. Do you know if there is more to it?

To use "normal" storage requires more parameters: it cannot use the "main" storage; thus, it must use a new storage - and you must provide the necessary information (which type (FileStorage or ClientStorage) and corresponding parameters).

Thus, as you already expect: zodb_temporary-storage = off only prevents the recipe to generate a definition for zodb_db "temporary" and allows you to provide your own (there is a recipe option to add extra configuration to the Zope configuration file).

Had some same type of error.

We have a plone 5.2.1 not yet in production.
We have simple validator in dexterity zc3form.
We did (wrongly ) there a call with this line of code:

context_request_items = self.context.REQUEST.items()

This was enough to trigger:
pediatric.registry.validators.monoIlarValidator, line 38, in ilarFieldRange [*** this is code line mentioned above]
Module ZPublisher.BaseRequest, line 307, in items
Module ZPublisher.HTTPRequest, line 1359, in get
Module Products.Sessions.SessionDataManager, line 131, in getSessionData
Module Products.Sessions.SessionDataManager, line 227, in _getSessionDataObject
Module Products.Transience.Transience, line 895, in new_or_existing
Module Products.Transience.Transience, line 541, in get
Module Products.Transience.Transience, line 354, in _move_item
Module ZODB.Connection, line 791, in setstate
Module ZODB.mvccadapter, line 143, in load
Module tempstorage.TemporaryStorage, line 196, in loadBefore
ZODB.POSException.POSKeyError: 0x13

The solution was replacement of the line of code with this:

context_request_items = self.context.REQUEST.form.items()

The ZODB uses "MVCC" (= "Multi Version Concurrency Control") to isolate its transactions. This essentially means that a transaction sees the state as it had been when the transaction started. To make this possible, a storage must keep enough historical data (to know how things have been at transaction start). tempstorage keeps very limited history (essentially only the current value and that before) -- and fails with the error you observe when it cannot fulfill a request for a state in the past.

Try not to use Zope sessions at all (in many cases, they can be emulated by cookies). If you need Zope sessions, do not use tempstorage -- but a storage keeping much more historical data (e.g. FileStorage).

Note that Plone's CSRF (= Cross Side Request Forgery") protection assumes that Zope sessions live in a mounted storage named "temporary". Thus, if you need CSRF and you want to change the session storage, you must redefine the corresponding mount point.

Thanks. Do you think we should inspect for some unknown use of zope sessions in our code base?
We never had this problem before and we run many similar systems - so my guess was problem was the one-liner we changed. So you recommend we look elsewhere also?

The Zope session is accessed as request["SESSION"]. SESSION is implemented as a so called "lazy request variable". This means, it is instantiated when it is first accessed (and then tempstorage may pose problems). Your request.items implicitly accesses request["SESSION"] -- avoid it.

We still randomly run into this problem with the latest releases of Plone 5.2.x. It's really annoying. Now we have a production machine where a simple logout results in a PosKeyError.
If I replace temp_storage with a normal Folder then we have CSRF warnings everywhere. We don't use request.SESSION anywhere in our code.
Only once I make a read request to it in a try-except block to get request.SESSION.id. I thought the try-except would solve the issue. Or is there maybe an other way to get the session id? I need something to recognize the current session again. What about request.__ac or request.__cp or request.tree-s or request,_ZopeId. There are all looking quite good to me. But I don't know which would be best.

Plone's CSRF protection tries to special case sessions but the corresponding logic does not recognize sessions by themselves. Instead, it relies on sessions to be hosted by a db names temporary. Thus, it is not sufficient to replace temp_storage by a normal folder. You must also put this folder into a database with the expected name. Alternatively, you could disable Plone's CSRF protection.

1 Like

Thanks. Then I have to look into storages. In most of the productive Plone installations we use Postgres as the storage backend. I have to look into buildout again and how I even add a folder into an other storage using the Zope web frontend.