Got BadWindow exception while trying to get active window on Linux about aw-watcher-window

[nikanar]

and now I got the same BadValue as @johan-bjareholt, too :

2017-07-30 15:03:22,689 [ERROR]: Exception thrown while trying to get active window: <class 'Xlib.error.BadValue'>: code = 2, resource_id = 10, sequence_number = 7254, major_opcode = 20, minor_opcode = 0  (aw_watcher_window.main:69)
Traceback (most recent call last):
  File "/home/will/.local/lib/python3.6/site-packages/aw_watcher_window/main.py", line 66, in heartbeat_loop
    current_window = get_current_window()
  File "/home/will/.local/lib/python3.6/site-packages/aw_watcher_window/lib.py", line 44, in get_current_window
    return get_current_window_linux()
  File "/home/will/.local/lib/python3.6/site-packages/aw_watcher_window/lib.py", line 14, in get_current_window_linux
    name = xlib.get_window_name(window)
  File "/home/will/.local/lib/python3.6/site-packages/aw_watcher_window/xlib.py", line 51, in get_window_name
    d = window.get_full_property(NET_WM_NAME, UTF8_STRING)
  File "/home/will/.local/lib/python3.6/site-packages/Xlib/xobject/drawable.py", line 477, in get_full_property
    prop.bytes_after // 4 + 1)
  File "/home/will/.local/lib/python3.6/site-packages/Xlib/xobject/drawable.py", line 461, in get_property
    long_length = length)
  File "/home/will/.local/lib/python3.6/site-packages/Xlib/protocol/rq.py", line 1360, in __init__
    self.reply()
  File "/home/will/.local/lib/python3.6/site-packages/Xlib/protocol/rq.py", line 1380, in reply
    raise self._error
Xlib.error.BadValue: <class 'Xlib.error.BadValue'>: code = 2, resource_id = 10, sequence_number = 7254, major_opcode = 20, minor_opcode = 0

During handling of the above exception, another exception occurred: 
Traceback (most recent call last):
  File "/home/will/.local/bin/aw-watcher-window", line 11, in <module>
    load_entry_point('aw-watcher-window==0.2', 'console_scripts', 'aw-watcher-window')()
  File "/home/will/.local/lib/python3.6/site-packages/aw_watcher_window/main.py", line 46, in main
    heartbeat_loop(client, bucket_id, poll_time=args.poll_time, exclude_title=args.exclude_title)
  File "/home/will/.local/lib/python3.6/site-packages/aw_watcher_window/main.py", line 70, in heartbeat_loop
    traceback.print_exc(e)
  File "/usr/lib/python3.6/traceback.py", line 159, in print_exc
    print_exception(*sys.exc_info(), limit=limit, file=file, chain=chain)
  File "/usr/lib/python3.6/traceback.py", line 100, in print_exception
    type(value), value, tb, limit=limit).format(chain=chain):
  File "/usr/lib/python3.6/traceback.py", line 497, in __init__
    capture_locals=capture_locals)
  File "/usr/lib/python3.6/traceback.py", line 332, in extract
    if limit >= 0:
TypeError: '>=' not supported between instances of 'BadValue' and 'int'

Will try and patch things up as @ErikBjare suggested... done. We should get more warnings and less crashes now, which sounds like a good thing to me !

[johan-bjareholt]

This should hopefully be fixed now with @nikanar 's PR. Please reopen if anyone encounters this issue again.

[johan-bjareholt]

Also got a crash now, log seems kind of different so cause is likely different though.

