David Hess | 14 Aug 2011 18:44
Favicon

Re: Interesting BTree failure


After some more investigation - this occurred right after live packing the database and changes to this
BTree were made and committed during the pack.

Afterwards, the oids seem to be jumbled up in this BTree (at least - maybe elsewhere in the database too).
Unpickled Persistent objects are not what they should be - interior BNodes are sometimes application
classes and stored values are sometimes BNodes rather than application classes.

Dave

On Aug 14, 2011, at 10:45 AM, David Hess wrote:

> 
> We have a long running process that does a lot of work with BTrees and in the middle of doing an "in"
operation, we got this traceback:
> 
> File "/usr/local/lib/python2.6/dist-packages/durus/btree.py", line 343, in __contains__
>  return self.root.search(key) is not None
> File "/usr/local/lib/python2.6/dist-packages/durus/btree.py", line 93, in search
>  return self.nodes[position].search(key)
> File "/usr/local/lib/python2.6/dist-packages/durus/btree.py", line 93, in search
>  return self.nodes[position].search(key)
> File "/usr/local/lib/python2.6/dist-packages/durus/persistent.py", line 173, in _p_load_state
>  self._p_connection.load_state(self)
> File "/usr/local/lib/python2.6/dist-packages/durus/connection.py", line 182, in load_state
>  pickle = self.get_stored_pickle(oid)
> File "/usr/local/lib/python2.6/dist-packages/durus/connection.py", line 111, in get_stored_pickle
>  record = self.storage.load(oid)
> File "/usr/local/lib/python2.6/dist-packages/durus/file_storage.py", line 96, in load
>  raise KeyError(oid)
(Continue reading)

David Hess | 15 Aug 2011 05:37
Favicon

Re: Interesting BTree failure


I think there might be a bug in load_state in connection.py -  shouldn't it also catch KeyError to handle the case when working from a local FileStorage instead of a ClientStorage (as the traceback below shows)?

Regardless, that's a case that shouldn't have happened in our app. In looking at the Shelf packer in Durus 3.8, it seems a bit more sophisticated than the one in 3.7. I'm guessing that an upgrade to 3.8 is likely to prevent this corruption?

Thanks.

Dave

On Aug 14, 2011, at 11:44 AM, David Hess wrote:


After some more investigation - this occurred right after live packing the database and changes to this BTree were made and committed during the pack.

Afterwards, the oids seem to be jumbled up in this BTree (at least - maybe elsewhere in the database too). Unpickled Persistent objects are not what they should be - interior BNodes are sometimes application classes and stored values are sometimes BNodes rather than application classes.

Dave

On Aug 14, 2011, at 10:45 AM, David Hess wrote:


We have a long running process that does a lot of work with BTrees and in the middle of doing an "in" operation, we got this traceback:

File "/usr/local/lib/python2.6/dist-packages/durus/btree.py", line 343, in __contains__
return self.root.search(key) is not None
File "/usr/local/lib/python2.6/dist-packages/durus/btree.py", line 93, in search
return self.nodes[position].search(key)
File "/usr/local/lib/python2.6/dist-packages/durus/btree.py", line 93, in search
return self.nodes[position].search(key)
File "/usr/local/lib/python2.6/dist-packages/durus/persistent.py", line 173, in _p_load_state
self._p_connection.load_state(self)
File "/usr/local/lib/python2.6/dist-packages/durus/connection.py", line 182, in load_state
pickle = self.get_stored_pickle(oid)
File "/usr/local/lib/python2.6/dist-packages/durus/connection.py", line 111, in get_stored_pickle
record = self.storage.load(oid)
File "/usr/local/lib/python2.6/dist-packages/durus/file_storage.py", line 96, in load
raise KeyError(oid)
KeyError: '\x00\x00\x00\x00\x00\x00T\xb4'

This is using shelf storage on Durus 3.7 and is a long running process. My best guess is a ghosted BNode that thought it was persisted to disk but really wasn't? I think I've seen this once before a couple of years ago (i.e. it seems to be really rare).

