XIO: fatal IO error 0 (Success) on X server ":1001"

[ghisvail]

I tried to run the test suite of ltfatpy using pytest-xvfb but it fails with the following error:

XIO:  fatal IO error 0 (Success) on X server ":1001"
      after 158 requests (158 known processed) with 1 events remaining.

The test suite succeeds if I call pytest with xvfb-run -a and the verbose log indicates that no test has failed in either cases.

Any idea what could cause this?

[The-Compiler]

Hmm, that's odd, especially the "Success" part 😉

Does it happen at the very end of the testsuite by any chance? What GUI toolkit are you using there?

[ghisvail]

Does it happen at the very end of the testsuite by any chance?

Yep

What GUI toolkit are you using there?

TkInter (matplotlib TkAgg backend)

[The-Compiler]

Hmm, it might be the same thing as #1 then. Unfortunately I never was able to find out what's causing it exactly - and since it works fine for Qt5, I unfortunately don't have the time to dig further currently - too busy with my main project, qutebrowser 😆

Sorry! I'll let you know if I (or someone else) figure out more somehow though.

[ghisvail]

since it works fine for Qt5

I can confirm that pytest-xvfb has worked for all Qt5 testing I have used it with so far (mainly for CI testing of Debian packages). I have since started to advocate its wider usage in Qt5-based projects I am interacting with, such as the spyder project.

too busy with my main project, qutebrowser

I read the recent announcement on the Python planet. Congrats and best of luck with the project 👍

Sorry! I'll let you know if I (or someone else) figure out more somehow though

I am afraid I won't be of any help. It was mostly a heads-up in case someone else had trouble using it with a different UI toolkit. Worst case, we still have good old manual calls to xvfb-run which worked in my case.

[twmr]

I have the following test that allows me to get the same "success" message at the end of pytest:

from PyQt4 import QtGui, QtCore


class Window(QtGui.QWidget):
    def __init__(self):
        QtGui.QWidget.__init__(self)
        self.button = QtGui.QPushButton('Test', self)
        self.button.clicked.connect(self.handleButton)
        layout = QtGui.QVBoxLayout(self)
        layout.addWidget(self.button)

    def handleButton(self):
        print('Hello World')


def test_qtgui(qtbot, capsys):
    w = Window()
    qtbot.mouseClick(w.button, QtCore.Qt.LeftButton)
    out, err = capsys.readouterr()
    assert 'Hello World' in out

pytest test_gui.py -v 
===================================================================================================== test session starts =====================================================================================================
platform linux -- Python 3.6.4, pytest-3.3.2, py-1.5.2, pluggy-0.6.0 -- /home/thomas/miniconda/envs/pyqttests/bin/python
cachedir: .cache
PyQt4 4.11.4 -- Qt runtime 4.8.7 -- Qt compiled 4.8.7
rootdir: /home/thomas/gitrepos/pyqttest, inifile:
plugins: xvfb-1.0.0, qt-2.3.1
collected 1 item                                                                                                                                                                                                              

test_gui.py::test_qtgui PASSED                                                                                                                                                                                          [100%]

================================================================================================== 1 passed in 0.07 seconds ===================================================================================================
python: Fatal IO error 0 (Success) on X server :1005.

[The-Compiler]

FWIW I see something like this as well with Qt5 nowadays (I think it was with the new PyQt exit scheme). Interestingly, it only happens when I run a subset of my tests, not when I run all of them - so there might be something in there that fixes it.

[rcxwhiz]

I just ran into the same issue with PyQt5. I'm getting it when I'm repeatedly opening and closing a dialog which performs threaded tasks, but the tasks and threads are being cleaned up before the dialog closes and the main window freezes.

[rcxwhiz]

FWIW my issue was with a thread being closed and improperly closing sqlite3 resources

[The-Compiler]

For qutebrowser tests, it seems to depend on how much time is passing after the widget tests have finished. For example, tox -e py38-pyqt515-cov -- tests/unit/misc/test_miscwidgets.py crashes, so does tests/unit/misc/test_miscwidgets.py tests/unit/utils/test_utils.py, but tox -e py38-pyqt515-cov -- tests/unit/misc/test_miscwidgets.py tests/unit/utils/ works.

Maybe we need to change something so we close the server after pytest-qt has had a chance to clean up widgets?

Also, it looks like it only happens with Qt 5.13 and newer - no issues with Qt 5.7 to 5.12...

[petercorke]

I'm having a similar problem using TkAgg backend. The unit tests all run fine, it's in the cleanup. Using latest version of matplotlib etc.

[The-Compiler]

@petercorke Any chance you can show things (the exact output, ideally the code triggering it) instead of describing them? That might help in tracking this down.

[petercorke]

The project is https://github.com/petercorke/spatialmath-python

and the raw log is:

