search

wamdam / backy2

backy2: Deduplicating block based backup software for ceph/rbd, image files and devices
http://backy2.com/
Other
195 stars 39 forks source link

deleted_blocks.id may not be NULL #43

Closed noeyhuy closed 4 years ago

noeyhuy commented 4 years ago

I was just trying to delete the backup. i dont know this error messages. what is mean? help me

[root@localhost ~]# backy2 ls INFO: $ /usr/local/bin/backy2 ls +---------------------+----------------+---------------+------+-------------+--------------------------------------+-------+-----------+----------------------------+ | date | name | snapshot_name | size | size_bytes | uid | valid | protected | tags | +---------------------+----------------+---------------+------+-------------+--------------------------------------+-------+-----------+----------------------------+ | 2019-12-24 02:17:10 | diff_friday | | 7789 | 32667729920 | 7db45032-25f3-11ea-b507-525400e5d9c4 | 1 | 0 | b_daily,b_monthly,b_weekly | | 2019-12-24 02:35:02 | diff_saturday | | 7789 | 32667992064 | fceae850-25f5-11ea-96df-525400e5d9c4 | 1 | 0 | b_daily,b_monthly,b_weekly | | 2019-12-24 02:47:58 | diff_sunday | | 7789 | 32668319744 | cb64594a-25f7-11ea-b015-525400e5d9c4 | 1 | 0 | b_daily,b_monthly,b_weekly | | 2019-12-24 02:02:55 | diff_thursday | | 7789 | 32667271168 | 80537f72-25f1-11ea-b51b-525400e5d9c4 | 1 | 0 | b_daily,b_monthly,b_weekly | | 2019-12-24 01:35:18 | diff_tuesday | | 7789 | 32667205632 | a497a042-25ed-11ea-976e-525400e5d9c4 | 1 | 0 | b_daily,b_monthly,b_weekly | | 2019-12-24 01:49:12 | diff_wednesday | | 7789 | 32667205632 | 955fdd22-25ef-11ea-b94c-525400e5d9c4 | 1 | 0 | b_daily,b_monthly,b_weekly | | 2019-12-24 01:18:44 | full_monday | | 7789 | 32667205632 | 53c5b570-25eb-11ea-a906-525400e5d9c4 | 1 | 0 | b_daily,b_monthly,b_weekly | +---------------------+----------------+---------------+------+-------------+--------------------------------------+-------+-----------+----------------------------+ INFO: Backy complete.