Is this new and/or known and fixed in Durus 3.8?

Dave


_______________________________________________
Durus-users mailing list
Durus-users <at> mems-exchange.org
http://mail.mems-exchange.org/mailman/listinfo/durus-users


------
David K. Hess
877.343.4947 x114

_______________________________________________
Durus-users mailing list
Durus-users <at> mems-exchange.org
http://mail.mems-exchange.org/mailman/listinfo/durus-users
David Binger | 15 Aug 2011 15:18

Re: Interesting BTree failure

I think I'd prefer to fix this by having FileStorage.load() raise a DurusKeyError instead of KeyError.
Does that seem reasonable to you?

On Aug 14, 2011, at 11:37 PM, David Hess wrote:

I think there might be a bug in load_state in connection.py -  shouldn't it also catch KeyError to handle the case when working from a local FileStorage instead of a ClientStorage (as the traceback below shows)?

_______________________________________________
Durus-users mailing list
Durus-users <at> mems-exchange.org
http://mail.mems-exchange.org/mailman/listinfo/durus-users
David Hess | 15 Aug 2011 15:30
Favicon

Re: Interesting BTree failure


Yep, that seems like a good fix.

Dave

On Aug 15, 2011, at 8:18 AM, David Binger wrote:

I think I'd prefer to fix this by having FileStorage.load() raise a DurusKeyError instead of KeyError.
Does that seem reasonable to you?

On Aug 14, 2011, at 11:37 PM, David Hess wrote:

I think there might be a bug in load_state in connection.py -  shouldn't it also catch KeyError to handle the case when working from a local FileStorage instead of a ClientStorage (as the traceback below shows)?


_______________________________________________
Durus-users mailing list
Durus-users <at> mems-exchange.org
http://mail.mems-exchange.org/mailman/listinfo/durus-users
David Binger | 15 Aug 2011 15:50

Re: Interesting BTree failure

This sounds like the offset mapping in memory is somehow out of sync with the file.
We've never seen this condition,  which is obviously bad.  I'm concerned
about this and trying to figure out how it could occur.

It seems unlikely to have anything in particular to do with BTree or BNodes:  those structures
are implemented in the same way as other persistent objects.  I think, from your
other message, that you are looking closely at the packing code, and that
seems like a good idea.  There was a time when you talked about
overriding a '_p_' method.  Does the code you are running involve
any such low-level modifications?  

In the current code tree, File.write() ends with self.file.flush() under all conditions.
Is that the case in the code you are running?  

On Aug 14, 2011, at 12:44 PM, David Hess wrote:

Afterwards, the oids seem to be jumbled up in this BTree (at least - maybe elsewhere in the database too). Unpickled Persistent objects are not what they should be - interior BNodes are sometimes application classes and stored values are sometimes BNodes rather than application classes.

_______________________________________________
Durus-users mailing list
Durus-users <at> mems-exchange.org
http://mail.mems-exchange.org/mailman/listinfo/durus-users
David Hess | 15 Aug 2011 16:12
Favicon

Re: Interesting BTree failure


On Aug 15, 2011, at 8:50 AM, David Binger wrote:

This sounds like the offset mapping in memory is somehow out of sync with the file.
We've never seen this condition,  which is obviously bad.  I'm concerned
about this and trying to figure out how it could occur.

Yes, if the packing implementation was an issue, I would have thought we would just have missing oids (or is that a durus_id now?) - but I also have evidence of an object whose class is BNode trying to load state of a pickle that was clearly associated with an application object.

Based on what I did to repair the database, it appears this corruption only affected the items that were touched when the modification to the BTree was made during the pack (interior BNodes and the application objects). It's almost as if there is a race problem during packing having to do with either durus_id allocation or file writing.