2020-08-19T06:52:56.4452400Z env:
2020-08-19T06:52:56.4452578Z pythonLocation: /opt/hostedtoolcache/Python/3.7.8/x64
2020-08-19T06:52:56.4452696Z MPLBACKEND: TkAgg
2020-08-19T06:52:56.4452858Z ##[endgroup]
2020-08-19T06:53:03.1543067Z ============================= test session starts ==============================
2020-08-19T06:53:03.1545002Z platform linux -- Python 3.7.8, pytest-6.0.1, py-1.9.0, pluggy-0.13.1
2020-08-19T06:53:03.1545596Z rootdir: /home/runner/work/spatialmath-python/spatialmath-python
2020-08-19T06:53:03.1546170Z plugins: timeout-1.4.2, cov-2.10.1, xvfb-2.0.0
2020-08-19T06:53:03.1546435Z timeout: 50.0s
2020-08-19T06:53:03.1546665Z timeout method: thread
2020-08-19T06:53:03.1546953Z timeout func_only: False
2020-08-19T06:53:03.1550184Z collected 151 items
2020-08-19T06:53:03.1550291Z
2020-08-19T06:53:03.7592137Z spatialmath/test_pose2d.py ..in log
2020-08-19T06:53:03.9149222Z ....... 17 deg
2020-08-19T06:53:03.9403330Z .......in log
2020-08-19T06:53:03.9502632Z .in log
2020-08-19T06:53:03.9571865Z .t = 0.15, 0.72; -43 deg
2020-08-19T06:53:04.0336046Z ........
2020-08-19T06:53:04.1289054Z spatialmath/test_pose3d.py ........ rpy/zyx = 17, 0, 0 deg
2020-08-19T06:53:04.1961094Z ............
2020-08-19T06:53:04.3084803Z spatialmath/test_quaternion.py ..........................
2020-08-19T06:53:04.3912650Z spatialmath/test_twist2d.py ............
2020-08-19T06:53:04.4234089Z spatialmath/test_twist3d.py .............
2020-08-19T06:53:04.4338518Z spatialmath/base/test_argcheck.py .....
2020-08-19T06:53:04.4508418Z spatialmath/base/test_quaternions.py ....
2020-08-19T06:53:11.6089887Z spatialmath/base/test_transforms.py .............................................
2020-08-19T06:53:11.6090129Z
2020-08-19T06:53:11.6090380Z =============================== warnings summary ===============================
2020-08-19T06:53:11.6090796Z spatialmath/test_pose2d.py::TestSO2::test_conversions
2020-08-19T06:53:11.6091080Z /opt/hostedtoolcache/Python/3.7.8/x64/lib/python3.7/importlib/_bootstrap.py:219: RuntimeWarning: numpy.ufunc size changed, may indicate binary incompatibility. Expected 192 from C header, got 216 from PyObject
2020-08-19T06:53:11.6091347Z return f(*args, **kwds)
2020-08-19T06:53:11.6091434Z
2020-08-19T06:53:11.6092392Z -- Docs: https://docs.pytest.org/en/stable/warnings.html
2020-08-19T06:53:11.6092651Z ======================= 151 passed, 1 warning in 12.08s ========================
2020-08-19T06:53:11.6095921Z XIO: fatal IO error 0 (Success) on X server ":0"
2020-08-19T06:53:11.6096325Z after 3611 requests (3608 known processed) with 0 events remaining.
2020-08-19T06:53:11.6179884Z ##[error]Process completed with exit code 1.
2020-08-19T06:53:11.6236503Z Post job cleanup.

the last test, spatialmath/base/test_transforms.py, does a bunch of matplotlib 3D plots and 3D animations using FuncAnimation. All graphical windows are closed after the tests using tearDownClass() handler.

The tests all pass, but it looks like the error occurs as pytest is exiting up. From what I can see of the code, a SIGTERM is sent to xvfb but maybe this error is caused by the pipe closing before it dies?? This is running on some version of Ubuntu provided by GH, apparently "latest". I'm happy to add debugs if you can advise what to add. Thanks.

[The-Compiler]

@petercorke Thanks! It might take me a while until I get the time to get back to this.

[petercorke]

@jhavl and I did some digging on this. The error happens in unconfigure, which is calling code in pyvirtualdisplay package. The error happens as soon as we attempt to terminate the Xvfb subprocess when THERE ARE STILL OPEN WINDOWS. This is really more an Xvfb issue than a pytest-xvfb issue, but there's lots of people in forums asking about this bug. The lesson, close all your windows after each unit test.

[The-Compiler]

I still haven't had a chance to dig into this more I'm afraid - thanks for the useful information though, @petercorke! If that's all there is to it, I might be able to add some code to pytest-xvfb which force-closes all windows before pytest exits.

I now found a way to reproduce this when running the entire testsuite of qutebrowser (rather than just a part):

diff --git a/tests/unit/utils/test_utils.py b/tests/unit/utils/test_utils.py
index d674dd694..bbeeff5cc 100644
--- a/tests/unit/utils/test_utils.py
+++ b/tests/unit/utils/test_utils.py
@@ -706,9 +706,9 @@ def test_set_unsupported_selection(self, clipboard_mock):
         (False, 'clipboard', 'fake text', 'fake text'),
         (False, 'clipboard', 'füb', r'f\u00fcb'),
     ])
