bit-team / backintime

Back In Time - An easy-to-use backup tool for GNU/Linux using rsync in the back
https://backintime.readthedocs.io
GNU General Public License v2.0
2.05k stars 203 forks source link

backintime-cli fails unit tests (Gtk-WARNING ... Theme parsing error) #1409

Closed KaibutsuX closed 1 year ago

KaibutsuX commented 1 year ago

Attempting to install v1.3.3-3

Both backintime and backintime-cli fail with the same test failure.

OS: Arch/Xfce

======================================================================
FAIL: test_local_snapshot_is_successful (test.test_backintime.TestBackInTime)
end to end test - from BIT initialization through snapshot
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/kaibutsux/.cache/yay/backintime/src/backintime-1.3.3/common/test/test_backintime.py", line 147, in test_local_snapshot_is_successful
    self.assertRegex(filtered_log_output, re.compile(r'''INFO: Lock
AssertionError: Regex didn't match: 'INFO: Lock\nINFO: Take a new snapshot. Profile: 1 Main profile\nINFO: Call rsync to take the snapshot\nINFO: Save config file\nINFO: Save permissions\nINFO: Create info file\nINFO: Unlock\n' not found in "INFO: Lock\nINFO: Take a new snapshot. Profile: 1 Main profile\nINFO: Call rsync to take the snapshot\nINFO: Save config file\nINFO: Save permissions\nINFO: Create info file\n\n(python:2194333): Gtk-WARNING **: 10:20:50.946: Theme parsing error: gtk.css:4419:85: '/*' in comment block\n\n(python:2194333): Gtk-WARNING **: 10:20:50.946: Theme parsing error: gtk.css:4512:64: '/*' in comment block\nINFO: Unlock\n"

----------------------------------------------------------------------
Ran 3 tests in 3.388s

FAILED (failures=1, skipped=1)
make: *** [Makefile:570: unittest] Error 1
==> ERROR: A failure occurred in check().
    Aborting...
 -> error making: backintime (backintime-cli backintime)
buhtz commented 1 year ago

Just to improve reading I reformatted the output

AssertionError: Regex didn't match:
    'INFO: Lock\n
     INFO: Take a new snapshot. Profile: 1 Main profile\n
     INFO: Call rsync to take the snapshot\n
     INFO: Save config file\n
     INFO: Save permissions\n
     INFO: Create info file\n
     INFO: Unlock\n'

     not found in

     "INFO: Lock\n
      INFO: Take a new snapshot. Profile: 1 Main profile\n
      INFO: Call rsync to take the snapshot\n
      INFO: Save config file\n
      INFO: Save permissions\n
      INFO: Create info file\n
      \n
      (python:2194333): Gtk-WARNING **: 10:20:50.946: Theme parsing error: gtk.css:4419:85: '/*' in comment block\n
      \n
      (python:2194333): Gtk-WARNING **: 10:20:50.946: Theme parsing error: gtk.css:4512:64: '/*' in comment block\n
      INFO: Unlock\n"

This (and some other) of the unit tests are of low quality. Using fulltext-regex isn't usefull.

No matter about that. I wonder why a Gtk-error is involved here. We are using Qt. I'm confused with that. But I'm also not a pro with desktop environments and GUI libs.

Would be nice to know what is going on here. But I think it isn't a critical bug with BIT. Waiting for some feedback and other opinions before decide what to do about it.

KaibutsuX commented 1 year ago

Yeah, the test should probably only look for the expected and ignore anything else. I don't know why I get gtk warnings, but I'm not interested in going down that rabbit hole.

aryoda commented 1 year ago

I once had a similar issue in the unit tests with unwanted (to be ignored) DBus output:

https://github.com/bit-team/backintime/blob/e22c7f253fa048fab9119f4cbea34c0fa8d1aba6/common/test/test_backintime.py#L132-L147

Perhaps it is the time now to create a flexible reusable "filter expected output" function for unit tests for such cases...

KaibutsuX commented 1 year ago

I would vote for that approach with a function like OutputContainsLines()

KaibutsuX commented 1 year ago

Add PR: https://github.com/bit-team/backintime/pull/1411

buhtz commented 1 year ago

Does anyone has an idea why Gtk is involved here? Does Qt do use Gtk elements?

buhtz commented 1 year ago

Dear @KaibutsuX , we can not reproduce the problem on our site. So please do us a favor.

Try the backintime-git package from Arch and tell us if you can reproduce it with that also. I hope you can.

After that step please checkout the code of my PR #1412. That PR is not commited yet. So you have to use the code from my forked repo.

Feel free to ask back.

KaibutsuX commented 1 year ago

Yes, Aur is where I install from, that is how I initially came across the problem.

But to be sure, I did:

git clone https://aur.archlinux.org/backintime-git.git && cd backintime-git
makepkg
cd src/backintime/common && pytest

*** Same regex error with gtk warnings in it ***

Cloned from your repo on branch 1409test still fails:

==================================================== short test summary info =====================================================
FAILED test/test_backintime.py::TestBackInTime::test_local_snapshot_is_successful - AssertionError: Regex didn't match: 'INFO: Lock\nINFO: Take a new snapshot. Profile: 1 Main profile\nINFO: Call rsync to take...
=========================================== 1 failed, 310 passed, 45 skipped in 32.84s ===========================================

AssertionError:

E   AssertionError: Regex didn't match: 'INFO: Lock\nINFO: Take a new snapshot. Profile: 1 Main profile\nINFO: Call rsync to take the snapshot\nINFO: Save config file\nINFO: Save permissions\nINFO: Create info file\nINFO: Unlock\n' not found in 'INFO: Lock\nINFO: Take a new snapshot. Profile: 1 Main profile\nINFO: Call rsync to take the snapshot\nINFO: Save config file\nINFO: Save permissions\nINFO: Create info file\n\n\nINFO: Unlock\n'

test/test_backintime.py:170: AssertionError
buhtz commented 1 year ago

Yes, Aur is where I install from, that is how I initially came across the problem.

There are multiple backintime packages on AUR. But testing it with our git repo is the best choice.

Same regex error with gtk warnings in it

Thanks a lot for testing this. I'll have a look into it.

Repeating your error output in an easier format

E   AssertionError: Regex didn't match: '
    INFO: Lock\n
    INFO: Take a new snapshot. Profile: 1 Main profile\n
    INFO: Call rsync to take the snapshot\n
    INFO: Save config file\n
    INFO: Save permissions\n
    INFO: Create info file\n
    INFO: Unlock\n

    'not found in '

    INFO: Lock\n
    INFO: Take a new snapshot. Profile: 1 Main profile\n
    INFO: Call rsync to take the snapshot\n
    INFO: Save config file\nINFO: Save permissions\n
    INFO: Create info file\n
    \n
    \n
    INFO: Unlock\n'
buhtz commented 1 year ago

Dear @KaibutsuX , can you pull again from my repo and test again. I updated my PR.

KaibutsuX commented 1 year ago

After pulling:

E   AssertionError: Regex didn't match: 'INFO: Lock\nINFO: Take a new snapshot. Profile: 1 Main profile\nINFO: Call rsync to take the snapshot\nINFO: Save config file\nINFO: Save permissions\nINFO: Create info file\nINFO: Unlock\n' not found in 'INFO: Lock\nINFO: Take a new snapshot. Profile: 1 Main profile\nINFO: Call rsync to take the snapshot\nINFO: Save config file\nINFO: Save permissions\nINFO: Create info file\n\n\nINFO: Unlock\n'

test/test_backintime.py:176: AssertionError
==================================================== short test summary info =====================================================
FAILED test/test_backintime.py::TestBackInTime::test_local_snapshot_is_successful - AssertionError: Regex didn't match: 'INFO: Lock\nINFO: Take a new snapshot. Profile: 1 Main profile\nINFO: Call rsync to take...
=========================================== 1 failed, 310 passed, 45 skipped in 38.21s ===========================================
E   AssertionError: Regex didn't match: 'INFO: Lock
INFO: Take a new snapshot. Profile: 1 Main profile
INFO: Call rsync to take the snapshot
INFO: Save config file
INFO: Save permissions
INFO: Create info file
INFO: Unlock
' not found in 'INFO: Lock
INFO: Take a new snapshot. Profile: 1 Main profile
INFO: Call rsync to take the snapshot
INFO: Save config file
INFO: Save permissions
INFO: Create info file

INFO: Unlock
buhtz commented 1 year ago

Thanks a lot for your patience. Can you try it again please?

EDIT: Sorry, my comment was a bit short. I think I found the problem and updated my PR.

KaibutsuX commented 1 year ago

Looks like that fixed it

aryoda commented 1 year ago

@KaibutsuX Is suspect that the gtk.css of your active theme is causing this warning and I am trying to find the gtk.css file and open an issue at the developer's site.

Could please show us the output of

python3 -c "from PyQt5.QtGui import QIcon; from PyQt5.QtWidgets import QSystemTrayIcon,QApplication,QStyleFactory; app = QApplication(['']); print(f'QT style: {app.style().objectName()}'); print(f'QT supported styles: {QStyleFactory.keys()}')"

because I need to know the active style to find the specific folder containing the gtk.css of this theme...

The file itself is located in the /usr/share/themes/<scheme name>/gtk* folder then and the gtk.css itself contains only an @import statement to load another css from a resource file, e.g.:

@import url("resource:///com/ubuntu/themes/Yaru-dark/3.0/gtk.css");

... loads this css from the resource file:

gresource extract /usr/share/themes/Yaru-dark/gtk-3.0/gtk.gresource /com/ubuntu/themes/Yaru-dark/3.0/gtk.css
KaibutsuX commented 1 year ago
python3 -c "from PyQt5.QtGui import QIcon; from PyQt5.QtWidgets import QSystemTrayIcon,QApplication,QStyleFactory; app = QApplication(['']); print(f'QT style: {app.style().objectName()}'); print(f'QT supported styles: {QStyleFactory.keys()}')"

(python3:1119780): Gtk-WARNING **: 19:36:32.381: Theme parsing error: gtk.css:4419:85: '/*' in comment block

(python3:1119780): Gtk-WARNING **: 19:36:32.382: Theme parsing error: gtk.css:4512:64: '/*' in comment block
QT style: fusion
QT supported styles: ['Windows', 'Fusion']

I don't have any results when I grep -ir for "fusion" in /usr/share/themes/*

aryoda commented 1 year ago

QT style: fusion QT supported styles: ['Windows', 'Fusion'] I don't have any results when I grep -ir for "fusion" in /usr/share/themes/*

THX, fusion is a Qt5-built-in style and therefor no gtk theme.

I think I give up here since it would require file access monitoring with strace now which may omit the spawned sub processes of BiT :-(

THX for giving it a try anyhow!

aryoda commented 1 year ago

python3 -c "from PyQt5.QtGui import QIcon; from PyQt5.QtWidgets import QSystemTrayIcon,QApplication,QStyleFactory; app = QApplication(['']); print(f'QT style: {app.style().objectName()}'); print(f'QT supported styles: {QStyleFactory.keys()}')"

(python3:1119780): Gtk-WARNING *: 19:36:32.381: Theme parsing error: gtk.css:4419:85: '/' in comment block

BTW: My Python test code shows that even without BiT the Gtk-Warning appears for some reasons by just a few lines of Qt5-related python code ;-)

aryoda commented 1 year ago

@KaibutsuX Oh lucky day, I have just realized that the fact that my small code example above reproduced the Gtk-WARNING on your computer (not mine) makes it is easier to find the faulty gtk.css.

Could you please execute this in console

strace python3 -c "from PyQt5.QtGui import QIcon; from PyQt5.QtWidgets import QSystemTrayIcon,QApplication,QStyleFactory; app = QApplication(['']); print(f'QT style: {app.style().objectName()}'); print(f'QT supported styles: {QStyleFactory.keys()}')" >test.log 2>&1

and open the test.log file in a text editor (contains about 4000 - 5000 lines ;-)

Then either upload the file here or

This gtk.css (or even more than one) is the culprit...

Example from my computer: The last line opens a gtk.css and shows the full path:

access("/usr/local/share/themes/Yaru/gtk-3.0/gtk.css", F_OK) = -1 ENOENT (No such file or directory)
access("/usr/share/themes/Yaru/gtk-3.24/gtk.css", F_OK) = -1 ENOENT (No such file or directory)
access("/usr/share/themes/Yaru/gtk-3.22/gtk.css", F_OK) = -1 ENOENT (No such file or directory)
access("/usr/share/themes/Yaru/gtk-3.20/gtk.css", F_OK) = 0
openat(AT_FDCWD, "/usr/share/themes/Yaru/gtk-3.20/gtk.css", O_RDONLY) = 12
KaibutsuX commented 1 year ago

Ran command. No occurences of -i gtk anywhere in my log file. test.log

aryoda commented 1 year ago

@KaibutsuX

Ran command. No occurences of -i gtk anywhere in my log file.

Please forgive me, I did accidentally delete a "Q" in the command so instead of QSystemTrayIcon it was SystemTrayIcon...

I have fixed above command and here it is again (tested on my computer):

strace python3 -c "from PyQt5.QtGui import QIcon; from PyQt5.QtWidgets import QSystemTrayIcon,QApplication,QStyleFactory; app = QApplication(['']); print(f'QT style: {app.style().objectName()}'); print(f'QT supported styles: {QStyleFactory.keys()}')" >test.log 2>&1

Could you please try it again and provide the test.log here? THX a lot :-)

buhtz commented 1 year ago

Fixed on dev by PR #1412 . Will released with next 1.3.4.

KaibutsuX commented 1 year ago

test.log

buhtz commented 1 year ago

Sorry, I was a bit to quick with closing this.

aryoda commented 1 year ago

According to the log this css file causes the warning:

~/.local/share/themes/PRO-dark-XFCE-4.14/gtk-3.0/gtk.css

The warning has been reported in 2018 and is still open, see this issue and a proposed work-around by manually editing the css file:

https://github.com/paullinuxthemer/PRO-Dark-XFCE-Edition/issues/2

@KaibutsuX Perhaps you fix the theme manually, try to find an update/fork or switch to another similar theme.

THX a lot for your support to identify the root cause!

I think the issue can now really be closed...