test: User-callback

[buhtz]

Try to close #1648 creating a system test checking the output produced by a user callback while running a backup.

This PR might not be ready to merge but is read to review.

Do run the test via:

$ cd common
$ pytest test/test_plugin_usercallback.py::SystemTest -vs

[aryoda]

A backup was created one time. But each next run of that test gave me a Nothing changed, no new snapshot necessary messages. But that test do create a temporary folder and delete it after every run. I am pretty sure about that. So how can there be a no snapshot needed message?

IMHO the takeSnapshot() function is quite complicated for historical reasons (a lot of branches and the core logic "hidden" in an else block). Above observations can be explained by this:

The INFO: Take a new snapshot. Profile: 1 Main profile log output is created first:

backintime/common/snapshots.py

Lines 759 to 765 in 5cbffdf

	# take snapshot process begin
	self.setTakeSnapshotMessage(0, '...')
	self.snapshotLog.new(now)
	profile_id = self.config.currentProfile()
	profile_name = self.config.profileName()
	logger.info("Take a new snapshot. Profile: %s %s"
	%(profile_id, profile_name), self)

Then the takeSnapshot() function is called which really tries to create a snapshot:

backintime/common/snapshots.py

Line 796 in 5cbffdf

ret_val, ret_error = self.takeSnapshot(sid, now, include_folders)

If no changes were reported by rsync and the config (profile) does not enforce taking a snapshot even if nothing has changed then you see the INFO: Nothing changed, no new snapshot necessary log output:

The 2nd element of params is never set to True:

backintime/common/snapshots.py

Lines 1284 to 1286 in 5cbffdf

	if not params[1] and not self.config.takeSnapshotRegardlessOfChanges():
	self.remove(new_snapshot)
	logger.info("Nothing changed, no new snapshot necessary", self)

But that test does create a temporary folder and delete it after every run

Yes, this is the only way for BiT's takeSnapshot to check if anything has changed:

1. Create a temp folder as snapshot target (well hidden in an if):
   

   backintime/common/snapshots.py

   Lines 1185 to 1186 in 5cbffdf

   	if not new_snapshot.saveToContinue and not new_snapshot.makeDirs():
   	return [False, True]

2. Execute rsync
   

   backintime/common/snapshots.py

   Lines 1225 to 1229 in 5cbffdf

   	proc = tools.Execute(cmd,
   	callback = self.rsyncCallback, # TODO interprets the user_data in params as: list of two bool [error, changes] but params is reused as return value of this function with [changes, error]. Use a separate variable to avoid confusion!
   	user_data = params,
   	filters = (self.filterRsyncProgress,),
   	parent = self)

   
   The user_data argument contains the well-known params variable which stores the rsync result finally (error flag + changes flag).

3. If an error occurred during rsyncing or nothing has changed then the temp snapshot target folder is deleted again (self.remove(new_snapshot)):

   backintime/common/snapshots.py

   Lines 1274 to 1286 in 5cbffdf

   	# params[0] -> error?
   	if params[0]:
   	if not self.config.continueOnErrors():
   	self.remove(new_snapshot)
   	return [False, True]
   	has_errors = True
   	new_snapshot.failed = True
   	# params[1] -> changes?
   	if not params[1] and not self.config.takeSnapshotRegardlessOfChanges():
   	self.remove(new_snapshot)
   	logger.info("Nothing changed, no new snapshot necessary", self)

[buhtz]

I updated my initial comment. Read to review.

[buhtz]

Regarding to your comment in PR #1269 the question is if this tests would make you sleep better? 😄
Currently it is only a "local snapshot" without ssh involved. But the (un)mount reason signals (7 & 8) are fired also.

[buhtz]

See pylint docu about I0021. It detects useless pylint-disable comments (e.g. # pylint: disable=E0401). I assume we will use such comments a lot in the next years. But they also become useless again very often because of heavy refactoring.