Copyq: Run-away CPU-hogging on MacOS

[ppesek]

For the second time now, I've had to manually kill off CopyQ because on an otherwise idle system, it was hogging up all my resources. The context for this was a clipboard filled with a lot of short rich text cut/pastes (mailing address fragments) from Google Docs (Sheets) using the latest release of Firefox on the latest release of MacOS with the latest release of CopyQ (2.8.2).

I wouldn't have known had the fan not started going crazy on my otherwise very quiet Mac Mini...

See picture.

[hluk]

Can try this with "Save and display HTML and rich text" option disabled? (It's under "Item" tab in Configuration dialog.)

[briskycat]

I have this problem occasionally too, most often after suspend/resume. And I think I used to have it with FlyCut on earlier OS X releases.

[hluk]

It would be much easier to fix if anyone could debug the issue and send stack trace. I.e. build the app in debug mode and when the process starts to misbehave attach a debugger to it and print stacktrace (alternatively killing the process with SIGABRT might create core dump).

[briskycat]

I ran a built-in macOS profiler when it happened again:
Sample of CopyQ.txt
Sample of CopyQ_2.txt
Looks like the main culprit is PasteboardGetItemIdentifier.

By the way, it happened with the "Save and display HTML and rich text" option disabled.

From man sample:

     sample is a command-line tool for gathering data about the running behavior of a process.  It suspends the process at specified intervals (by
     default, every 1 millisecond), records the call stacks of all threads in the process at that time, then resumes the process.  The analysis done
     by sample is called ``sampling'' because it only checks the state of the program at the sampling points.  The analysis may miss execution of some
     functions that are not executing during one of the samples, but sample still provides useful data about commonly executing functions.

     At the end of the sampling duration, sample produces a report showing which functions were executing during the sampling.  The data is condensed
     into a call tree, showing the functions seen on the stack and how they were called.  (This tree is a subset of the actual call tree for the exe-
     cution, since some functions may not have been executing during any of the sampling events.)  The tree is displayed textually, with called func-
     tions indented one level to the right of the callee.

     In the call tree, if a function calls more than one function then a vertical line is printed to visually connect those separate children func-
     tions, making it easier to see which functions are at the same level.  The characters used to draw those lines, such as + | : ! are arbitrary and
     have no specific meaning.

[hluk]

Thanks for the info.

Seems that clipboard monitor process is actively looping in some Qt code when getting clipboard data.

Here is version with workaround (commit 6d399196b7ea4e6a4423d9c63a76725783c95e17): https://github.com/hluk/CopyQ/releases/download/testing/CopyQ.dmg

[flyinbutrs]

I have this same problem, and will also test that workaround.

[Fitech]

I was seeing the CPU hogging very frequently. I'm using the workaround version and it hasn't happened since. Thanks.

[briskycat]

I have been testing the workaround for more than a week now. And although in the log I have this:

Note [2017-02-02 23:53:03.741]: Loading plugin: /Applications/copyq.app/Contents/Plugins/copyq/libitemdata.dylib
Note [2017-02-02 23:53:03.802]: Loading plugin: /Applications/copyq.app/Contents/Plugins/copyq/libitemencrypted.dylib
Note [2017-02-02 23:53:03.826]: Loading plugin: /Applications/copyq.app/Contents/Plugins/copyq/libitemfakevim.dylib
Note [2017-02-02 23:53:03.858]: Loading plugin: /Applications/copyq.app/Contents/Plugins/copyq/libitemimage.dylib
Note [2017-02-02 23:53:03.894]: Loading plugin: /Applications/copyq.app/Contents/Plugins/copyq/libitemnotes.dylib
Note [2017-02-02 23:53:03.938]: Loading plugin: /Applications/copyq.app/Contents/Plugins/copyq/libitemsync.dylib
Note [2017-02-02 23:53:03.975]: Loading plugin: /Applications/copyq.app/Contents/Plugins/copyq/libitemtags.dylib
Note [2017-02-02 23:53:04.008]: Loading plugin: /Applications/copyq.app/Contents/Plugins/copyq/libitemtext.dylib
ERROR [2017-02-03 13:06:56.811]: Remote process: Connection timeout!
ERROR [2017-02-07 12:02:56.115]: Remote process: Connection timeout!
ERROR [2017-02-13 11:50:16.076]: Remote process: Connection timeout!
ERROR [2017-02-14 16:15:42.970]: Remote process: Connection timeout!
ERROR [2017-02-14 16:16:00.970]: Remote process: Connection timeout!
ERROR [2017-02-14 16:32:11.946]: Remote process: Connection timeout!
ERROR [2017-02-14 16:32:28.946]: Remote process: Connection timeout!
ERROR [2017-02-14 16:32:45.945]: Remote process: Connection timeout!
ERROR [2017-02-14 16:33:02.945]: Remote process: Connection timeout!
ERROR [2017-02-14 16:33:19.944]: Remote process: Connection timeout!
ERROR [2017-02-14 16:33:35.944]: Remote process: Connection timeout!
ERROR [2017-02-14 16:33:53.944]: Remote process: Connection timeout!
ERROR [2017-02-14 16:34:09.943]: Remote process: Connection timeout!
ERROR [2017-02-14 16:34:25.945]: Remote process: Connection timeout!

I haven't observed any runaway processes ever since. So, I presume the workaround does work.

[hluk]

@briskycat Yup, the errors indicate that the clipboard monitor process isn't responding and it's restarted. Though it's strange that the process is restarted so many times.

[flyinbutrs]

I also haven't seen any runaway procs since testing started.

[briskycat]

@hluk It would be nice to reflect it in the log when the monitor process gets killed.

[hluk]

@briskycat I improved the error messages a bit (it will show something like Restarting clipboard monitor (Connection timeout!)).

[mrjcleaver]

Quick point of clarity - is this included in 3.0? The branch link above was updated 2 days ago, but 3.0 was released 23 days ago.

Thx.

[hluk]

@mrjcleaver The fix is included in 3.0. Is this still an issue?

[mrjcleaver]

Ah, no, it's seems fine now. Thanks!

[jialongl]

This bug is appearing again in the latest OS X test release after 3.0.1.

Note [2017-05-29 14:36:47.149] Server-24352: Command “Show/hide main window”
Note [2017-05-29 14:36:47.149] Server-24352:    Exit code: 1
Note [2017-05-29 14:36:47.149] Server-24352:    
Note [2017-05-29 14:36:47.149] Server-24352:    ERROR: Connection lost!
Note [2017-05-29 14:36:47.149] Server-24352:    
Note [2017-05-29 14:36:47.149] Server-24352:    1. copyq:  toggle()
Note [2017-05-29 14:36:47.151] Server-24352: Command “Show/hide main window”
Note [2017-05-29 14:36:47.151] Server-24352:    Exit code: 1
Note [2017-05-29 14:36:47.151] Server-24352:    
Note [2017-05-29 14:36:47.151] Server-24352:    ERROR: Connection lost!
Note [2017-05-29 14:36:47.151] Server-24352:    
Note [2017-05-29 14:36:47.151] Server-24352:    1. copyq:  toggle()
Note [2017-05-29 14:39:21.605] Server-24396: Loading plugin: /Users/jialong.liu/Applications/CopyQ.app/Contents/Plugins/copyq/libitemdata.dylib
Note [2017-05-29 14:39:21.606] Server-24396: Loading plugin: /Users/jialong.liu/Applications/CopyQ.app/Contents/Plugins/copyq/libitemencrypted.dylib
Note [2017-05-29 14:39:21.606] Server-24396: Loading plugin: /Users/jialong.liu/Applications/CopyQ.app/Contents/Plugins/copyq/libitemfakevim.dylib
Note [2017-05-29 14:39:21.607] Server-24396: Loading plugin: /Users/jialong.liu/Applications/CopyQ.app/Contents/Plugins/copyq/libitemimage.dylib
Note [2017-05-29 14:39:21.608] Server-24396: Loading plugin: /Users/jialong.liu/Applications/CopyQ.app/Contents/Plugins/copyq/libitemnotes.dylib
Note [2017-05-29 14:39:21.608] Server-24396: Loading plugin: /Users/jialong.liu/Applications/CopyQ.app/Contents/Plugins/copyq/libitempinned.dylib
Note [2017-05-29 14:39:21.609] Server-24396: Loading plugin: /Users/jialong.liu/Applications/CopyQ.app/Contents/Plugins/copyq/libitemsync.dylib
Note [2017-05-29 14:39:21.610] Server-24396: Loading plugin: /Users/jialong.liu/Applications/CopyQ.app/Contents/Plugins/copyq/libitemtags.dylib
Note [2017-05-29 14:39:21.611] Server-24396: Loading plugin: /Users/jialong.liu/Applications/CopyQ.app/Contents/Plugins/copyq/libitemtext.dylib
ERROR [2017-05-29 14:40:01.711] Server-24396: Restarting clipboard monitor (Connection timeout)
ERROR [2017-05-29 14:40:46.801] Server-24396: Restarting clipboard monitor (Connection timeout)

[hluk]

@jialongl I cannot reproduce it with latest pre-release on Sierra 10.12.5. Do you know when it happens?

[jialongl]

@hluk I am sorry that I confused myself. The bug happened in version 3.0.1 actually, when I have copyQ main window shown. As soon as the main window shown, CPU usage hikes.

I used the "CopyQ About" window for the version info, and I thought the version number for the pre-release stays the same as the prior stable release.
I am now using the pre-release on Sierra 10.12.5, version 3.0.1-g22be297, and the problem is gone.

Sorry for all the confusion.
But by the way, you do have come across with the problem on 3.0.1, haven't you?

[hluk]

@jialongl Yes, I remember your issue was related to some rendering problems which was fixed some time after 3.0.1 was released.

The versioning for pre-release was also fixed recently.

I'll try to release new app version ASAP. Thanks for the report.

[jialongl]

No, thank you Lucas, for keeping up the good work!