2017-07-01 18:00:25,809 [INFO ]: Running watcher with poll time 1.0 seconds  (aw_watcher_window.main:35)
2017-07-01 18:00:25,811 [INFO ]: aw-watcher-window has started  (aw_watcher_window.main:43)
2017-07-01 18:00:25,889 [INFO ]: Connection to aw-server established  (aw_client.client:257)
2017-07-01 18:00:25,969 [WARNING]: window_prop was None  (root:21)
2017-07-01 18:00:26,971 [WARNING]: window_prop was None  (root:21)
2017-07-01 18:00:27,986 [WARNING]: window_prop was None  (root:21)
2017-07-01 18:00:28,988 [WARNING]: window_prop was None  (root:21)
2017-07-01 18:00:29,991 [WARNING]: window_prop was None  (root:21)
2017-07-01 18:00:30,993 [WARNING]: window_prop was None  (root:21)
2017-07-01 18:00:31,996 [WARNING]: window_prop was None  (root:21)
2017-07-01 18:00:32,997 [WARNING]: window_prop was None  (root:21)
2017-07-01 18:00:33,999 [ERROR]: Exception thrown while trying to get active window: 'NoneType' object is not subscriptable  (aw_watche
Traceback (most recent call last):
  File "/home/johan/Programming/activitywatch/aw-watcher-window/aw_watcher_window/main.py", line 61, in heartbeat_loop
    current_window = get_current_window()
  File "/home/johan/Programming/activitywatch/aw-watcher-window/aw_watcher_window/lib.py", line 44, in get_current_window
    return get_current_window_linux()
  File "/home/johan/Programming/activitywatch/aw-watcher-window/aw_watcher_window/lib.py", line 13, in get_current_window_linux
    cls = xlib.get_window_class(window)
  File "/home/johan/Programming/activitywatch/aw-watcher-window/aw_watcher_window/xlib.py", line 72, in get_window_class
    cls = cls[1]
TypeError: 'NoneType' object is not subscriptable

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/aw-watcher-window", line 11, in <module>
    load_entry_point('aw-watcher-window', 'console_scripts', 'aw-watcher-window')()
  File "/home/johan/Programming/activitywatch/aw-watcher-window/aw_watcher_window/main.py", line 45, in main
    heartbeat_loop(client, bucket_id, poll_time=args.poll_time, exclude_title=args.exclude_title)
  File "/home/johan/Programming/activitywatch/aw-watcher-window/aw_watcher_window/main.py", line 65, in heartbeat_loop
    traceback.print_exc(e)
  File "/usr/lib/python3.6/traceback.py", line 159, in print_exc
    print_exception(*sys.exc_info(), limit=limit, file=file, chain=chain)
  File "/usr/lib/python3.6/traceback.py", line 100, in print_exception
    type(value), value, tb, limit=limit).format(chain=chain):
  File "/usr/lib/python3.6/traceback.py", line 497, in __init__
    capture_locals=capture_locals)
  File "/usr/lib/python3.6/traceback.py", line 332, in extract
    if limit >= 0:
TypeError: '>=' not supported between instances of 'TypeError' and 'int'

[nikanar]

Got the same one as @johan-bjareholt :

2017-07-16 14:04:20,395 [INFO ]: No longer AFK  (aw_watcher_afk.afk:111)
2017-07-16 14:04:20,427 [WARNING]: Event initializer did not receive a timestamp argument, using now as timestamp  (aw_core.models:48)
2017-07-16 16:29:45,466 [ERROR]: Exception thrown while trying to get active window: 'NoneType' object is not subscriptable  (aw_watcher_window.main:64)
Traceback (most recent call last):
File "/usr/lib/python3.6/site-packages/aw_watcher_window/main.py", line 61, in heartbeat_loop
    current_window = get_current_window()
  File "/usr/lib/python3.6/site-packages/aw_watcher_window/lib.py", line 44, in get_current_window
    return get_current_window_linux()
  File "/usr/lib/python3.6/site-packages/aw_watcher_window/lib.py", line 13, in get_current_window_linux
    cls = xlib.get_window_class(window)
  File "/usr/lib/python3.6/site-packages/aw_watcher_window/xlib.py", line 72, in get_window_class
    cls = cls[1]
TypeError: 'NoneType' object is not subscriptable

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/aw-watcher-window", line 11, in <module>
    load_entry_point('aw-watcher-window==0.2', 'console_scripts', 'aw-watcher-window')()
  File "/usr/lib/python3.6/site-packages/aw_watcher_window/main.py", line 45, in main
    heartbeat_loop(client, bucket_id, poll_time=args.poll_time, exclude_title=args.exclude_title)
  File "/usr/lib/python3.6/site-packages/aw_watcher_window/main.py", line 65, in heartbeat_loop
    traceback.print_exc(e)
  File "/usr/lib/python3.6/traceback.py", line 159, in print_exc
    print_exception(*sys.exc_info(), limit=limit, file=file, chain=chain)
  File "/usr/lib/python3.6/traceback.py", line 100, in print_exception
    type(value), value, tb, limit=limit).format(chain=chain):
  File "/usr/lib/python3.6/traceback.py", line 497, in __init__
    capture_locals=capture_locals)
  File "/usr/lib/python3.6/traceback.py", line 332, in extract
    if limit >= 0:
TypeError: '>=' not supported between instances of 'TypeError' and 'int'
Reading active process stderr...
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/aw_qt-0.1-py3.6.egg/aw_qt/trayicon.py", line 110, in rebuild_modules_menu
    show_module_failed_dialog(module)
  File "/usr/lib/python3.6/site-packages/aw_qt-0.1-py3.6.egg/aw_qt/trayicon.py", line 96, in show_module_failed_dialog
    box.setDetailedText(module.stderr())
  File "/usr/lib/python3.6/site-packages/aw_qt-0.1-py3.6.egg/aw_qt/manager.py", line 108, in stderr
    self._log += self._process.stderr.read()
AttributeError: 'NoneType' object has no attribute 'read'
Aborted (core dumped)