It seems unlikely to have anything in particular to do with BTree or BNodes:  those structures
are implemented in the same way as other persistent objects.  I think, from your
other message, that you are looking closely at the packing code, and that
seems like a good idea.  There was a time when you talked about
overriding a '_p_' method.  Does the code you are running involve
any such low-level modifications?  

That's on one particular and isolated class that was not involved in this situation. All it does is ignore the ghosting request from the cache manager (which is safe because we never have conflicts).

In the current code tree, File.write() ends with self.file.flush() under all conditions.
Is that the case in the code you are running? 

Here's the implementation we are running from on Durus 3.7:

    def write(self, s):
        self.obtain_lock()
        self.file.write(s)

I noticed that DurusWorks 1.0 has been released but the CHANGES.txt files are gone. Should we upgrade to DurusWorks 1.0 instead of 3.8? It looks like Durus is no longer distributed separately?

Thanks.

Dave

On Aug 14, 2011, at 12:44 PM, David Hess wrote:

Afterwards, the oids seem to be jumbled up in this BTree (at least - maybe elsewhere in the database too). Unpickled Persistent objects are not what they should be - interior BNodes are sometimes application classes and stored values are sometimes BNodes rather than application classes.

_______________________________________________
Durus-users mailing list
Durus-users <at> mems-exchange.org
http://mail.mems-exchange.org/mailman/listinfo/durus-users
David Hess | 15 Aug 2011 16:50
Favicon

Re: Interesting BTree failure


On Aug 15, 2011, at 9:12 AM, David Hess wrote:

> On Aug 15, 2011, at 8:50 AM, David Binger wrote:
> 
>> This sounds like the offset mapping in memory is somehow out of sync with the file.
>> We've never seen this condition,  which is obviously bad.  I'm concerned
>> about this and trying to figure out how it could occur.

I should note that this mis-mapping was not just in process memory. It was a permanent change to the database
and occurs each time you open it and access an affected object.

Thinking about this some more: if that object was worked with during the pack and yet it was ghosted and was
trying to reload its state - that implies that not only commits occurred during a pack but also a cache shrink.

Is it safe for a cache shrink to occur during a pack?

We're going to work on building a test app that can recreate this problem.

Dave
David Binger | 15 Aug 2011 16:59

Re: Interesting BTree failure


On Aug 15, 2011, at 10:50 AM, David Hess wrote:

I should note that this mis-mapping was not just in process memory. It was a permanent change to the database and occurs each time you open it and access an affected object.

OK.


Thinking about this some more: if that object was worked with during the pack and yet it was ghosted and was trying to reload its state - that implies that not only commits occurred during a pack but also a cache shrink.

Is it safe for a cache shrink to occur during a pack?

I haven't studied the issue, but I would guess that it is safe.


We're going to work on building a test app that can recreate this problem.

If we have that, then we can solve it for sure.

_______________________________________________
Durus-users mailing list
Durus-users <at> mems-exchange.org
http://mail.mems-exchange.org/mailman/listinfo/durus-users
David Binger | 15 Aug 2011 16:55

Re: Interesting BTree failure

On Aug 15, 2011, at 10:12 AM, David Hess wrote:


On Aug 15, 2011, at 8:50 AM, David Binger wrote:

This sounds like the offset mapping in memory is somehow out of sync with the file.
We've never seen this condition,  which is obviously bad.  I'm concerned
about this and trying to figure out how it could occur.

Yes, if the packing implementation was an issue, I would have thought we would just have missing oids (or is that a durus_id now?) - but I also have evidence of an object whose class is BNode trying to load state of a pickle that was clearly associated with an application object.

Yes, the oid is now called "durus_id".

I just meant that the BNode class doesn't have any special state management code
that could be causing the problem.  I think BNode is involved only because
that is where your actions happen to be.


Based on what I did to repair the database, it appears this corruption only affected the items that were touched when the modification to the BTree was made during the pack (interior BNodes and the application objects). It's almost as if there is a race problem during packing having to do with either durus_id allocation or file writing.

