search

ActivityWatch / activitywatch-old

[DEPRECATED] :watch: Logs your computer activities, a RescueTime replacement.
MIT License
16 stars 2 forks source link

100% CPU usage #22

Closed ErikBjare closed 8 years ago

ErikBjare commented 8 years ago

On my system (Arch) ActivityWatch wants to use up 100% of available resources for the core it's running on.

Will have to investigate this, now I don't run it at all on my system because of this issue (since it makes my CPU fan remind me of it's existence).

ErikBjare commented 8 years ago

The problem seems to have been triggered by an issue in X11Watcher (Xlib.error.BadWindow). Once such an event has happened once, it starts chugging resources. Although I'm unable to replicate it for now, so might be something completely different. None the less another reason to solve #3.

ErikBjare commented 8 years ago

Managed to reproduce, here is the profiling output:

         779007989 function calls (876158290 primitive calls) in 623.265 seconds                                                                                                                      [820/12841]

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
773814146  211.815    0.000  211.815    0.000 /usr/lib/python3.5/site-packages/Xlib/support/lock.py:33(_DummyLock.__noop)
31954/96696586  384.291    0.012   75.031    0.000 /usr/lib/python3.5/site-packages/Xlib/protocol/display.py:344(_BaseDisplay.send_and_recv)
11358/11359    0.099    0.000   54.751    0.005 /home/erb/Programming/Python/activity-watch/activitywatch/watchers/linux.py:112(X11Watcher.loop)
11359/11360    0.415    0.000   54.602    0.005 /home/erb/Programming/Python/activity-watch/activitywatch/watchers/linux.py:57(X11Watcher.update_active_window)
11435/11436    0.093    0.000   53.653    0.005 /usr/lib/python3.5/site-packages/Xlib/xobject/drawable.py:451(Window.get_full_property)
11447/11448    0.291    0.000   53.546    0.005 /usr/lib/python3.5/site-packages/Xlib/xobject/drawable.py:434(Window.get_property)
11449/11450    0.227    0.000   53.227    0.005 /usr/lib/python3.5/site-packages/Xlib/protocol/rq.py:1470(InternAtom.__init__)
11449/11450    0.168    0.000   52.423    0.005 /usr/lib/python3.5/site-packages/Xlib/protocol/rq.py:1483(InternAtom.reply)
76849/76866    1.255    0.000   31.878    0.000 /usr/lib/python3.5/threading.py:531(Event.wait)
66373/66390    2.031    0.000   29.750    0.000 /usr/lib/python3.5/threading.py:261(Condition.wait)
30718/30735    5.329    0.000   19.789    0.001 /usr/lib/python3.5/threading.py:851(Thread.run)
30734/30735    0.415    0.000   16.536    0.001 /usr/lib/python3.5/threading.py:826(KeyboardListener.start)
30717/30732    0.430    0.000   14.320    0.000 /home/erb/Programming/Python/activity-watch/activitywatch/watchers/afk.py:12(_repeat_trigger)
32057/32059    0.843    0.000    9.620    0.000 /usr/lib/python3.5/site-packages/Xlib/protocol/display.py:621(_BaseDisplay.parse_response)
62853/62855    0.774    0.000    8.499    0.000 /usr/lib/python3.5/site-packages/Xlib/protocol/display.py:719(_BaseDisplay.parse_request_response)
51332/51333    0.589    0.000    6.584    0.000 /usr/lib/python3.5/site-packages/Xlib/ext/record.py:217(EnableContext._parse_response)
    51279    1.143    0.000    5.186    0.000 /usr/lib/python3.5/site-packages/pymouse/x11.py:205(MouseListener.handler)
3078/3079    0.045    0.000    4.119    0.001 /usr/lib/python3.5/selectors.py:356(PollSelector.select)
6138/15367    0.000    0.000    3.860    0.000 /home/erb/Programming/Python/activity-watch/activitywatch/watchers/afk.py:17(_wait_for_either)
       12    0.003    0.000    2.687    0.224 /home/erb/Programming/Python/activity-watch/activitywatch/loggers/json.py:26(JSONLogger.log)
       12    0.314    0.026    2.515    0.210 /usr/lib/python3.5/json/__init__.py:119(dump)
    51331    0.633    0.000    2.510    0.000 /usr/lib/python3.5/site-packages/Xlib/protocol/rq.py:847(EventField.parse_binary_value)
   114201    1.037    0.000    2.230    0.000 <string>:1(Struct.parse_binary)
    63377    0.435    0.000    1.946    0.000 /usr/lib/python3.5/threading.py:510(Event.set)
    51286    0.253    0.000    1.538    0.000 /usr/lib/python3.5/site-packages/Xlib/protocol/rq.py:1519(MotionNotify.__init__)
    30736    0.510    0.000    1.443    0.000 /usr/lib/python3.5/threading.py:755(KeyboardListener.__init__)
   348933    0.222    0.000    1.322    0.000 /usr/lib/python3.5/json/encoder.py:411(_iterencode)
    63377    0.336    0.000    1.156    0.000 /usr/lib/python3.5/threading.py:355(Condition.notify_all)
    48436    0.104    0.000    1.145    0.000 /home/erb/Programming/Python/activity-watch/activitywatch/watchers/afk.py:123(MouseListener.move)
