activitywatch icon indicating copy to clipboard operation
activitywatch copied to clipboard
verified publisher icon ActivityWatch

Fatal error, stopping (aw_watcher_window.main:120)

Open fraction01 opened this issue 8 months ago • 1 comments

  • [x] I am on the latest ActivityWatch version.
  • [x] I have searched the issues of this repo and believe that this is not a duplicate.
  • OS name and version: LMDE 6 Faye base: Debian 12.1 bookworm
  • ActivityWatch version: v0.13.2

Describe the bug

aw-watcher-window crashed and stopped reporting data.

To Reproduce

Expected behavior

I think it should restart after a crash

Documentation

aw-watcher-window logs:

2025-05-19 11:21:40 [INFO ]: aw-watcher-window started  (aw_watcher_window.main:70)
2025-05-19 11:21:41 [INFO ]: Connection to aw-server established by aw-watcher-window  (aw_client.client:447)
2025-05-26 15:46:21 [WARNING]: Unable to get window class, got a BadWindow exception.  (aw_watcher_window.xlib:115)
2025-05-26 15:46:21 [ERROR]: Fatal error, stopping  (aw_watcher_window.main:120)
Traceback (most recent call last):
  File "aw_watcher_window/main.py", line 115, in heartbeat_loop
  File "aw_watcher_window/lib.py", line 64, in get_current_window
  File "aw_watcher_window/lib.py", line 16, in get_current_window_linux
  File "aw_watcher_window/xlib.py", line 120, in get_window_class
OSError: [Errno 5] Input/output error
2025-05-26 15:46:21 [ERROR]: Unhandled exception  (root:50)
Traceback (most recent call last):
  File "<string>", line 1, in <module>
OSError: [Errno 5] Input/output error
2025-05-26 15:46:21 [ERROR]: Unhandled exception  (root:50)
Traceback (most recent call last):
  File "<string>", line 1, in <module>
OSError: [Errno 5] Input/output error

Additional context

Image

fraction01 avatar May 27 '25 11:05 fraction01

Hi there! As you're new to this repo, please make sure you've used an appropriate issue template and searched for duplicates (it helps us focus on actual development!). We'd also like to suggest that you read our contribution guidelines and our code of conduct. Thanks a bunch for opening your first issue! 🙏

github-actions[bot] avatar May 27 '25 11:05 github-actions[bot]

I'm a relatively new Activity Watch user and I've run into the same issue a couple times so far.

  • OS name and version: Debian 12 bookworm
  • ActivityWatch Version: v0.13.2
$ cat  ~/.cache/activitywatch/log/aw-watcher-window/aw-watcher-window_2025-07-12T01-12-14.log 
2025-07-12 01:12:14 [INFO ]: aw-watcher-window started  (aw_watcher_window.main:70)
2025-07-12 01:12:15 [INFO ]: Connection to aw-server established by aw-watcher-window  (aw_client.client:447)
2025-07-12 03:08:28 [WARNING]: Unable to get window class, got a BadWindow exception.  (aw_watcher_window.xlib:115)
2025-07-12 03:08:28 [ERROR]: Fatal error, stopping  (aw_watcher_window.main:120)
Traceback (most recent call last):
  File "aw_watcher_window/main.py", line 115, in heartbeat_loop
  File "aw_watcher_window/lib.py", line 64, in get_current_window
  File "aw_watcher_window/lib.py", line 16, in get_current_window_linux
  File "aw_watcher_window/xlib.py", line 120, in get_window_class
OSError: [Errno 5] Input/output error
2025-07-12 03:08:28 [ERROR]: Unhandled exception  (root:50)
Traceback (most recent call last):
  File "<string>", line 1, in <module>
OSError: [Errno 5] Input/output error
2025-07-12 03:08:28 [ERROR]: Unhandled exception  (root:50)
Traceback (most recent call last):
  File "<string>", line 1, in <module>
OSError: [Errno 5] Input/output error