I would be interested in the details of the repair.

I don't remember the details of how you are using FileStorage.
Do you have just one thread/process using the FileStorage?  I hope so.


It seems unlikely to have anything in particular to do with BTree or BNodes:  those structures
are implemented in the same way as other persistent objects.  I think, from your
other message, that you are looking closely at the packing code, and that
seems like a good idea.  There was a time when you talked about
overriding a '_p_' method.  Does the code you are running involve
any such low-level modifications?  

That's on one particular and isolated class that was not involved in this situation. All it does is ignore the ghosting request from the cache manager (which is safe because we never have conflicts).

That does seem safe.   Is there any code in the cache manager, though, that
calls the ghosting function and then takes some action based on the assumption
that the ghosting worked?


In the current code tree, File.write() ends with self.file.flush() under all conditions.
Is that the case in the code you are running? 

Here's the implementation we are running from on Durus 3.7:

    def write(self, s):
        self.obtain_lock()
        self.file.write(s)

The new code adds self.file.flush().  Without it, certain file systems 
lose track of the correct end of the file, so a subsequent seek to the end
of the file ends up in an incorrect place. 
In a pack, an offset is written into the header of the file and then
there is a seek to the end of the file.  It is important for
this to work correctly.  It could possibly be the reason
for the trouble you have seen.


I noticed that DurusWorks 1.0 has been released but the CHANGES.txt files are gone. Should we upgrade to DurusWorks 1.0 instead of 3.8? It looks like Durus is no longer distributed separately?

Yes, DurusWorks is a new distribution that includes Durus.
I have not yet sent out an announcement.  Sorry.
I'll start a new CHANGES.txt file in the next release.  
I'd recommend downloading it and diffing the durus package
against the one you have.  This code is not changed
much, so I hope that is not too much trouble.
I would upgrade.


Thanks.

Dave

On Aug 14, 2011, at 12:44 PM, David Hess wrote:

Afterwards, the oids seem to be jumbled up in this BTree (at least - maybe elsewhere in the database too). Unpickled Persistent objects are not what they should be - interior BNodes are sometimes application classes and stored values are sometimes BNodes rather than application classes.



_______________________________________________
Durus-users mailing list
Durus-users <at> mems-exchange.org
http://mail.mems-exchange.org/mailman/listinfo/durus-users
David Hess | 15 Aug 2011 17:13
Favicon

Re: Interesting BTree failure


On Aug 15, 2011, at 9:55 AM, David Binger wrote:

On Aug 15, 2011, at 10:12 AM, David Hess wrote:


On Aug 15, 2011, at 8:50 AM, David Binger wrote:

This sounds like the offset mapping in memory is somehow out of sync with the file.
We've never seen this condition,  which is obviously bad.  I'm concerned
about this and trying to figure out how it could occur.

Yes, if the packing implementation was an issue, I would have thought we would just have missing oids (or is that a durus_id now?) - but I also have evidence of an object whose class is BNode trying to load state of a pickle that was clearly associated with an application object.

Yes, the oid is now called "durus_id".

I just meant that the BNode class doesn't have any special state management code
that could be causing the problem.  I think BNode is involved only because
that is where your actions happen to be.

Agree.

Based on what I did to repair the database, it appears this corruption only affected the items that were touched when the modification to the BTree was made during the pack (interior BNodes and the application objects). It's almost as if there is a race problem during packing having to do with either durus_id allocation or file writing.

I would be interested in the details of the repair.

This particular BTree is an index of all instances of a particular Persistent subclass. My repair involved using a monkey patched get_crawler that could handle an exception in __setstate__ and keep going.

I then walked through the entire database finding all instances of my particular class that didn't blow up when loaded and then loading them into a brand new btree. I then deleted the old btree and packed the resulting database. Based on the debugging I added to the monkey patched get_crawler, the magnitude of the problem reported there matched the amount of change that went on during the packing. Didn't confirm yet that it was exactly the changes that occurred during the packing.