RT says I exclusively opened google-chrome/emacs/terminator at that time (as I always do), so it ain't due to a specific window.

and relatedly to ActivityWatch/aw-qt#19, aw-server and aw-watcher-afk didn't crash, only aw-watcher-window and aw-qt.

and again at

2017-07-16 17:30:08,725 [ERROR]: Exception thrown while trying to get active window: 'NoneType' object is not subscriptable  (aw_watcher_window.main:64)
[same]

[johan-bjareholt]

Looked more closely at the code and the issue I and @nikanar stumbled upon was quite obvious. Commited straight to master here a8e704f

We need to handle the Xlib.error.BadWindow exception properly to fix the original problem which @ErikBjare posted though.

[johan-bjareholt]

After running for almost two weeks, I didn't get BadWindow but instead a BadValue exception.

2017-07-08 10:32:45,844 [INFO ]: Running watcher with poll time 1.0 seconds  (aw_watcher_window.main:35)
2017-07-08 10:32:45,846 [INFO ]: aw-watcher-window has started  (aw_watcher_window.main:43)
2017-07-08 10:32:45,936 [INFO ]: Connection to aw-server established  (aw_client.client:257)
2017-07-08 10:32:46,020 [WARNING]: window_prop was None  (root:21)
2017-07-08 10:32:47,022 [WARNING]: window_prop was None  (root:21)
2017-07-08 10:32:48,023 [WARNING]: window_prop was None  (root:21)
2017-07-08 10:32:49,025 [WARNING]: window_prop was None  (root:21)
2017-07-08 10:32:50,027 [WARNING]: window_prop was None  (root:21)
2017-07-08 10:32:51,028 [WARNING]: window_prop was None  (root:21)
2017-07-08 10:32:52,030 [WARNING]: window_prop was None  (root:21)
2017-07-22 18:41:47,207 [ERROR]: Exception thrown while trying to get active window: <class 'Xlib.error.BadValue'>: code = 2, resource_id = 10, sequence_number = 16630, major_opcode = 20, minor_opcode = 0  (aw_watcher_window.main:64)
Traceback (most recent call last):
  File "/home/johan/Programming/activitywatch/aw-watcher-window/aw_watcher_window/main.py", line 61, in heartbeat_loop
    if os.getppid() == 1:
  File "/home/johan/Programming/activitywatch/aw-watcher-window/aw_watcher_window/lib.py", line 44, in get_current_window
    return get_current_window_linux()
  File "/home/johan/Programming/activitywatch/aw-watcher-window/aw_watcher_window/lib.py", line 14, in get_current_window_linux
    name = xlib.get_window_name(window)
  File "/home/johan/Programming/activitywatch/aw-watcher-window/aw_watcher_window/xlib.py", line 49, in get_window_name
    d = window.get_full_property(NET_WM_NAME, UTF8_STRING)
  File "/usr/lib/python3.6/site-packages/python_xlib-0.19-py3.6.egg/Xlib/xobject/drawable.py", line 477, in get_full_property
  File "/usr/lib/python3.6/site-packages/python_xlib-0.19-py3.6.egg/Xlib/xobject/drawable.py", line 461, in get_property
  File "/usr/lib/python3.6/site-packages/python_xlib-0.19-py3.6.egg/Xlib/protocol/rq.py", line 1360, in __init__
  File "/usr/lib/python3.6/site-packages/python_xlib-0.19-py3.6.egg/Xlib/protocol/rq.py", line 1380, in reply
Xlib.error.BadValue: <class 'Xlib.error.BadValue'>: code = 2, resource_id = 10, sequence_number = 16630, major_opcode = 20, minor_opcode = 0

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/aw-watcher-window", line 11, in <module>
    load_entry_point('aw-watcher-window', 'console_scripts', 'aw-watcher-window')()
  File "/home/johan/Programming/activitywatch/aw-watcher-window/aw_watcher_window/main.py", line 45, in main
    with client:
  File "/home/johan/Programming/activitywatch/aw-watcher-window/aw_watcher_window/main.py", line 65, in heartbeat_loop
    try:
  File "/usr/lib/python3.6/traceback.py", line 159, in print_exc
    print_exception(*sys.exc_info(), limit=limit, file=file, chain=chain)
  File "/usr/lib/python3.6/traceback.py", line 100, in print_exception
    type(value), value, tb, limit=limit).format(chain=chain):
  File "/usr/lib/python3.6/traceback.py", line 497, in __init__
    capture_locals=capture_locals)
  File "/usr/lib/python3.6/traceback.py", line 332, in extract
    if limit >= 0:
TypeError: '>=' not supported between instances of 'BadValue' and 'int'

[nikanar]

Got one BadWindow this time, which looks like the same as OP :

2017-07-25 20:44:26,433 [WARNING]: Unable to get window class, got a BadWindow exception.  (root:73)