The 1:12 timestamp is when I noticed this issue and manually restarted the server with the aw-qt binary. The error at 3:08 is around when I went to bed, so this may have been when I locked my computer or when it went to sleep. It might also have been earlier when I was using the computer.

Interestingly, the pgrep -f "aw-watcher-window" gives a value back, so the program is still running, but it is somehow in a bad state because it isn't feeding any new data into the server. My other watchers (aw-watcher-afk and aw-watcher-rustrover) are chugging along without issue. Perhaps the error isn't causing the program to exit cleanly, so aw-qt doesn't know to restart it?

The first part of the error message being a stack trace makes sense and is normal. What I'm not sure about is this part:

OSError: [Errno 5] Input/output error
2025-07-12 03:08:28 [ERROR]: Unhandled exception  (root:50)
Traceback (most recent call last):
  File "<string>", line 1, in <module>
OSError: [Errno 5] Input/output error
2025-07-12 03:08:28 [ERROR]: Unhandled exception  (root:50)
Traceback (most recent call last):
  File "<string>", line 1, in <module>
OSError: [Errno 5] Input/output error

To try to find what happened to cause this error at 03:08:28, I asked Claude and we found a few things:

sudo journalctl --since="2025-07-12 03:05" --until="2025-07-12 03:10"
Jul 12 03:08:43 omar-debian earlyoom[1417]: mem avail:  8018 of 63399 MiB (12.65%), swap free:    0 of    0 MiB ( 0.00%)
Jul 12 03:08:49 omar-debian cinnamon[3099]: Could not create selection source for X11: Format TARGETS not supported
Jul 12 03:08:49 omar-debian cinnamon[3099]: Could not create selection source for X11: Format TARGETS not supported
Jul 12 03:08:49 omar-debian cinnamon[3099]: Could not create selection source for X11: Format TARGETS not supported
Jul 12 03:08:49 omar-debian cinnamon[3099]: Could not create selection source for X11: Format TARGETS not supported
Jul 12 03:08:49 omar-debian cinnamon[3099]: Could not create selection source for X11: Format TARGETS not supported

I don't know what was using up all of that memory, but 8GB free is still plenty. The repeated "Format TARGETS" message repeated another ~15 times. Also, these are after the aw-watcher-window partial crash, so maybe not related. The timing is a bit suspect though.

Omustardo avatar Jul 13 '25 06:07 Omustardo

I tried to reproduce this issue but failed:

I got to a good state by killing and restarting the binary. This starts the server and the two basic built-in watchers:

$ pkill -f aw-qt
$ /home/omustardo/.local/share/activitywatch/aw-qt
$ $ ps -aux | grep "aw-"
omustar+ 3471884  0.4  0.1 610592 95716 ?        S    01:12   6:07 /home/omustardo/.local/share/activitywatch/aw-server/aw-server
omustar+ 3471886  0.2  0.0 264468 41140 ?        Sl   01:12   3:16 /home/omustardo/.local/share/activitywatch/aw-watcher-afk/aw-watcher-afk
omustar+ 3811618  0.2  0.0 115356 35172 pts/6    Sl   23:58   0:00 /home/omustardo/.local/share/activitywatch/aw-watcher-window/aw-watcher-window

I verified that it's working by looking at the timeline. http://localhost:5600/#/timeline

Next I'm going to try to break it.

To tell when I break it, I kept a view of the log file open in another terminal:

$ cat  ~/.cache/activitywatch/log/aw-watcher-window/aw-watcher-window_2025-07-12T23-58-34.log 
2025-07-12 23:58:34 [INFO ]: aw-watcher-window started  (aw_watcher_window.main:70)
2025-07-12 23:58:35 [INFO ]: Connection to aw-server established by aw-watcher-window  (aw_client.client:447)

Shutdown menu

Since my experience made it seem related to locking / suspending my computer, I clicked the "Menu > Quit" to open the tiny window for "Shut down this system now?" with options: Suspend/Restart/Cancel/Shut Down. Even without clicking any buttons, this resulted in a log:

2025-07-13 00:04:40 [WARNING]: Unable to get window class, got a BadWindow exception.  (aw_watcher_window.xlib:115)
2025-07-13 00:04:40 [WARNING]: Code made an unclear branch  (aw_watcher_window.xlib:121)
2025-07-13 00:04:40 [WARNING]: Unable to get window property NET_WM_NAME, got a BadWindow exception from Xlib  (aw_watcher_window.xlib:69)

This is different then the message from the prior two comments. I verified that it didn't appear to affect logs going to the server, but it's still interesting.

Lock screen

I tried locking the computer with cinnamon-screensaver-command --lock (same as using Super + L). No effect.

RAM usage

This is a long shot, but my prior comment noted a log in journalctl about high memory usage, after the crash in aw-window-watcher.

I increased my RAM usage with $ stress --vm 48 --vm-bytes 512M --timeout 30s until it was well above 80%, and didn't cause any issues. I would have been very surprised if it had.

Omustardo avatar Jul 13 '25 08:07 Omustardo

Now to look at some code. tl;dr might be related to closing a client. Not sure.

The stack trace was:

  File "aw_watcher_window/main.py", line 115, in heartbeat_loop
  File "aw_watcher_window/lib.py", line 64, in get_current_window
  File "aw_watcher_window/lib.py", line 16, in get_current_window_linux
  File "aw_watcher_window/xlib.py", line 120, in get_window_class

Error Source

The error is thrown from window.get_wm_class() so perhaps we can figure this out by finding out why a Xlib.xobject.drawable.Window would ever throw that.

  1. get_wm_class
  2. get_full_text_property

I dug a bit further but didn't find anything where the exception might've been thrown.

Error type

https://docs.python.org/3/library/exceptions.html#OSError

This exception is raised when a system function returns a system-related error, including I/O failures such as “file not found” or “disk full” (not for illegal argument types or other incidental errors).

Not sure what to do with this. I don't think my system would have had I/O errors for this program while I wouldn't have noticed them in other programs, but it's hard to say.

Error Handling

While I'm interested in what might've caused the OSError, what's more important is why it didn't properly propagate and kill the program, which would presumably have led aw-qt to restart it, and we'd have been back to a good state.

After reviewing the code, my best guess is that there is a problem freeing the client ("with client:"). I believe a with client only exits when the resource is released. It would explain why the heartbeat loop isn't working, but the program also hasn't exited.

I dug into the code relatively deeply here, starting at __exit__() in aw-client. I'm not entirely sure if it stalling there for long periods is possible, but it's worth checking. I cloned this repo and added some debug logs to main.py. It appeared to build, but when I dropped its binary in as a replacement for the old binary, it didn't upload any information. I'm not sure what I'm doing wrong there.

Omustardo avatar Jul 13 '25 09:07 Omustardo

EDIT: This didn't work. The server gets started, but the watchers do not. Not sure why. Maybe an environmental variable issue, since cron doesn't have the same variables as running something in bash.

As a mitigation for myself, I've added a crontab entry to restart Activity Watch every 30 minutes. Not a great long term solution though.

pkill -f aw-server
pkill -f aw-watcher-afk
pkill -f aw-watcher-window
~/.local/share/activitywatch/aw-qt

Omustardo avatar Jul 13 '25 09:07 Omustardo

Previously I had been running ActivityWatch through aw-qt. It started up the server and watcher binaries. I decided to try running each binary individually, as suggested in https://docs.activitywatch.net/en/latest/installing-from-source.html#running

I ran each in a separate tab in bash:

~/.local/share/activitywatch/aw-server/aw-server
~/.local/share/activitywatch/aw-watcher-afk/aw-watcher-afk
~/.local/share/activitywatch/aw-watcher-window/aw-watcher-window

This seems to have resolved the issue, though there's a decent chance that I've just been lucky and not hit the original issue recently. All logs seem normal, except aw-watcher-window which has repeated exceptions but apparently none that crashed the program. https://gist.github.com/Omustardo/d289f987dba77e0511d0f54b4839e8f0

Omustardo avatar Jul 17 '25 05:07 Omustardo