I don't remember the details of how you are using FileStorage.
Do you have just one thread/process using the FileStorage?  I hope so.

We are definitely one thread and one process for this FileStorage. We do use Twisted so there's a lot of asynchronous things going on and interleaved with each crank forward of the packing generator. We commit every 5 seconds rather than on a transactional basis. We never have conflicts.

It seems unlikely to have anything in particular to do with BTree or BNodes:  those structures
are implemented in the same way as other persistent objects.  I think, from your
other message, that you are looking closely at the packing code, and that
seems like a good idea.  There was a time when you talked about
overriding a '_p_' method.  Does the code you are running involve
any such low-level modifications?  

That's on one particular and isolated class that was not involved in this situation. All it does is ignore the ghosting request from the cache manager (which is safe because we never have conflicts).

That does seem safe.   Is there any code in the cache manager, though, that
calls the ghosting function and then takes some action based on the assumption
that the ghosting worked?

The Cache.shrink implementation didn't seem to care - but I'm not that familiar enough with exactly how that code works to be sure.

In the current code tree, File.write() ends with self.file.flush() under all conditions.
Is that the case in the code you are running? 

Here's the implementation we are running from on Durus 3.7:

    def write(self, s):
        self.obtain_lock()
        self.file.write(s)

The new code adds self.file.flush().  Without it, certain file systems 
lose track of the correct end of the file, so a subsequent seek to the end
of the file ends up in an incorrect place. 
In a pack, an offset is written into the header of the file and then
there is a seek to the end of the file.  It is important for
this to work correctly.  It could possibly be the reason
for the trouble you have seen.

Our platform is Ubuntu 10.04 LTS and this is an ext3 file system.

I noticed that DurusWorks 1.0 has been released but the CHANGES.txt files are gone. Should we upgrade to DurusWorks 1.0 instead of 3.8? It looks like Durus is no longer distributed separately?

Yes, DurusWorks is a new distribution that includes Durus.
I have not yet sent out an announcement.  Sorry.
I'll start a new CHANGES.txt file in the next release.  
I'd recommend downloading it and diffing the durus package
against the one you have.  This code is not changed
much, so I hope that is not too much trouble.
I would upgrade.

Ok, we'll head that direction.

Dave

------
David K. Hess
877.343.4947 x114

_______________________________________________
Durus-users mailing list
Durus-users <at> mems-exchange.org
http://mail.mems-exchange.org/mailman/listinfo/durus-users
David Binger | 17 Aug 2011 14:38

Re: Interesting BTree failure: SOLVED

Good news.
The issue discussed in this thread has now been diagnosed and solved by David Hess.

The problem turned out to be this:
when a persistent instance becomes temporarily unreachable during the period
that an incremental pack is in progress, the object's record might be left out of the
newly packed file. All subsequent attempts to access that object, including subsequent
packs, would get an exception.

This rare trap has existed for years: for all versions that supported incremental packing.

The patch will be included in the next release (expected soon).

Thanks, David, for your good work on this.
David Hess | 17 Aug 2011 15:38
Favicon

Re: Interesting BTree failure: SOLVED


As always, thanks for Durus. It's a great (and under-recognized) database.

We may end up patching Durus 3.7 to avoid having to upgrade everything for the moment. If anybody is
interested in that patch, let me know.

Dave

On Aug 17, 2011, at 7:38 AM, David Binger wrote:

> Good news.
> The issue discussed in this thread has now been diagnosed and solved by David Hess.
> 
> The problem turned out to be this:
> when a persistent instance becomes temporarily unreachable during the period
> that an incremental pack is in progress, the object's record might be left out of the
> newly packed file. All subsequent attempts to access that object, including subsequent
> packs, would get an exception.
> 
> This rare trap has existed for years: for all versions that supported incremental packing.
> 
> The patch will be included in the next release (expected soon).
> 
> Thanks, David, for your good work on this.

Gmane