348933/697662    0.535    0.000    1.099    0.000 /usr/lib/python3.5/json/encoder.py:332(_iterencode_dict)
348765/475662    0.395    0.000    0.883    0.000 /usr/lib/python3.5/json/encoder.py:276(_iterencode_list)
    46116    0.251    0.000    0.827    0.000 /usr/lib/python3.5/threading.py:496(Event.__init__)
    63377    0.457    0.000    0.769    0.000 /usr/lib/python3.5/threading.py:332(Condition.notify)
   154011    0.398    0.000    0.766    0.000 /usr/lib/python3.5/site-packages/Xlib/protocol/rq.py:295(Window.parse_value)
   169059    0.526    0.000    0.734    0.000 /usr/lib/python3.5/threading.py:237(Condition.__enter__)
    15364    0.312    0.000    0.706    0.000 /home/erb/Programming/Python/activity-watch/activitywatch/base.py:101(AFKWatcher.settings)
   169042    0.530    0.000    0.683    0.000 /usr/lib/python3.5/threading.py:240(Condition.__exit__)
    62855    0.433    0.000    0.562    0.000 /usr/lib/python3.5/site-packages/Xlib/protocol/display.py:838(_BaseDisplay.get_waiting_replyrequest)
   129767    0.355    0.000    0.530    0.000 /usr/lib/python3.5/threading.py:252(Condition._is_owned)
    46116    0.518    0.000    0.518    0.000 /usr/lib/python3.5/threading.py:213(Condition.__init__)
    66373    0.277    0.000    0.418    0.000 /usr/lib/python3.5/threading.py:249(Condition._acquire_restore)
    11448    0.119    0.000    0.418    0.000 /usr/lib/python3.5/site-packages/Xlib/protocol/rq.py:1503(InternAtom._parse_response)
   348933    0.287    0.000    0.399    0.000 /usr/lib/python3.5/codecs.py:326(IncrementalDecoder.reset)
    46092    0.215    0.000    0.362    0.000 /home/erb/Programming/Python/activity-watch/activitywatch/base.py:116(AFKWatcher.agent_type)
51359/51433    0.197    0.000    0.359    0.000 <frozen importlib._bootstrap>:996(_handle_fromlist)
   407912    0.348    0.000    0.348    0.000 /usr/lib/python3.5/site-packages/Xlib/protocol/rq.py:1413(DictWrapper.__getattr__)
    11494    0.128    0.000    0.347    0.000 <string>:1(Struct.to_binary)
    28816    0.152    0.000    0.340    0.000 /usr/lib/python3.5/threading.py:521(Event.clear)
    30717    0.221    0.000    0.271    0.000 /usr/lib/python3.5/_weakrefset.py:38(_remove)
    66390    0.209    0.000    0.268    0.000 /usr/lib/python3.5/threading.py:246(Condition._release_save)
   102681    0.155    0.000    0.217    0.000 /usr/lib/python3.5/site-packages/Xlib/protocol/display.py:276(_BaseDisplay.get_resource_class)
    11533    0.163    0.000    0.214    0.000 /usr/lib/python3.5/site-packages/Xlib/protocol/display.py:310(_BaseDisplay.send_request)
   114058    0.211    0.000    0.211    0.000 /usr/lib/python3.5/site-packages/Xlib/xobject/resource.py:22(Window.__init__)
       50    0.000    0.000    0.189    0.004 /home/erb/.local/lib/python3.5/site-packages/psutil/_pslinux.py:807(Process.wrapper)
    11359    0.047    0.000    0.179    0.000 /home/erb/Programming/Python/activity-watch/activitywatch/watchers/linux.py:127(X11Watcher.get_window)
    30744    0.137    0.000    0.176    0.000 /usr/lib/python3.5/_weakrefset.py:81(WeakSet.add)
       25    0.000    0.000    0.144    0.006 /home/erb/Programming/Python/activity-watch/activitywatch/watchers/linux.py:130(get_window_name)
    11448    0.108    0.000    0.143    0.000 /usr/lib/python3.5/site-packages/Xlib/protocol/rq.py:289(Window.check_value)
        1    0.000    0.000    0.141    0.141 /home/erb/Programming/Python/activity-watch/activitywatch/main.py:7(start)
    30846    0.100    0.000    0.136    0.000 /usr/lib/python3.5/threading.py:1224(current_thread)
    11446    0.135    0.000    0.136    0.000 /usr/lib/python3.5/site-packages/Xlib/protocol/rq.py:629(PropertyData.parse_binary_value)
       25    0.000    0.000    0.132    0.005 /home/erb/.local/lib/python3.5/site-packages/psutil/__init__.py:601(Process.cmdline)
       25    0.005    0.000    0.132    0.005 /home/erb/.local/lib/python3.5/site-packages/psutil/_pslinux.py:877(Process.cmdline)
    11359    0.071    0.000    0.132    0.000 /usr/lib/python3.5/site-packages/Xlib/display.py:185(Display.create_resource_object)
    30739    0.126    0.000    0.126    0.000 /usr/lib/python3.5/threading.py:725(_newname)
    12/40    0.000    0.000    0.116    0.003 <frozen importlib._bootstrap>:966(_find_and_load)
    12/40    0.000    0.000    0.116    0.003 <frozen importlib._bootstrap>:939(_find_and_load_unlocked)
    12/39    0.000    0.000    0.114    0.003 <frozen importlib._bootstrap>:659(_load_unlocked)

Not sure what purpose _DummyLock.__noop is doing, but at least I have a clue now. Will investigate further when I have the time.

ErikBjare commented 8 years ago

This will be resolved by a reimplementation of the X11Watcher using xprop instead of the old Xlib wrapper library. See #25 for more info.

Closing.