[ZODB-Dev] Bug during pack with Relstorage 1.5.0

[Shane Hathaway]

On 08/30/2011 04:02 AM, Sylvain Viollon wrote:
>      I have a customer using RelStorage 1.5.0 in production, and he cannot pack anymore his Data.fs. When he tries he have the following error:
>
>> 2011-08-29 15:43:03,459 [zodbpack] INFO Opening storage (RelStorageFactory)...
>> 2011-08-29 15:43:03,966 [zodbpack] INFO Packing storage (RelStorageFactory).
>> 2011-08-29 15:43:03,974 [relstorage] INFO pack: analyzing transactions committed Fri Aug 26 18:04:56 2011 or before
>> 2011-08-29 15:43:03,977 [relstorage.adapters.packundo] INFO pre_pack: start with gc enabled
>> 2011-08-29 15:43:04,784 [relstorage.adapters.packundo] INFO analyzing references from objects in 436309 new transaction(s)
>> /var/www/env_ucpa_silva/ucpa_silva/eggs/RelStorage-1.5.0-py2.6.egg/relstorage/adapters/scriptrunner.py:52: Warning: Field 'zoid' doesn't have a default value
>> cursor.execute(stmt, generic_params)
>> 2011-08-29 15:43:04,799 [relstorage.adapters.scriptrunner] WARNING script statement failed: '\n        INSERT INTO object_refs_added (tid)\n VALUES (%(tid)s)\n        '; parameters: {'tid': 247097224207245124L}
>> 2011-08-29 15:43:04,799 [relstorage.adapters.packundo] ERROR pre_pack: failed
>> Traceback (most recent call last):
>> File "/var/www/env_ucpa_silva/ucpa_silva/eggs/RelStorage-1.5.0-py2.6.egg/relstorage/adapters/packundo.py", line 486, in pre_pack
>>    conn, cursor, pack_tid, get_references)
>> File "/var/www/env_ucpa_silva/ucpa_silva/eggs/RelStorage-1.5.0-py2.6.egg/relstorage/adapters/packundo.py", line 580, in _pre_pack_with_gc
>>    self.fill_object_refs(conn, cursor, get_references)
>> File "/var/www/env_ucpa_silva/ucpa_silva/eggs/RelStorage-1.5.0-py2.6.egg/relstorage/adapters/packundo.py", line 387, in fill_object_refs
>>    self._add_refs_for_tid(cursor, tid, get_references)
>> File "/var/www/env_ucpa_silva/ucpa_silva/eggs/RelStorage-1.5.0-py2.6.egg/relstorage/adapters/packundo.py", line 459, in _add_refs_for_tid
>>    self.runner.run_script_stmt(cursor, stmt, {'tid': tid})
>> File "/var/www/env_ucpa_silva/ucpa_silva/eggs/RelStorage-1.5.0-py2.6.egg/relstorage/adapters/scriptrunner.py", line 52, in run_script_stmt
>>    cursor.execute(stmt, generic_params)
>> File "/var/www/env_ucpa_silva/ucpa_silva/eggs/MySQL_python-1.2.3-py2.6-linux-x86_64.egg/MySQLdb/cursors.py", line 174, in execute
>>    self.errorhandler(self, exc, value)
>> File "/var/www/env_ucpa_silva/ucpa_silva/eggs/MySQL_python-1.2.3-py2.6-linux-x86_64.egg/MySQLdb/connections.py", line 36, in defaulterrorhandler
>>    raise errorclass, errorvalue
>> IntegrityError: (1062, "Duplicate entry '0' for key 'PRIMARY'")
>
>    He tried to cleanup the tables object_refs_added and object_refs but the error persist and seems to stay the same.
>
>    Before 1.5.0 they had 1.4.1 (the database have been created using that version), and when this problem appear, I recommended as 1.5.0 contains various fixes for pack on large database.
>
>    Do you have any ideas on how to fix this pack ?

What version of MySQL?

It looks to me like he tried to clean up the tables by dropping and 
re-creating them, but that he used the wrong schema when creating them. 
  The warning "Field 'zoid' doesn't have a default value" in the log 
suggests he used the history-free version of the object_refs_added table 
with a history-preserving database.  They are not compatible.  Try this, 
then pack again:

DROP TABLE object_ref;
DROP TABLE object_refs_added;

CREATE TABLE object_ref (
     zoid        BIGINT NOT NULL,
     tid         BIGINT NOT NULL,
     to_zoid     BIGINT NOT NULL,
     PRIMARY KEY (tid, zoid, to_zoid)
) ENGINE = MyISAM;

CREATE TABLE object_refs_added (
     tid         BIGINT NOT NULL PRIMARY KEY
) ENGINE = MyISAM;

Shane