Ok I'm starting to understand things a little better. The transaction
255911127406517196 was the last transaction who's references were added to the
object_ref table. But (I'm guessing because I interrupted the pack) it didn't
get marked in the transaction table as packed. In fact there are 11088
transactions in this state. Below are the details. I haven't fully understood
the code yet (and its getting too late for productive thinking :) ) but I see
to potential solutions:
1. Mark the transactions that have been moved to object_ref as packed but I'm
guessing though that this isn't a good idea because there is other stuff that
needs to happen during the pack.
2. Remove the unpacked transactions from the object_ref table. (this seems very
scary to me).
I will continue looking at the code tomorrow. In the mean time is there an
issue with continuing to use the database? Will the orphaned object_ref
records cause a problem. (doesn't seem like they would).
Here are the details:
mysql> select tid from transaction where tid <= 255911127406517196 and
packed=true order by tid desc limit 1;
+--------------------+
| tid |
+--------------------+
| 255908476364112230 | -- the last transaction marked as packed
+--------------------+
mysql> select count(*) from transaction where tid >= 255908476364112230 and tid
< 255911127406517196 order by tid desc;
+----------+
| count(*) |
+----------+
| 11088 | -- this is the number of transactions that seem to have been
packed without being marked as packed.
+----------+
mysql> select count(*) from transaction where tid > 255911127406517196;
+----------+
| count(*) |
+----------+
| 178909 | -- number of transactions that haven't made it into the object_ref
table
+----------+
mysql> select count(*) from object_ref where tid > 255911127406517196;
+----------+
| count(*) |
+----------+
| 0 | -- confirmation that the transactions after 255911127406517196
have not made it into the object_ref table
+----------+
1 row in set (0.00 sec)
mysql> select count(*) from object_ref where tid >= 255911127406517196;
+----------+
| count(*) |
+----------+
| 3907 | -- confirmation again
+----------+
1 row in set (0.00 sec)
mysql> select count(*) from object_ref where tid = 255911127406517196;
+----------+
| count(*) |
+----------+
| 3907 | -- and again
+----------+
1 row in set (0.00 sec)
-EAD
On Mar 29, 2011, at 9:39 PM, Erik Dahl wrote:
> I was running a pack and canceled so that I could reboot my box. After it
> came back up I tried to restart the pack and got this:
>
> 2011-03-29 20:53:07,259 [zodbpack] INFO Opening storage (RelStorageFactory)...
> 2011-03-29 20:53:07,457 [zodbpack] INFO Packing storage (RelStorageFactory).
> 2011-03-29 20:53:07,464 [relstorage] INFO pack: analyzing transactions
> committed Tue Mar 29 20:49:48 2011 or before
> 2011-03-29 20:53:07,465 [relstorage.adapters.packundo] INFO pre_pack: start
> with gc enabled
> 2011-03-29 20:53:08,846 [relstorage.adapters.packundo] INFO discovering
> references from objects in 178910 transaction(s)
> 2011-03-29 20:53:10,808 [relstorage.adapters.packundo] ERROR pre_pack: failed
> Traceback (most recent call last):
> File
> "/opt/zenoss/lib/python2.6/site-packages/RelStorage-1.4.2-py2.6.egg/relstorage/adapters/packundo.py",
> line 431, in pre_pack
> conn, cursor, pack_tid, get_references)
> File
> "/opt/zenoss/lib/python2.6/site-packages/RelStorage-1.4.2-py2.6.egg/relstorage/adapters/packundo.py",
> line 525, in _pre_pack_with_gc
> self.fill_object_refs(conn, cursor, get_references)
> File
> "/opt/zenoss/lib/python2.6/site-packages/RelStorage-1.4.2-py2.6.egg/relstorage/adapters/packundo.py",
> line 347, in fill_object_refs
> added += self._add_refs_for_tid(cursor, tid, get_references)
> File
> "/opt/zenoss/lib/python2.6/site-packages/RelStorage-1.4.2-py2.6.egg/relstorage/adapters/packundo.py",
> line 397, in _add_refs_for_tid
> self.runner.run_many(cursor, stmt, add_rows)
> File
> "/opt/zenoss/lib/python2.6/site-packages/RelStorage-1.4.2-py2.6.egg/relstorage/adapters/scriptrunner.py",
> line 90, in run_many
> cursor.executemany(stmt, items)
> File "build/bdist.linux-x86_64/egg/MySQLdb/cursors.py", line 206, in
> executemany
> r = r + self.execute(query, a)
> File "build/bdist.linux-x86_64/egg/MySQLdb/cursors.py", line 174, in execute
> self.errorhandler(self, exc, value)
> File "build/bdist.linux-x86_64/egg/MySQLdb/connections.py", line 36, in
> defaulterrorhandler
> raise errorclass, errorvalue
> IntegrityError: (1062, "Duplicate entry '255911127406517196-2714-893440' for
> key 'PRIMARY'")
> Traceback (most recent call last):
> File "/opt/zenoss/bin/zodbpack", line 8, in <module>
> load_entry_point('RelStorage==1.4.2', 'console_scripts', 'zodbpack')()
>
>
> I'm in process of running mysqlcheck against the database and I have the
> application off line. I've looked at the code but I'm not 100% what it's
> trying to do. Thoughts? Is my database hosed? or just my packing process.
>
>
> -EAD
>
>
>
_______________________________________________
For more information about ZODB, see the ZODB Wiki:
http://www.zope.org/Wikis/ZODB/
ZODB-Dev mailing list - ZODB-Dev@zope.org
https://mail.zope.org/mailman/listinfo/zodb-dev