[root@localhost~]# backy2 rm 53c5b570-25eb-11ea-a906-525400e5d9c4 -f INFO: $ /usr/local/bin/backy2 rm 53c5b570-25eb-11ea-a906-525400e5d9c4 -f ERROR: Unexpected exception ERROR: (raised as a result of Query-invoked autoflush; consider using a session.no_autoflush block if this flush is occurring prematurely) (sqlite3.IntegrityError) deleted_blocks.id may not be NULL [SQL: INSERT INTO deleted_blocks (uid, size, delete_candidate, time) VALUES (?, ?, ?, ?)] [parameters: ('27e0f57bb3WZTSVmnbwxZy3X7Yr7h7U2', 4194304, 0, 1577164518)] (Background on this error at: http://sqlalche.me/e/gkpj) Traceback (most recent call last): File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 1246, in _execute_context cursor, statement, parameters, context File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/engine/default.py", line 581, in do_execute cursor.execute(statement, parameters) sqlite3.IntegrityError: deleted_blocks.id may not be NULL

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/usr/local/lib/python3.6/site-packages/backy2-2.9.18-py3.6.egg/backy2/scripts/backy.py", line 583, in main func(func_args) File "/usr/local/lib/python3.6/site-packages/backy2-2.9.18-py3.6.egg/backy2/scripts/backy.py", line 62, in rm backy.rm(version_uid, force, disallow_rm_when_younger_than_days) File "/usr/local/lib/python3.6/site-packages/backy2-2.9.18-py3.6.egg/backy2/backy.py", line 345, in rm num_blocks = self.meta_backend.rm_version(version_uid) File "/usr/local/lib/python3.6/site-packages/backy2-2.9.18-py3.6.egg/backy2/meta_backends/sql.py", line 380, in rm_version affected_blocks.delete() File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/orm/query.py", line 3752, in delete deleteop.exec() File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x8664.egg/sqlalchemy/orm/persistence.py", line 1691, in exec self._do_pre() File "", line 1, in File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/orm/persistence.py", line 1737, in _do_pre session._autoflush() File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 1588, in _autoflush util.raise_from_cause(e) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/util/compat.py", line 398, in raise_from_cause reraise(type(exception), exception, tb=exc_tb, cause=cause) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/util/compat.py", line 153, in reraise raise value File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 1577, in _autoflush self.flush() File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 2470, in flush self._flush(objects) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 2608, in _flush transaction.rollback(_capture_exception=True) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/util/langhelpers.py", line 68, in exit compat.reraise(exc_type, exc_value, exc_tb) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/util/compat.py", line 153, in reraise raise value File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 2568, in _flush flush_context.execute() File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/orm/unitofwork.py", line 422, in execute rec.execute(self) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/orm/unitofwork.py", line 589, in execute uow, File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/orm/persistence.py", line 245, in save_obj insert, File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/orm/persistence.py", line 1137, in _emit_insert_statements statement, params File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 982, in execute return meth(self, multiparams, params) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/sql/elements.py", line 287, in _execute_on_connection return connection._execute_clauseelement(self, multiparams, params) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 1101, in _execute_clauseelement distilled_params, File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 1250, in _execute_context e, statement, parameters, cursor, context File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 1476, in _handle_dbapi_exception util.raise_from_cause(sqlalchemy_exception, exc_info) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/util/compat.py", line 398, in raise_from_cause reraise(type(exception), exception, tb=exc_tb, cause=cause) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/util/compat.py", line 152, in reraise raise value.with_traceback(tb) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 1246, in _execute_context cursor, statement, parameters, context File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/engine/default.py", line 581, in do_execute cursor.execute(statement, parameters) sqlalchemy.exc.IntegrityError: (raised as a result of Query-invoked autoflush; consider using a session.no_autoflush block if this flush is occurring prematurely) (sqlite3.IntegrityError) deleted_blocks.id may not be NULL** [SQL: INSERT INTO deleted_blocks (uid, size, delete_candidate, time) VALUES (?, ?, ?, ?)] [parameters: ('27e0f57bb3WZTSVmnbwxZy3X7Yr7h7U2', 4194304, 0, 1577164518)] (Background on this error at: http://sqlalche.me/e/gkpj) INFO: Backy failed.

olifre commented 4 years ago

Are you using sqlite as DB? If so, this is probably a duplicate of #35 .

noeyhuy commented 4 years ago

Thanks. I think the delete command(name : full_monday) is done, I checked with the stats command and it was not deleted properly. Is there anything wrong?

[root@localhost backy2]# backy2 rm 53c5b570-25eb-11ea-a906-525400e5d9c4 -f
INFO: $ /usr/local/bin/backy2 rm 53c5b570-25eb-11ea-a906-525400e5d9c4 -f /usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/orm/session.py:1895: SAWarning: Identity map already had an identity for (<class 'backy2.meta_backends.sql.DeletedBlock'>, ('c81373f370WJdUBuWZpSBwVMWNzNojeK',), None), replacing it with newly flushed object. Are there load operations occurring inside of an event handler within the flush? "within the flush?" % (instance_key,) /usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/orm/session.py:1895: SAWarning: Identity map already had an identity for (<class 'backy2.meta_backends.sql.DeletedBlock'>, ('88dfc850f8F73ptS9CzqeW3wQbTqf96a',), None), replacing it with newly flushed object. Are there load operations occurring inside of an event handler within the flush? "within the flush?" % (instance_key,) /usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.11-py3.6-linux-x86_64.egg/sqlalchemy/orm/session.py:1895: SAWarning: Identity map already had an identity for (<class 'backy2.meta_backends.sql.DeletedBlock'>, ('dba679b059KxwBQEtdv2vBNWo4nUcskE',), None), replacing it with newly flushed object. Are there load operations occurring inside of an event handler within the flush? "within the flush?" % (instance_key,) INFO: Removed backup version 53c5b570-25eb-11ea-a906-525400e5d9c4 with 7789 blocks. INFO: Backy complete.

[root@localhost backy2]# backy2 ls INFO: $ /usr/local/bin/backy2 ls +---------------------+----------------+---------------+------+-------------+--------------------------------------+-------+-----------+----------------------------+ | date | name | snapshot_name | size | size_bytes | uid | valid | protected | tags | +---------------------+----------------+---------------+------+-------------+--------------------------------------+-------+-----------+----------------------------+ | 2019-12-24 02:17:10 | diff_friday | | 7789 | 32667729920 | 7db45032-25f3-11ea-b507-525400e5d9c4 | 1 | 0 | b_daily,b_monthly,b_weekly | | 2019-12-24 02:35:02 | diff_saturday | | 7789 | 32667992064 | fceae850-25f5-11ea-96df-525400e5d9c4 | 1 | 0 | b_daily,b_monthly,b_weekly | | 2019-12-24 02:47:58 | diff_sunday | | 7789 | 32668319744 | cb64594a-25f7-11ea-b015-525400e5d9c4 | 1 | 0 | b_daily,b_monthly,b_weekly | | 2019-12-24 02:02:55 | diff_thursday | | 7789 | 32667271168 | 80537f72-25f1-11ea-b51b-525400e5d9c4 | 1 | 0 | b_daily,b_monthly,b_weekly | | 2019-12-24 01:35:18 | diff_tuesday | | 7789 | 32667205632 | a497a042-25ed-11ea-976e-525400e5d9c4 | 1 | 0 | b_daily,b_monthly,b_weekly | | 2019-12-24 01:49:12 | diff_wednesday | | 7789 | 32667205632 | 955fdd22-25ef-11ea-b94c-525400e5d9c4 | 1 | 0 | b_daily,b_monthly,b_weekly | +---------------------+----------------+---------------+------+-------------+--------------------------------------+-------+-----------+----------------------------+ INFO: Backy complete.

[root@localhost backy2]# backy2 stats INFO: $ /usr/local/bin/backy2 stats +---------------------+--------------------------------------+----------------+-------------+-------------+-------------+-------------+---------------+----------------+-------------+--------------+--------------+---------------+--------------+ | date | uid | name | size bytes | size blocks | bytes read | blocks read | bytes written | blocks written | bytes dedup | blocks dedup | bytes sparse | blocks sparse | duration (s) | +---------------------+--------------------------------------+----------------+-------------+-------------+-------------+-------------+---------------+----------------+-------------+--------------+--------------+---------------+--------------+ | 2019-12-24 01:22:37 | 53c5b570-25eb-11ea-a906-525400e5d9c4 | full_monday | 32667205632 | 7789 | 32667205632 | 7789 | 2879258624 | 687 | 12582912 | 3 | 29775364096 | 7099 | 233 | | 2019-12-24 01:38:53 | a497a042-25ed-11ea-976e-525400e5d9c4 | diff_tuesday | 32667205632 | 7789 | 32667205632 | 7789 | 41943040 | 10 | 2849898496 | 680 | 29775364096 | 7099 | 214 | | 2019-12-24 01:52:58 | 955fdd22-25ef-11ea-b94c-525400e5d9c4 | diff_wednesday | 32667205632 | 7789 | 32667205632 | 7789 | 69074944 | 17 | 2822766592 | 673 | 29775364096 | 7099 | 226 | | 2019-12-24 02:06:31 | 80537f72-25f1-11ea-b51b-525400e5d9c4 | diff_thursday | 32667271168 | 7789 | 32667271168 | 7789 | 52363264 | 13 | 2839543808 | 677 | 29775364096 | 7099 | 215 | | 2019-12-24 02:20:50 | 7db45032-25f3-11ea-b507-525400e5d9c4 | diff_friday | 32667729920 | 7789 | 32667729920 | 7789 | 52822016 | 13 | 2839543808 | 677 | 29775364096 | 7099 | 219 | | 2019-12-24 02:38:38 | fceae850-25f5-11ea-96df-525400e5d9c4 | diff_saturday | 32667992064 | 7789 | 32667992064 | 7789 | 32112640 | 8 | 2860515328 | 682 | 29775364096 | 7099 | 215 | | 2019-12-24 02:51:37 | cb64594a-25f7-11ea-b015-525400e5d9c4 | diff_sunday | 32668319744 | 7789 | 32668319744 | 7789 | 40828928 | 10 | 2852126720 | 680 | 29775364096 | 7099 | 218 | +---------------------+--------------------------------------+----------------+-------------+-------------+-------------+-------------+---------------+----------------+-------------+--------------+--------------+---------------+--------------+ INFO: Backy complete.

olifre commented 4 years ago

@noeyhuy That does indeed not look right to me. I stopped using Backy2 after encountering the SQLite backup deletion issue, so I can sadly not be of help here apart from recommending switching to a different DBMS if you want to keep using SQLite.

noeyhuy commented 4 years ago

ok. thanks you. I changed from sqlite to postgresql. But the same problem happened when I deleted it. Why would I see it if I typed the stats command? Fortunately, the deletion seems to have been good, considering that the recovery is not possible.

[root@localhost ~]# backy2 ls INFO: $ /usr/local/bin/backy2 ls +----------------------------+-------------+---------------+------+-------------+--------------------------------------+-------+-----------+----------------------------+ | date | name | snapshot_name | size | size_bytes | uid | valid | protected | tags | +----------------------------+-------------+---------------+------+-------------+--------------------------------------+-------+-----------+----------------------------+ | 2019-12-30 17:32:46.407500 | full_monday | | 7789 | 32667205632 | f4a7e452-2ade-11ea-b7c5-525400e5d9c4 | 1 | 0 | b_daily,b_monthly,b_weekly | +----------------------------+-------------+---------------+------+-------------+--------------------------------------+-------+-----------+----------------------------+ INFO: Backy complete.

[root@localhost ~]# backy2 rm f4a7e452-2ade-11ea-b7c5-525400e5d9c4 -f INFO: $ /usr/local/bin/backy2 rm f4a7e452-2ade-11ea-b7c5-525400e5d9c4 -f INFO: Removed backup version f4a7e452-2ade-11ea-b7c5-525400e5d9c4 with 7789 blocks. INFO: Backy complete.

[root@localhost ~]# backy2 ls
INFO: $ /usr/local/bin/backy2 ls +------+------+---------------+------+------------+-----+-------+-----------+------+ | date | name | snapshot_name | size | size_bytes | uid | valid | protected | tags | +------+------+---------------+------+------------+-----+-------+-----------+------+ +------+------+---------------+------+------------+-----+-------+-----------+------+ INFO: Backy complete.

[root@localhost ~]# backy2 cleanup -f INFO: $ /usr/local/bin/backy2 cleanup -f INFO: Cleanup: Removed 1384 blobs INFO: Backy complete.

[root@localhost ~]## backy2 stats INFO: $ /usr/local/bin/backy2 stats +----------------------------+--------------------------------------+-------------+-------------+-------------+-------------+-------------+---------------+----------------+-------------+--------------+--------------+---------------+--------------+ | date | uid | name | size bytes | size blocks | bytes read | blocks read | bytes written | blocks written | bytes dedup | blocks dedup | bytes sparse | blocks sparse | duration (s) | +----------------------------+--------------------------------------+-------------+-------------+-------------+-------------+-------------+---------------+----------------+-------------+--------------+--------------+---------------+--------------+ | 2019-12-30 17:34:43.390984 | f4a7e452-2ade-11ea-b7c5-525400e5d9c4 | full_monday | 32667205632 | 7789 | 32667205632 | 7789 | 2879258624 | 687 | 12582912 | 3 | 29775364096 | 7099 | 117 | +----------------------------+--------------------------------------+-------------+-------------+-------------+-------------+-------------+---------------+----------------+-------------+--------------+--------------+---------------+--------------+ INFO: Backy complete.

[root@localhost ~]# backy2 restore f4a7e452-2ade-11ea-b7c5-525400e5d9c4 file:///home/restore/KT1_TEST_hyu_guest.img INFO: $ /usr/local/bin/backy2 restore f4a7e452-2ade-11ea-b7c5-525400e5d9c4 file:///home/restore/KT1_TEST_hyu_guest.img ERROR: Unexpected exception ERROR: 'Version f4a7e452-2ade-11ea-b7c5-525400e5d9c4 not found.' Traceback (most recent call last): File "/usr/local/lib/python3.6/site-packages/backy2-2.9.18-py3.6.egg/backy2/scripts/backy.py", line 583, in main func(func_args) File "/usr/local/lib/python3.6/site-packages/backy2-2.9.18-py3.6.egg/backy2/scripts/backy.py", line 42, in restore backy.restore(version_uid, target, sparse, force) File "/usr/local/lib/python3.6/site-packages/backy2-2.9.18-py3.6.egg/backy2/backy.py", line 266, in restore version = self.meta_backend.get_version(version_uid) # raise if version not exists File "/usr/local/lib/python3.6/site-packages/backy2-2.9.18-py3.6.egg/backy2/meta_backends/sql.py", line 266, in get_version raise KeyError('Version {} not found.'.format(uid)) KeyError: 'Version f4a7e452-2ade-11ea-b7c5-525400e5d9c4 not found.' INFO: Backy failed.**

wamdam commented 4 years ago

id not null closed in #35 with https://github.com/wamdam/backy2/commit/c55ea0ea71d42bdf58e7708c746c08a6b9ae98f7 .