-    def test_set_logging(self, clipboard_mock, caplog, selection, what,
+    def test_set_logging(self, monkeypatch, clipboard_mock, caplog, selection, what,
                          text, expected):
-        utils.log_clipboard = True
+        monkeypatch.setattr(utils, 'log_clipboard', True)
         utils.set_clipboard(text, selection=selection)
         assert not clipboard_mock.setText.called
         expected = 'Setting fake {}: "{}"'.format(what, expected)

Why? No idea.

[JSS95]

Encountered same issue. It happened when I added a long test using QMediaPlayer in my project.
Fixed by adding qtbot.addWidget(widget) at the beginning and widget.close() at the end of every test function.

(EDIT)
Closing the widget wasn't what fixed this. The test file that broke my build must be the LAST FILE run by pytest!

Here are the build results, test_processor.py being the culprit.

Order of the test functions in the file did not matter.

(EDIT)
In my case, the issue is somehow related to QVideoFrame.toImage of the video frame I manually constructed and modified the bits. It must be related to the memory.

[The-Compiler]

This seems to reliably reproduce it (minimized from pytest-dev/pytest-qt#490):

import pytest

import sys
from PyQt5.QtWebEngineWidgets import QWebEnginePage
from PyQt5.QtWidgets import QWidget, QApplication

app = QApplication(sys.argv)

def test_widget():
    widget = QWidget()
    widget.show()

Most notably, removing the QtWebEngine import fixes the problem?! Using xvfb-run also still works correctly. I'm still puzzled.

This is with Python 3.11.3 and:

Package           Version
----------------- -------
iniconfig         2.0.0
packaging         23.1
pip               23.0
pluggy            1.0.0
PyQt5             5.15.9
PyQt5-Qt5         5.15.2
PyQt5-sip         12.12.1
PyQtWebEngine     5.15.6
PyQtWebEngine-Qt5 5.15.2
pytest            7.3.1
pytest-xvfb       2.0.0
PyVirtualDisplay  3.0
setuptools        67.1.0
wheel             0.38.4

[The-Compiler]

Plain Python reproducer:

import sys
from PyQt5.QtWebEngineWidgets import QWebEnginePage
from PyQt5.QtWidgets import QWidget, QApplication

from pyvirtualdisplay import Display

with Display() as disp:
    app = QApplication(sys.argv)
    widget = QWidget()
    widget.show()

and a quick hack without PyVirtualDisplay:

import os
import sys
import time
import subprocess

from PyQt5.QtWebEngineWidgets import QWebEnginePage
from PyQt5.QtWidgets import QWidget, QApplication

proc = subprocess.Popen(["Xvfb", ":42"])
os.environ["DISPLAY"] = ":42"
time.sleep(1)

app = QApplication(sys.argv)
widget = QWidget()
widget.show()

print("done")
proc.terminate()

I suppose the problem is that the QApplication (or PyQt) does some kind of cleanup (like disconnecting from the X server?) when the process exits. However, if we start Xvfb from inside Python, and we want to terminate it cleanly, it follows that Xvfb will always be killed before the process where the QApplication lives exits.

It's still unclear to me why this only happens sometimes (in the qutebrowser testsuite I only see it when running individual tests, not when running the entire testsuite) - or why it only happens when importing QtWebEngine (might be registering some kind of exit hooks?).

Sadly, even using atexit doesn't help things:

import os
import sys
import time
import subprocess
import atexit

from PyQt5.QtWebEngineWidgets import QWebEnginePage
from PyQt5.QtWidgets import QWidget, QApplication

proc = subprocess.Popen(["Xvfb", ":42"])
atexit.register(proc.terminate)

os.environ["DISPLAY"] = ":42"
time.sleep(1)

app = QApplication(sys.argv)
widget = QWidget()
widget.show()

print("done")

[sanjacob]

You are probably right about the exit hooks. I found that simply importing the dependencies after having registered the xvfb exit hook works.

import os
import sys
import time
import subprocess
import atexit

proc = subprocess.Popen(["Xvfb", ":42"])
atexit.register(proc.terminate)

from PyQt5.QtWebEngineWidgets import QWebEnginePage
from PyQt5.QtWidgets import QWidget, QApplication

os.environ["DISPLAY"] = ":42"
time.sleep(1)

app = QApplication(sys.argv)
widget = QWidget()
widget.show()

print("done")

Note that simply changing the order of these lines makes all the difference:
as seen in this diff.

It makes sense if pyqt's hooks are also using atexit, since per the documentation they will run in reverse order as they were registered.

[sanjacob]

I don't know a lot about pytest, but I guess this can be solved by registering this exit hook before the rest of the imports, perhaps by creating a dummy module which must be imported before any other dependencies. However, I am not sure how to reconcile this with the pytest framework.

[The-Compiler]

Using atexit at import time (rather than pytest_unconfigure) to stop Xvfb actually seems to do the trick!

I have a few small things I want to look at, and then it's time for a v3.0.0 release with this (hopefully) finally fixed for everyone.

Thanks @jacobszpz for the initial reproducer and the ideas around atexit!

[The-Compiler]

v3.0.0 has been released! I added a test for the reproducer involving QtWebEngine, but if anyone else here who was still seeing this could confirm it's now gone, that'd be great.