2017-07-25 20:44:26,433 [WARNING]: Code made an unclear branch  (root:78)
2017-07-25 20:44:26,438 [ERROR]: Exception thrown while trying to get active window: <class 'Xlib.error.BadWindow'>: code = 3, resource_id = <class 'Xlib.xobject.resource.Resource'>(0x01e005f4), sequence_number = 118, major_opcode = 15, minor_opcode = 0  (aw_watcher_window.main:69)
Traceback (most recent call last):
  File "/home/will/.local/lib/python3.6/site-packages/aw_watcher_window/main.py", line 66, in heartbeat_loop
    current_window = get_current_window()
  File "/home/will/.local/lib/python3.6/site-packages/aw_watcher_window/lib.py", line 44, in get_current_window
    return get_current_window_linux()
  File "/home/will/.local/lib/python3.6/site-packages/aw_watcher_window/lib.py", line 13, in get_current_window_linux
    cls = xlib.get_window_class(window)
  File "/home/will/.local/lib/python3.6/site-packages/aw_watcher_window/xlib.py", line 79, in get_window_class
    window = window.query_tree().parent
  File "/home/will/.local/lib/python3.6/site-packages/Xlib/xobject/drawable.py", line 425, in query_tree
    window = self.id)
  File "/home/will/.local/lib/python3.6/site-packages/Xlib/protocol/rq.py", line 1360, in __init__
    self.reply()
  File "/home/will/.local/lib/python3.6/site-packages/Xlib/protocol/rq.py", line 1380, in reply
    raise self._error
Xlib.error.BadWindow: <class 'Xlib.error.BadWindow'>: code = 3, resource_id = <class 'Xlib.xobject.resource.Resource'>(0x01e005f4), sequence_number = 118, major_opcode = 15, minor_opcode = 0

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/will/.local/bin/aw-watcher-window", line 11, in <module>
    load_entry_point('aw-watcher-window==0.2', 'console_scripts', 'aw-watcher-window')()
  File "/home/will/.local/lib/python3.6/site-packages/aw_watcher_window/main.py", line 46, in main
    heartbeat_loop(client, bucket_id, poll_time=args.poll_time, exclude_title=args.exclude_title)
  File "/home/will/.local/lib/python3.6/site-packages/aw_watcher_window/main.py", line 70, in heartbeat_loop
    traceback.print_exc(e)
  File "/usr/lib/python3.6/traceback.py", line 159, in print_exc
    print_exception(*sys.exc_info(), limit=limit, file=file, chain=chain)
  File "/usr/lib/python3.6/traceback.py", line 100, in print_exception
    type(value), value, tb, limit=limit).format(chain=chain):
  File "/usr/lib/python3.6/traceback.py", line 497, in __init__
    capture_locals=capture_locals)
  File "/usr/lib/python3.6/traceback.py", line 332, in extract
    if limit >= 0:
TypeError: '>=' not supported between instances of 'BadWindow' and 'int'
Reading active process stderr...
Traceback (most recent call last):
  File "/home/will/.local/lib/python3.6/site-packages/aw_qt-0.1-py3.6.egg/aw_qt/trayicon.py", line 110, in rebuild_modules_menu
    show_module_failed_dialog(module)
  File "/home/will/.local/lib/python3.6/site-packages/aw_qt-0.1-py3.6.egg/aw_qt/trayicon.py", line 96, in show_module_failed_dialog
    box.setDetailedText(module.stderr())
  File "/home/will/.local/lib/python3.6/site-packages/aw_qt-0.1-py3.6.egg/aw_qt/manager.py", line 108, in stderr
    self._log += self._process.stderr.read()
AttributeError: 'NoneType' object has no attribute 'read'
2017-07-25 20:44:28,414 [INFO ]: afkwatcher stopped because parent process died  (aw_watcher_afk.afk:81)

Might be linked to a window that was behaving very badly, a single chrome google-sheets tab which wasn't displayed at all by my awesome wm, it would appear when I fullscreened it, but again disappear entirely when I un-fullscreen it back, I had to toggle use system title bar and borders to get it in line.

[ErikBjare]

I'm guessing we could work around this issue by catching XError's and retrying, or simply returning None which would indicate the active window was unknown (probably better since we won't have to worry about very fast retries).

I think it's caused by the window.query_tree().parent, perhaps because the window disappears before the tree is queried? Something similar could be the case for the BadValue exception.

See xlib source here: https://github.com/python-xlib/python-xlib/blob/master/Xlib/error.py

Also, that traceback.print_exc(e) line is wrong, the e argument shouldn't be there (that's why we get the weird limit errors).

Wrote this while a bit sleep deprived during a 7h layover at the Vaclav Havel Airport in Prague... Results may vary.