1# vim: ft=python fileencoding=utf-8 sts=4 sw=4 et:
2
3# Copyright 2015-2021 Florian Bruhin (The Compiler) <mail@qutebrowser.org>
4#
5# This file is part of qutebrowser.
6#
7# qutebrowser is free software: you can redistribute it and/or modify
8# it under the terms of the GNU General Public License as published by
9# the Free Software Foundation, either version 3 of the License, or
10# (at your option) any later version.
11#
12# qutebrowser is distributed in the hope that it will be useful,
13# but WITHOUT ANY WARRANTY; without even the implied warranty of
14# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
15# GNU General Public License for more details.
16#
17# You should have received a copy of the GNU General Public License
18# along with qutebrowser.  If not, see <https://www.gnu.org/licenses/>.
19
20"""Fixtures to run qutebrowser in a QProcess and communicate."""
21
22import pathlib
23import re
24import sys
25import time
26import datetime
27import logging
28import tempfile
29import contextlib
30import itertools
31import collections
32import json
33
34import yaml
35import pytest
36from PyQt5.QtCore import pyqtSignal, QUrl, QPoint
37from PyQt5.QtGui import QImage, QColor
38
39from qutebrowser.misc import ipc
40from qutebrowser.utils import log, utils, javascript
41from helpers import testutils
42from end2end.fixtures import testprocess
43
44
45instance_counter = itertools.count()
46
47
48def is_ignored_qt_message(pytestconfig, message):
49    """Check if the message is listed in qt_log_ignore."""
50    regexes = pytestconfig.getini('qt_log_ignore')
51    for regex in regexes:
52        if re.search(regex, message):
53            return True
54    return False
55
56
57def is_ignored_lowlevel_message(message):
58    """Check if we want to ignore a lowlevel process output."""
59    ignored_messages = [
60        # https://travis-ci.org/qutebrowser/qutebrowser/jobs/157941720
61        # ???
62        'Xlib: sequence lost*',
63        # Started appearing with Qt 5.8...
64        # https://patchwork.sourceware.org/patch/10255/
65        ("*_dl_allocate_tls_init: Assertion `listp->slotinfo[cnt].gen <= "
66         "GL(dl_tls_generation)' failed!*"),
67        # ???
68        'getrlimit(RLIMIT_NOFILE) failed',
69        'libpng warning: Skipped (ignored) a chunk between APNG chunks',
70        # Travis CI containers don't have a /etc/machine-id
71        ('*D-Bus library appears to be incorrectly set up; failed to read '
72         'machine uuid: Failed to open "/etc/machine-id": No such file or '
73         'directory'),
74        'See the manual page for dbus-uuidgen to correct this issue.',
75        # Travis CI macOS:
76        # 2017-09-11 07:32:56.191 QtWebEngineProcess[5455:28501] Couldn't set
77        # selectedTextBackgroundColor from default ()
78        "* Couldn't set selectedTextBackgroundColor from default ()",
79        # Mac Mini:
80        # <<<< VTVideoEncoderSelection >>>>
81        # VTSelectAndCreateVideoEncoderInstanceInternal: no video encoder
82        # found for 'avc1'
83        #
84        # [22:32:03.636] VTSelectAndCreateVideoEncoderInstanceInternal
85        # signalled err=-12908 (err) (Video encoder not available) at
86        # /SourceCache/CoreMedia_frameworks/CoreMedia-1562.240/Sources/
87        # VideoToolbox/VTVideoEncoderSelection.c line 1245
88        #
89        # [22:32:03.636] VTCompressionSessionCreate signalled err=-12908 (err)
90        # (Could not select and open encoder instance) at
91        # /SourceCache/CoreMedia_frameworks/CoreMedia-1562.240/Sources/
92        # VideoToolbox/VTCompressionSession.c # line 946
93        '*VTSelectAndCreateVideoEncoderInstanceInternal*',
94        '*VTSelectAndCreateVideoEncoderInstanceInternal*',
95        '*VTCompressionSessionCreate*',
96        # During shutdown on AppVeyor:
97        # https://ci.appveyor.com/project/qutebrowser/qutebrowser/build/master-2089/job/or4tbct1oeqsfhfm
98        'QNetworkProxyFactory: factory 0x* has returned an empty result set',
99        # Qt 5.10 with debug Chromium
100        # [1016/155149.941048:WARNING:stack_trace_posix.cc(625)] Failed to open
101        # file: /home/florian/#14687139 (deleted)
102        #   Error: No such file or directory
103        '  Error: No such file or directory',
104        # Qt 5.7.1
105        'qt.network.ssl: QSslSocket: cannot call unresolved function *',
106        # Qt 5.11
107        # DevTools listening on ws://127.0.0.1:37945/devtools/browser/...
108        'DevTools listening on *',
109        # /home/travis/build/qutebrowser/qutebrowser/.tox/py36-pyqt511-cov/lib/
110        # python3.6/site-packages/PyQt5/Qt/libexec/QtWebEngineProcess:
111        # /lib/x86_64-linux-gnu/libdbus-1.so.3: no version information
112        # available (required by /home/travis/build/qutebrowser/qutebrowser/
113        # .tox/py36-pyqt511-cov/lib/python3.6/site-packages/PyQt5/Qt/libexec/
114        # ../lib/libQt5WebEngineCore.so.5)
115        '*/QtWebEngineProcess: /lib/x86_64-linux-gnu/libdbus-1.so.3: no '
116        'version information available (required by '
117        '*/libQt5WebEngineCore.so.5)',
118
119        # hunter and Python 3.9
120        # https://github.com/ionelmc/python-hunter/issues/87
121        '<frozen importlib._bootstrap>:*: RuntimeWarning: builtins.type size changed, '
122        'may indicate binary incompatibility. Expected 872 from C header, got 880 from '
123        'PyObject',
124    ]
125    return any(testutils.pattern_match(pattern=pattern, value=message)
126               for pattern in ignored_messages)
127
128
129def is_ignored_chromium_message(line):
130    msg_re = re.compile(r"""
131        \[
132        (\d+:\d+:)?  # Process/Thread ID
133        \d{4}/[\d.]+:  # MMDD/Time
134        (?P<loglevel>[A-Z]+):  # Log level
135        [^ :]+    # filename / line
136        \]
137        \ (?P<message>.*)  # message
138    """, re.VERBOSE)
139    match = msg_re.fullmatch(line)
140    if match is None:
141        return False
142
143    if match.group('loglevel') == 'INFO':
144        return True
145
146    message = match.group('message')
147    ignored_messages = [
148        # [27289:27289:0605/195958.776146:INFO:zygote_host_impl_linux.cc(107)]
149        # No usable sandbox! Update your kernel or see
150        # https://chromium.googlesource.com/chromium/src/+/master/docs/linux_suid_sandbox_development.md
151        # for more information on developing with the SUID sandbox. If you want
152        # to live dangerously and need an immediate workaround, you can try
153        # using --no-sandbox.
154        'No usable sandbox! Update your kernel or see *',
155        # [30981:30992:0605/200633.041364:ERROR:cert_verify_proc_nss.cc(918)]
156        # CERT_PKIXVerifyCert for localhost failed err=-8179
157        'CERT_PKIXVerifyCert for localhost failed err=*',
158        # [1:1:0914/130428.060976:ERROR:broker_posix.cc(41)] Invalid node
159        # channel message
160        'Invalid node channel message',
161
162        # Qt 5.9.3
163        # [30217:30229:1124/141512.682110:ERROR:
164        # cert_verify_proc_openssl.cc(212)]
165        # X509 Verification error self signed certificate : 18 : 0 : 4
166        'X509 Verification error self signed certificate : 18 : 0 : 4',
167        # Qt 5.13
168        # [27789:27805:0325/111821.127349:ERROR:ssl_client_socket_impl.cc(962)]
169        # handshake failed; returned -1, SSL error code 1, net_error -202
170        'handshake failed; returned -1, SSL error code 1, net_error -202',
171
172        # Not reproducible anymore?
173
174        'Running without the SUID sandbox! *',
175        'Unable to locate theme engine in module_path: *',
176        'Could not bind NETLINK socket: Address already in use',
177        # Started appearing in sessions.feature with Qt 5.8...
178        'Invalid node channel message *',
179        # Makes tests fail on Quantumcross' machine
180        ('CreatePlatformSocket() returned an error, errno=97: Address family'
181         'not supported by protocol'),
182
183        # Qt 5.9 with debug Chromium
184
185        # [28121:28121:0605/191637.407848:WARNING:resource_bundle_qt.cpp(114)]
186        # locale_file_path.empty() for locale
187        'locale_file_path.empty() for locale',
188        # [26598:26598:0605/191429.639416:WARNING:audio_manager.cc(317)]
189        # Multiple instances of AudioManager detected
190        'Multiple instances of AudioManager detected',
191        # [25775:25788:0605/191240.931551:ERROR:quarantine_linux.cc(33)]
192        # Could not set extended attribute user.xdg.origin.url on file
193        # /tmp/pytest-of-florian/pytest-32/test_webengine_download_suffix0/
194        # downloads/download.bin: Operation not supported
195        ('Could not set extended attribute user.xdg.* on file *: '
196         'Operation not supported*'),
197        # [5947:5947:0605/192837.856931:ERROR:render_process_impl.cc(112)]
198        # WebFrame LEAKED 1 TIMES
199        'WebFrame LEAKED 1 TIMES',
200
201        # Qt 5.10 with debug Chromium
202        # [1016/155149.941048:WARNING:stack_trace_posix.cc(625)] Failed to open
203        # file: /home/florian/#14687139 (deleted)
204        #   Error: No such file or directory
205        'Failed to open file: * (deleted)',
206
207        # macOS on Travis
208        # [5140:5379:0911/063441.239771:ERROR:mach_port_broker.mm(175)]
209        # Unknown process 5176 is sending Mach IPC messages!
210        'Unknown process * is sending Mach IPC messages!',
211        # [5205:44547:0913/142945.003625:ERROR:node_controller.cc(1268)] Error
212        # on receiving Mach ports FFA56F125F699ADB.E28E252911A8704B. Dropping
213        # message.
214        'Error on receiving Mach ports *. Dropping message.',
215
216        # [2734:2746:1107/131154.072032:ERROR:nss_ocsp.cc(591)] No
217        # URLRequestContext for NSS HTTP handler. host: ocsp.digicert.com
218        'No URLRequestContext for NSS HTTP handler. host: *',
219
220        # https://bugreports.qt.io/browse/QTBUG-66661
221        # [23359:23359:0319/115812.168578:WARNING:
222        # render_frame_host_impl.cc(2744)] OnDidStopLoading was called twice.
223        'OnDidStopLoading was called twice.',
224
225        # [30412:30412:0323/074933.387250:ERROR:node_channel.cc(899)] Dropping
226        # message on closed channel.
227        'Dropping message on closed channel.',
228        # [2204:1408:0703/113804.788:ERROR:
229        # gpu_process_transport_factory.cc(1019)] Lost UI shared context.
230        'Lost UI shared context.',
231
232        # [20870:20908:0607/081717.652282:ERROR:block_files.cc(465)] Failed to
233        # open /tmp/qutebrowser-basedir-cg284f_m/data/webengine/GPUCache/data_2
234        'Failed to open *GPUCache*',
235
236        # Qt 5.12
237        # WORKAROUND for https://bugreports.qt.io/browse/QTBUG-70702
238        # [32123:32123:0923/224739.457307:ERROR:in_progress_cache_impl.cc(192)]
239        # Cache is not initialized, cannot RetrieveEntry.
240        'Cache is not initialized, cannot RetrieveEntry.',
241        'Cache is not initialized, cannot AddOrReplaceEntry.',
242        # [10518:10518:0924/121250.186121:WARNING:
243        # render_frame_host_impl.cc(431)]
244        # InterfaceRequest was dropped, the document is no longer active:
245        # content.mojom.RendererAudioOutputStreamFactory
246        'InterfaceRequest was dropped, the document is no longer active: '
247        'content.mojom.RendererAudioOutputStreamFactory',
248        # [1920:2168:0225/112442.664:ERROR:in_progress_cache_impl.cc(124)]
249        # Could not write download entries to file: C:\Users\appveyor\AppData\
250        # Local\Temp\1\qutebrowser-basedir-1l3jmxq4\data\webengine\
251        # in_progress_download_metadata_store
252        'Could not write download entries to file: *',
253
254        # Qt 5.13
255        # [32651:32651:0325/130146.300817:WARNING:
256        # render_frame_host_impl.cc(486)]
257        # InterfaceRequest was dropped, the document is no longer active:
258        # resource_coordinator.mojom.FrameCoordinationUnit
259        'InterfaceRequest was dropped, the document is no longer active: '
260        'resource_coordinator.mojom.FrameCoordinationUnit',
261
262        # Qt 5.14
263        # [1:7:1119/162200.709920:ERROR:command_buffer_proxy_impl.cc(124)]
264        # ContextResult::kTransientFailure: Failed to send
265        # GpuChannelMsg_CreateCommandBuffer.
266        'ContextResult::kTransientFailure: Failed to send '
267        'GpuChannelMsg_CreateCommandBuffer.',
268        # [156330:156350:1121/120052.060701:WARNING:
269        # important_file_writer.cc(97)]
270        # temp file failure: /home/florian/.local/share/qutebrowser/
271        # qutebrowser/QtWebEngine/Default/user_prefs.json : could not create
272        # temporary file: No such file or directory (2)
273        'temp file failure: */qutebrowser/qutebrowser/QtWebEngine/Default/'
274        'user_prefs.json : could not create temporary file: No such file or '
275        'directory (2)',
276        # [156330:156330:1121/120052.602236:ERROR:
277        # viz_process_transport_factory.cc(331)]
278        # Switching to software compositing.
279        'Switching to software compositing.',
280        # [160686:160712:1121/121226.457866:ERROR:surface_manager.cc(438)]
281        # Old/orphaned temporary reference to
282        # SurfaceId(FrameSinkId[](5, 2), LocalSurfaceId(8, 1, 7C3A...))
283        'Old/orphaned temporary reference to '
284        'SurfaceId(FrameSinkId[](*), LocalSurfaceId(*))',
285        # [79680:79705:0111/151113.071008:WARNING:
286        # important_file_writer.cc(97)] temp file failure:
287        # /tmp/qutebrowser-basedir-gwkvqpyp/data/webengine/user_prefs.json :
288        # could not create temporary file: No such file or directory (2)
289        # (Only in debug builds)
290        # https://bugreports.qt.io/browse/QTBUG-78319
291        'temp file failure: * : could not create temporary file: No such file '
292        'or directory (2)',
293
294        # Travis
295        # test_ssl_error_with_contentssl_strict__true
296        # [5306:5324:0417/151739.362362:ERROR:address_tracker_linux.cc(171)]
297        # Could not bind NETLINK socket: Address already in use (98)
298        'Could not bind NETLINK socket: Address already in use (98)',
299
300        # Qt 5.15 with AppVeyor
301        # [2968:3108:0601/123442.125:ERROR:mf_helpers.cc(14)] Error in
302        # dxva_video_decode_accelerator_win.cc on line 517
303        'Error in dxva_video_decode_accelerator_win.cc on line 517',
304
305        # Qt 5.15 and debug build
306        # [134188:134199:0609/132454.797229:WARNING:
307        # simple_synchronous_entry.cc(1389)]
308        # Could not open platform files for entry.
309        # [134151:134187:0609/132456.754321:ERROR:process_posix.cc(333)]
310        # Unable to terminate process 134188: No such process (3)
311        # [134151:134187:0609/132456.754414:WARNING:internal_linux.cc(64)]
312        # Failed to read /proc/134188/stat
313        'Could not open platform files for entry.',
314        'Unable to terminate process *: No such process (3)',
315        'Failed to read /proc/*/stat',
316
317        # Qt 5.15.1 debug build (Chromium 83)
318        # '[314297:7:0929/214605.491958:ERROR:context_provider_command_buffer.cc(145)]
319        # GpuChannelHost failed to create command buffer.'
320        'GpuChannelHost failed to create command buffer.',
321        # [338691:4:0929/220114.488847:WARNING:ipc_message_attachment_set.cc(49)]
322        # MessageAttachmentSet destroyed with unconsumed attachments: 0/1
323        'MessageAttachmentSet destroyed with unconsumed attachments: *',
324
325        # GitHub Actions with Qt 5.15.1
326        ('SharedImageManager::ProduceGLTexture: Trying to produce a '
327         'representation from a non-existent mailbox. *'),
328        ('[.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : '
329         'DoCreateAndTexStorage2DSharedImageINTERNAL: invalid mailbox name'),
330        ('[.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : '
331         'DoBeginSharedImageAccessCHROMIUM: bound texture is not a shared image'),
332        ('[.DisplayCompositor]RENDER WARNING: texture bound to texture unit 0 is '
333         'not renderable. It might be non-power-of-2 or have incompatible texture '
334         'filtering (maybe)?'),
335        ('[.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : '
336         'DoEndSharedImageAccessCHROMIUM: bound texture is not a shared image'),
337        'Unable to map Index file',
338
339        # WebRTC with Qt 5.13 / 5.14
340        'Failed to query stereo recording.',
341        'Accepting maxRetransmits = -1 for backwards compatibility',
342        'Accepting maxRetransmitTime = -1 for backwards compatibility',
343
344        # Windows N:
345        # https://github.com/microsoft/playwright/issues/2901
346        ('DXVAVDA fatal error: could not LoadLibrary: *: The specified '
347         'module could not be found. (0x7E)'),
348
349        # Qt 5.15.3 dev build
350        r'Duplicate id found. Reassigning from * to *',
351
352        # Flatpak
353        'mDNS responder manager failed to start.',
354        'The mDNS responder manager is not started yet.',
355
356        # GitHub Actions with Qt 5.15.0
357        # [5387:5407:0713/142608.526916:ERROR:cache_util.cc(135)] Unable to
358        # move cache folder
359        # /tmp/qutebrowser-basedir-4x3ue9fq/data/webengine/GPUCache to
360        # /tmp/qutebrowser-basedir-4x3ue9fq/data/webengine/old_GPUCache_000
361        # [5387:5407:0713/142608.526934:ERROR:disk_cache.cc(184)] Unable to
362        # create cache
363        # [5387:5407:0713/142608.526938:ERROR:shader_disk_cache.cc(606)] Shader
364        # Cache Creation failed: -2
365        ('Unable to move cache folder */data/webengine/GPUCache to '
366            '*/data/webengine/old_GPUCache_000'),
367        'Unable to create cache',
368        'Shader Cache Creation failed: -2',
369    ]
370    return any(testutils.pattern_match(pattern=pattern, value=message)
371               for pattern in ignored_messages)
372
373
374class LogLine(testprocess.Line):
375
376    """A parsed line from the qutebrowser log output.
377
378    Attributes:
379        timestamp/loglevel/category/module/function/line/message/levelname:
380            Parsed from the log output.
381        expected: Whether the message was expected or not.
382    """
383
384    def __init__(self, pytestconfig, data):
385        super().__init__(data)
386        try:
387            line = json.loads(data)
388        except ValueError:
389            raise testprocess.InvalidLine(data)
390        if not isinstance(line, dict):
391            raise testprocess.InvalidLine(data)
392
393        self.timestamp = datetime.datetime.fromtimestamp(line['created'])
394        self.msecs = line['msecs']
395        self.loglevel = line['levelno']
396        self.levelname = line['levelname']
397        self.category = line['name']
398        self.module = line['module']
399        self.function = line['funcName']
400        self.line = line['lineno']
401        if self.function is None and self.line == 0:
402            self.line = None
403        self.traceback = line.get('traceback')
404        self.message = line['message']
405
406        self.expected = is_ignored_qt_message(pytestconfig, self.message)
407        self.use_color = False
408
409    def __str__(self):
410        return self.formatted_str(colorized=self.use_color)
411
412    def formatted_str(self, colorized=True):
413        """Return a formatted colorized line.
414
415        This returns a line like qute without --json-logging would produce.
416
417        Args:
418            colorized: If True, ANSI color codes will be embedded.
419        """
420        r = logging.LogRecord(self.category, self.loglevel, '', self.line,
421                              self.message, (), None)
422        # Patch some attributes of the LogRecord
423        if self.line is None:
424            r.line = 0
425        r.created = self.timestamp.timestamp()
426        r.msecs = self.msecs
427        r.module = self.module
428        r.funcName = self.function
429
430        format_str = log.EXTENDED_FMT
431        format_str = format_str.replace('{asctime:8}',
432                                        '{asctime:8}.{msecs:03.0f}')
433        # Mark expected errors with (expected) so it's less confusing for tests
434        # which expect errors but fail due to other errors.
435        if self.expected and self.loglevel > logging.INFO:
436            new_color = '{' + log.LOG_COLORS['DEBUG'] + '}'
437            format_str = format_str.replace('{log_color}', new_color)
438            format_str = re.sub(r'{levelname:(\d*)}',
439                                # Leave away the padding because (expected) is
440                                # longer anyway.
441                                r'{levelname} (expected)', format_str)
442
443        formatter = log.ColoredFormatter(format_str, log.DATEFMT, '{',
444                                         use_colors=colorized)
445        result = formatter.format(r)
446        # Manually append the stringified traceback if one is present
447        if self.traceback is not None:
448            result += '\n' + self.traceback
449        return result
450
451
452class QuteProc(testprocess.Process):
453
454    """A running qutebrowser process used for tests.
455
456    Attributes:
457        _ipc_socket: The IPC socket of the started instance.
458        _webengine: Whether to use QtWebEngine
459        basedir: The base directory for this instance.
460        request: The request object for the current test.
461        _instance_id: A unique ID for this QuteProc instance
462        _run_counter: A counter to get a unique ID for each run.
463
464    Signals:
465        got_error: Emitted when there was an error log line.
466    """
467
468    got_error = pyqtSignal()
469
470    KEYS = ['timestamp', 'loglevel', 'category', 'module', 'function', 'line',
471            'message']
472
473    def __init__(self, request, *, parent=None):
474        super().__init__(request, parent)
475        self._ipc_socket = None
476        self.basedir = None
477        self._instance_id = next(instance_counter)
478        self._run_counter = itertools.count()
479        self._screenshot_counters = collections.defaultdict(itertools.count)
480
481    def _process_line(self, log_line):
482        """Check if the line matches any initial lines we're interested in."""
483        start_okay_message = (
484            "load status for <qutebrowser.browser.* tab_id=0 "
485            "url='about:blank'>: LoadStatus.success")
486
487        if (log_line.category == 'ipc' and
488                log_line.message.startswith("Listening as ")):
489            self._ipc_socket = log_line.message.split(' ', maxsplit=2)[2]
490        elif (log_line.category == 'webview' and
491              testutils.pattern_match(pattern=start_okay_message,
492                                      value=log_line.message)):
493            log_line.waited_for = True
494            self.ready.emit()
495        elif (log_line.category == 'init' and
496              log_line.module == 'standarddir' and
497              log_line.function == 'init' and
498              log_line.message.startswith('Base directory:')):
499            self.basedir = log_line.message.split(':', maxsplit=1)[1].strip()
500        elif self._is_error_logline(log_line):
501            self.got_error.emit()
502
503    def _parse_line(self, line):
504        try:
505            log_line = LogLine(self.request.config, line)
506        except testprocess.InvalidLine:
507            if not line.strip():
508                return None
509            elif (is_ignored_qt_message(self.request.config, line) or
510                  is_ignored_lowlevel_message(line) or
511                  is_ignored_chromium_message(line) or
512                  list(self.request.node.iter_markers('no_invalid_lines'))):
513                self._log("IGNORED: {}".format(line))
514                return None
515            else:
516                raise
517
518        log_line.use_color = self.request.config.getoption('--color') != 'no'
519        verbose = self.request.config.getoption('--verbose')
520        if log_line.loglevel > logging.VDEBUG or verbose:
521            self._log(log_line)
522        self._process_line(log_line)
523        return log_line
524
525    def _executable_args(self):
526        profile = self.request.config.getoption('--qute-profile-subprocs')
527        if hasattr(sys, 'frozen'):
528            if profile:
529                raise Exception("Can't profile with sys.frozen!")
530            executable = str(pathlib.Path(sys.executable).parent / 'qutebrowser')
531            args = []
532        else:
533            executable = sys.executable
534            if profile:
535                profile_dir = pathlib.Path.cwd() / 'prof'
536                profile_id = '{}_{}'.format(self._instance_id,
537                                            next(self._run_counter))
538                profile_file = profile_dir / '{}.pstats'.format(profile_id)
539                profile_dir.mkdir(exist_ok=True)
540                args = [str(pathlib.Path('scripts') / 'dev' / 'run_profile.py'),
541                        '--profile-tool', 'none',
542                        '--profile-file', str(profile_file)]
543            else:
544                args = ['-bb', '-m', 'qutebrowser']
545        return executable, args
546
547    def _default_args(self):
548        backend = 'webengine' if self.request.config.webengine else 'webkit'
549        args = ['--debug', '--no-err-windows', '--temp-basedir',
550                '--json-logging', '--loglevel', 'vdebug',
551                '--backend', backend, '--debug-flag', 'no-sql-history',
552                '--debug-flag', 'werror', '--debug-flag',
553                'test-notification-service']
554
555        if self.request.config.webengine:
556            args += testutils.seccomp_args(qt_flag=True)
557
558        args.append('about:blank')
559        return args
560
561    def path_to_url(self, path, *, port=None, https=False):
562        """Get a URL based on a filename for the localhost webserver.
563
564        URLs like about:... and qute:... are handled specially and returned
565        verbatim.
566        """
567        special_schemes = ['about:', 'qute:', 'chrome:', 'view-source:',
568                           'data:', 'http:', 'https:']
569        server = self.request.getfixturevalue('server')
570        server_port = server.port if port is None else port
571
572        if any(path.startswith(scheme) for scheme in special_schemes):
573            path = path.replace('(port)', str(server_port))
574            return path
575        else:
576            return '{}://localhost:{}/{}'.format(
577                'https' if https else 'http',
578                server_port,
579                path if path != '/' else '')
580
581    def wait_for_js(self, message):
582        """Wait for the given javascript console message.
583
584        Return:
585            The LogLine.
586        """
587        line = self.wait_for(category='js',
588                             message='[*] {}'.format(message))
589        line.expected = True
590        return line
591
592    def wait_scroll_pos_changed(self, x=None, y=None):
593        """Wait until a "Scroll position changed" message was found.
594
595        With QtWebEngine, on older Qt versions which lack
596        QWebEnginePage.scrollPositionChanged, this also skips the test.
597        """
598        __tracebackhide__ = (lambda e:
599                             e.errisinstance(testprocess.WaitForTimeout))
600        if (x is None and y is not None) or (y is None and x is not None):
601            raise ValueError("Either both x/y or neither must be given!")
602
603        if x is None and y is None:
604            point = 'PyQt5.QtCore.QPoint(*, *)'  # not counting 0/0 here
605        elif x == '0' and y == '0':
606            point = 'PyQt5.QtCore.QPoint()'
607        else:
608            point = 'PyQt5.QtCore.QPoint({}, {})'.format(x, y)
609        self.wait_for(category='webview',
610                      message='Scroll position changed to ' + point)
611
612    def wait_for(self, timeout=None,  # pylint: disable=arguments-differ
613                 **kwargs):
614        """Extend wait_for to add divisor if a test is xfailing."""
615        __tracebackhide__ = (lambda e:
616                             e.errisinstance(testprocess.WaitForTimeout))
617        xfail = self.request.node.get_closest_marker('xfail')
618        if xfail and (not xfail.args or xfail.args[0]):
619            kwargs['divisor'] = 10
620        else:
621            kwargs['divisor'] = 1
622        return super().wait_for(timeout=timeout, **kwargs)
623
624    def _is_error_logline(self, msg):
625        """Check if the given LogLine is some kind of error message."""
626        is_js_error = (msg.category == 'js' and
627                       testutils.pattern_match(pattern='[*] [FAIL] *',
628                                               value=msg.message))
629        # Try to complain about the most common mistake when accidentally
630        # loading external resources.
631        is_ddg_load = testutils.pattern_match(
632            pattern="load status for <* tab_id=* url='*duckduckgo*'>: *",
633            value=msg.message)
634
635        is_log_error = (msg.loglevel > logging.INFO and
636                        not msg.message.startswith("Ignoring world ID") and
637                        not msg.message.startswith(
638                            "Could not initialize QtNetwork SSL support."))
639        return is_log_error or is_js_error or is_ddg_load
640
641    def _maybe_skip(self):
642        """Skip the test if [SKIP] lines were logged."""
643        skip_texts = []
644
645        for msg in self._data:
646            if (msg.category == 'js' and
647                    testutils.pattern_match(pattern='[*] [SKIP] *',
648                                            value=msg.message)):
649                skip_texts.append(msg.message.partition(' [SKIP] ')[2])
650
651        if skip_texts:
652            pytest.skip(', '.join(skip_texts))
653
654    def before_test(self):
655        """Clear settings before every test."""
656        super().before_test()
657        self.send_cmd(':config-clear')
658        self._init_settings()
659        self.clear_data()
660
661    def _init_settings(self):
662        """Adjust some qutebrowser settings after starting."""
663        settings = [
664            ('messages.timeout', '0'),
665            ('auto_save.interval', '0'),
666            ('new_instance_open_target_window', 'last-opened')
667        ]
668
669        for opt, value in settings:
670            self.set_setting(opt, value)
671
672    def after_test(self):
673        """Handle unexpected/skip logging and clean up after each test."""
674        __tracebackhide__ = lambda e: e.errisinstance(pytest.fail.Exception)
675        bad_msgs = [msg for msg in self._data
676                    if self._is_error_logline(msg) and not msg.expected]
677
678        try:
679            call = self.request.node.rep_call
680        except AttributeError:
681            pass
682        else:
683            if call.failed or hasattr(call, 'wasxfail'):
684                super().after_test()
685                return
686
687        try:
688            if bad_msgs:
689                text = 'Logged unexpected errors:\n\n' + '\n'.join(
690                    str(e) for e in bad_msgs)
691                pytest.fail(text, pytrace=False)
692            else:
693                self._maybe_skip()
694        finally:
695            super().after_test()
696
697    def _wait_for_ipc(self):
698        """Wait for an IPC message to arrive."""
699        self.wait_for(category='ipc', module='ipc', function='on_ready_read',
700                      message='Read from socket *')
701
702    def send_ipc(self, commands, target_arg=''):
703        """Send a raw command to the running IPC socket."""
704        delay = self.request.config.getoption('--qute-delay')
705        time.sleep(delay / 1000)
706
707        assert self._ipc_socket is not None
708        ipc.send_to_running_instance(self._ipc_socket, commands, target_arg)
709
710        try:
711            self._wait_for_ipc()
712        except testprocess.WaitForTimeout:
713            # Sometimes IPC messages seem to get lost on Windows CI?
714            # Retry a second time as this shouldn't make tests fail.
715            ipc.send_to_running_instance(self._ipc_socket, commands,
716                                         target_arg)
717            self._wait_for_ipc()
718
719    def start(self, *args, **kwargs):  # pylint: disable=arguments-differ
720        try:
721            super().start(*args, **kwargs)
722        except testprocess.ProcessExited:
723            is_dl_inconsistency = str(self.captured_log[-1]).endswith(
724                "_dl_allocate_tls_init: Assertion "
725                "`listp->slotinfo[cnt].gen <= GL(dl_tls_generation)' failed!")
726            if testutils.ON_CI and is_dl_inconsistency:
727                # WORKAROUND for https://sourceware.org/bugzilla/show_bug.cgi?id=19329
728                self.captured_log = []
729                self._log("NOTE: Restarted after libc DL inconsistency!")
730                self.clear_data()
731                super().start(*args, **kwargs)
732            else:
733                raise
734
735    def send_cmd(self, command, count=None, invalid=False, *, escape=True):
736        """Send a command to the running qutebrowser instance.
737
738        Args:
739            count: The count to pass to the command.
740            invalid: If True, we don't wait for "command called: ..." in the
741                     log and return None.
742            escape: Escape backslashes in the command
743
744        Return:
745            The parsed log line with "command called: ..." or None.
746        """
747        __tracebackhide__ = lambda e: e.errisinstance(testprocess.WaitForTimeout)
748        summary = command
749        if count is not None:
750            summary += ' (count {})'.format(count)
751        self.log_summary(summary)
752
753        if escape:
754            command = command.replace('\\', r'\\')
755
756        if count is not None:
757            command = ':run-with-count {} {}'.format(count,
758                                                     command.lstrip(':'))
759
760        self.send_ipc([command])
761        if invalid:
762            return None
763        else:
764            return self.wait_for(category='commands', module='command',
765                                 function='run', message='command called: *')
766
767    def get_setting(self, opt, pattern=None):
768        """Get the value of a qutebrowser setting."""
769        if pattern is None:
770            cmd = ':set {}?'.format(opt)
771        else:
772            cmd = ':set -u {} {}?'.format(pattern, opt)
773
774        self.send_cmd(cmd)
775        msg = self.wait_for(loglevel=logging.INFO, category='message',
776                            message='{} = *'.format(opt))
777
778        if pattern is None:
779            return msg.message.split(' = ')[1]
780        else:
781            return msg.message.split(' = ')[1].split(' for ')[0]
782
783    def set_setting(self, option, value):
784        # \ and " in a value should be treated literally, so escape them
785        value = value.replace('\\', r'\\')
786        value = value.replace('"', '\\"')
787        self.send_cmd(':set -t "{}" "{}"'.format(option, value), escape=False)
788        self.wait_for(category='config', message='Config option changed: *')
789
790    @contextlib.contextmanager
791    def temp_setting(self, opt, value):
792        """Context manager to set a setting and reset it on exit."""
793        old_value = self.get_setting(opt)
794        self.set_setting(opt, value)
795        yield
796        self.set_setting(opt, old_value)
797
798    def open_path(self, path, *, new_tab=False, new_bg_tab=False,
799                  new_window=False, private=False, as_url=False, port=None,
800                  https=False, wait=True):
801        """Open the given path on the local webserver in qutebrowser."""
802        url = self.path_to_url(path, port=port, https=https)
803        self.open_url(url, new_tab=new_tab, new_bg_tab=new_bg_tab,
804                      new_window=new_window, private=private, as_url=as_url,
805                      wait=wait)
806
807    def open_url(self, url, *, new_tab=False, new_bg_tab=False,
808                 new_window=False, private=False, as_url=False, wait=True):
809        """Open the given url in qutebrowser."""
810        if sum(1 for opt in [new_tab, new_bg_tab, new_window, private, as_url]
811               if opt) > 1:
812            raise ValueError("Conflicting options given!")
813
814        if as_url:
815            self.send_cmd(url, invalid=True)
816            line = None
817        elif new_tab:
818            line = self.send_cmd(':open -t ' + url)
819        elif new_bg_tab:
820            line = self.send_cmd(':open -b ' + url)
821        elif new_window:
822            line = self.send_cmd(':open -w ' + url)
823        elif private:
824            line = self.send_cmd(':open -p ' + url)
825        else:
826            line = self.send_cmd(':open ' + url)
827
828        if wait:
829            self.wait_for_load_finished_url(url, after=line)
830
831    def mark_expected(self, category=None, loglevel=None, message=None):
832        """Mark a given logging message as expected."""
833        line = self.wait_for(category=category, loglevel=loglevel,
834                             message=message)
835        line.expected = True
836
837    def wait_for_load_finished_url(self, url, *, timeout=None,
838                                   load_status='success', after=None):
839        """Wait until a URL has finished loading."""
840        __tracebackhide__ = (lambda e: e.errisinstance(
841            testprocess.WaitForTimeout))
842
843        if timeout is None:
844            if testutils.ON_CI:
845                timeout = 15000
846            else:
847                timeout = 5000
848
849        qurl = QUrl(url)
850        if not qurl.isValid():
851            raise ValueError("Invalid URL {}: {}".format(url,
852                                                         qurl.errorString()))
853
854        # We really need the same representation that the webview uses in
855        # its __repr__
856        url = utils.elide(qurl.toDisplayString(QUrl.EncodeUnicode), 100)
857        assert url
858
859        pattern = re.compile(
860            r"(load status for <qutebrowser\.browser\..* "
861            r"tab_id=\d+ url='{url}/?'>: LoadStatus\.{load_status}|fetch: "
862            r"PyQt5\.QtCore\.QUrl\('{url}'\) -> .*)".format(
863                load_status=re.escape(load_status), url=re.escape(url)))
864
865        try:
866            self.wait_for(message=pattern, timeout=timeout, after=after)
867        except testprocess.WaitForTimeout:
868            raise testprocess.WaitForTimeout("Timed out while waiting for {} "
869                                             "to be loaded".format(url))
870
871    def wait_for_load_finished(self, path, *, port=None, https=False,
872                               timeout=None, load_status='success'):
873        """Wait until a path has finished loading."""
874        __tracebackhide__ = (lambda e: e.errisinstance(
875            testprocess.WaitForTimeout))
876        url = self.path_to_url(path, port=port, https=https)
877        self.wait_for_load_finished_url(url, timeout=timeout,
878                                        load_status=load_status)
879
880    def get_session(self):
881        """Save the session and get the parsed session data."""
882        with tempfile.TemporaryDirectory() as tdir:
883            session = pathlib.Path(tdir) / 'session.yml'
884            self.send_cmd(':session-save --with-private "{}"'.format(session))
885            self.wait_for(category='message', loglevel=logging.INFO,
886                          message='Saved session {}.'.format(session))
887            data = session.read_text(encoding='utf-8')
888
889        self._log('\nCurrent session data:\n' + data)
890        return utils.yaml_load(data)
891
892    def get_content(self, plain=True):
893        """Get the contents of the current page."""
894        with tempfile.TemporaryDirectory() as tdir:
895            path = pathlib.Path(tdir) / 'page'
896
897            if plain:
898                self.send_cmd(':debug-dump-page --plain "{}"'.format(path))
899            else:
900                self.send_cmd(':debug-dump-page "{}"'.format(path))
901
902            self.wait_for(category='message', loglevel=logging.INFO,
903                          message='Dumped page to {}.'.format(path))
904
905            return path.read_text(encoding='utf-8')
906
907    def get_screenshot(
908            self,
909            *,
910            probe_pos: QPoint = None,
911            probe_color: QColor = testutils.Color(0, 0, 0),
912    ) -> QImage:
913        """Get a screenshot of the current page.
914
915        Arguments:
916            probe: If given, only continue if the pixel at the given position isn't
917                   black (or whatever is specified by probe_color).
918        """
919        for _ in range(5):
920            tmp_path = self.request.getfixturevalue('tmp_path')
921            counter = self._screenshot_counters[self.request.node.nodeid]
922
923            path = tmp_path / f'screenshot-{next(counter)}.png'
924            self.send_cmd(f':screenshot {path}')
925
926            screenshot_msg = f'Screenshot saved to {path}'
927            self.wait_for(message=screenshot_msg)
928            print(screenshot_msg)
929
930            img = QImage(str(path))
931            assert not img.isNull()
932
933            if probe_pos is None:
934                return img
935
936            probed_color = testutils.Color(img.pixelColor(probe_pos))
937            if probed_color == probe_color:
938                return img
939
940            # Rendering might not be completed yet...
941            time.sleep(0.5)
942
943        # Using assert again for pytest introspection
944        assert probed_color == probe_color, "Color probing failed, values on last try:"
945        raise utils.Unreachable()
946
947    def press_keys(self, keys):
948        """Press the given keys using :fake-key."""
949        self.send_cmd(':fake-key -g "{}"'.format(keys))
950
951    def click_element_by_text(self, text):
952        """Click the element with the given text."""
953        # Use Javascript and XPath to find the right element, use console.log
954        # to return an error (no element found, ambiguous element)
955        script = (
956            'var _es = document.evaluate(\'//*[text()={text}]\', document, '
957            'null, XPathResult.ORDERED_NODE_SNAPSHOT_TYPE, null);'
958            'if (_es.snapshotLength == 0) {{ console.log("qute:no elems"); }} '
959            'else if (_es.snapshotLength > 1) {{ console.log("qute:ambiguous '
960            'elems") }} '
961            'else {{ console.log("qute:okay"); _es.snapshotItem(0).click() }}'
962        ).format(text=javascript.string_escape(_xpath_escape(text)))
963        self.send_cmd(':jseval ' + script, escape=False)
964        message = self.wait_for_js('qute:*').message
965        if message.endswith('qute:no elems'):
966            raise ValueError('No element with {!r} found'.format(text))
967        if message.endswith('qute:ambiguous elems'):
968            raise ValueError('Element with {!r} is not unique'.format(text))
969        if not message.endswith('qute:okay'):
970            raise ValueError('Invalid response from qutebrowser: {}'
971                             .format(message))
972
973    def compare_session(self, expected):
974        """Compare the current sessions against the given template.
975
976        partial_compare is used, which means only the keys/values listed will
977        be compared.
978        """
979        __tracebackhide__ = lambda e: e.errisinstance(pytest.fail.Exception)
980        data = self.get_session()
981        expected = yaml.load(expected, Loader=YamlLoader)
982        outcome = testutils.partial_compare(data, expected)
983        if not outcome:
984            msg = "Session comparison failed: {}".format(outcome.error)
985            msg += '\nsee stdout for details'
986            pytest.fail(msg)
987
988    def turn_on_scroll_logging(self, no_scroll_filtering=False):
989        """Make sure all scrolling changes are logged."""
990        cmd = ":debug-pyeval -q objects.debug_flags.add('{}')"
991        if no_scroll_filtering:
992            self.send_cmd(cmd.format('no-scroll-filtering'))
993        self.send_cmd(cmd.format('log-scroll-pos'))
994
995
996class YamlLoader(yaml.SafeLoader):
997
998    """Custom YAML loader used in compare_session."""
999
1000
1001# Translate ... to ellipsis in YAML.
1002YamlLoader.add_constructor('!ellipsis', lambda loader, node: ...)
1003YamlLoader.add_implicit_resolver('!ellipsis', re.compile(r'\.\.\.'), None)
1004
1005
1006def _xpath_escape(text):
1007    """Escape a string to be used in an XPath expression.
1008
1009    The resulting string should still be escaped with javascript.string_escape,
1010    to prevent javascript from interpreting the quotes.
1011
1012    This function is needed because XPath does not provide any character
1013    escaping mechanisms, so to get the string
1014        "I'm back", he said
1015    you have to use concat like
1016        concat('"I', "'m back", '", he said')
1017
1018    Args:
1019        text: Text to escape
1020
1021    Return:
1022        The string "escaped" as a concat() call.
1023    """
1024    # Shortcut if at most a single quoting style is used
1025    if "'" not in text or '"' not in text:
1026        return repr(text)
1027    parts = re.split('([\'"])', text)
1028    # Python's repr() of strings will automatically choose the right quote
1029    # type. Since each part only contains one "type" of quote, no escaping
1030    # should be necessary.
1031    parts = [repr(part) for part in parts if part]
1032    return 'concat({})'.format(', '.join(parts))
1033
1034
1035@pytest.fixture(scope='module')
1036def quteproc_process(qapp, server, request):
1037    """Fixture for qutebrowser process which is started once per file."""
1038    # Passing request so it has an initial config
1039    proc = QuteProc(request)
1040    proc.start()
1041    yield proc
1042    proc.terminate()
1043
1044
1045@pytest.fixture
1046def quteproc(quteproc_process, server, request):
1047    """Per-test qutebrowser fixture which uses the per-file process."""
1048    request.node._quteproc_log = quteproc_process.captured_log
1049    quteproc_process.before_test()
1050    quteproc_process.request = request
1051    yield quteproc_process
1052    quteproc_process.after_test()
1053
1054
1055@pytest.fixture
1056def quteproc_new(qapp, server, request):
1057    """Per-test qutebrowser process to test invocations."""
1058    proc = QuteProc(request)
1059    request.node._quteproc_log = proc.captured_log
1060    # Not calling before_test here as that would start the process
1061    yield proc
1062    proc.after_test()
1063    proc.terminate()
1064