Windows CPU resource at 15%

[Kevin]

Have installed Ver 0.48 on Windows XP (latest SP's and patches) on Dell Vostro 1500.
Inkscape appears to operate correctly but Windows task manager reports the CPU usage at 12 to 20% for Inkscape continuously even when it is inactive and minimised.

[David Mathog (mathog)]

Ditto.

Windows XP SP3
Inkscape built on Mingw from source, identifies itself as 0.48+devel

[David Mathog (mathog)]

This is probably irrelevant, but the hardware is a Gigabyte MA785GMT-UD2H motherboard with a dual core Athlon X2 245.

[David Mathog (mathog)]

I built a version of trunk with -g -pg and managed to get a gmon.out. (Only by running inkscape.exe from within the debugger - the programming tools under mingw are a bit iffy. If run by itself inkscape.exe created a tiny gmon.out file which was almost entirely null bytes) Let the application sit idle for a while, then quit. Did that twice. Results were the same both times.

gprof inkscape.exe gmon.out >killme.txt

Also, while it was running in gdb, sent inkscape an interrupt using debugbreak

  http://www.mingw.org/wiki/Workaround_for_GDB_Ctrl_C_Interrupt

and then ran "bt" on all threads. Did that a few times and the results were similar each time.

Anyway, the bt info and the top of the gprof results are attached. The latter seems to implicate
the handleTimerCB method, which is in swatches.cpp.

Have there been any changes to swatches.cpp in the time frame where the CPU use on Windows increased?

The backtrace on thread 1 always shows it in libglib in g_poll and poll_rest. I kind of doubt that is the issue because if it was every piece of mingw code that used the same polling mechanism would have a similar background CPU level. Unless maybe a timeout value is passed in somewhere as a parameter, and that is now too short, leading to excessive activity during the polling.

[David Mathog (mathog)]

Tested inkscape releases going back and found that inkscape.exe (0.48.1-2 = r9819) was the last release that did not have the high idle CPU problem. 0.48.2 has the 16-17% idle.

In order to determine if it was a devlibs problem or an inkscape.exe problem, took the inkscape.exe from 0.48.1-2, renamed
it inkscape0481.exe, and copied it into the 0.48.2 directory. Ran it there. Idle CPU was zero. Then copied inkscape0481.exe to
the latest trunk build I had (r11289) and it ran with those dll's too, again, with 0% idle CPU.

The inverse experiment wasn't possible -newer inkscape.exe would not run with older dll's.

What revision was 0.48.1-2? It seems to be about halfway between 0.48.0 (r9654) and 0.48.2-1 (r9819).

[su_v (suv-lp)]

> What revision was 0.48.1-2?

Inkscape 0.48.0 r9654
<http://bazaar.launchpad.net/~inkscape.dev/inkscape/RELEASE_0_48_BRANCH/changes/9654>
Inkscape 0.48.1 r9760
<http://bazaar.launchpad.net/~inkscape.dev/inkscape/RELEASE_0_48_BRANCH/changes/9760>
Inkscape 0.48.2 r9819
<http://bazaar.launchpad.net/~inkscape.dev/inkscape/RELEASE_0_48_BRANCH/changes/9819>
Inkscape 0.48.3.1 r9886
<http://bazaar.launchpad.net/~inkscape.dev/inkscape/RELEASE_0_48_BRANCH/changes/9886>

[David Mathog (mathog)]

OK, found the patch that is causing it, which is:

http://bazaar.launchpad.net/~inkscape.dev/inkscape/RELEASE_0_48_BRANCH/revision/9782

(I could not find the corresponding patch in trunk, and it is not noted in 9782.)

As I guessed in comment 3 above, it is the modification to swatches.cpp/swatches.h. The last revision I built
was 0_48_BRANCH/revision/9789 which had the 16% CPU. Swapped out the two swatches files with some from
trunk revision 9811 (which do not have these changes), rebuilt, and idle CPU went to 0%.

Now the question is - why? Presumably on Mac and Linux this sort of CPU usage isn't seen, so there is something
about this code which is bad specifically for windows. Perhaps something in GTK or GDK is using a glib timer on Windows where on mac/linux it is using select(), and something in this code is kicking that awake while it should stay asleep?

Also, hard to see why the swatches dialog is being run here in the first place - my test case is an inkscape window open with nothing turned on, just a blank drawing surface. The idle CPU usage is high even when the window is minimized, no way a dialog should be doing that.

Anyway, in branch 48 rev 9789 changed in swatches.cpp this

            refreshTimer = Glib::signal_timeout().connect( sigc::ptr_fun(handleTimerCB), 33 );

to this

            refreshTimer = Glib::signal_timeout().connect( sigc::ptr_fun(handleTimerCB), 330 );

and the idle CPU usage dropped to 2%. Tried that on a recent trunk (11289) and again, the idle CPU use dropped to 2%.

So, in summary, we now know where, but at least for me, why is still obscure.

[Kris (kris-degussem)]

To be honest, I do not encounter the issue (vista 64 bit) with current trunk. No abnormal CPU usage. FYI: it was trunk revision 10244 that is corresponding to the above mentioned revision 9782.

[David Mathog (mathog)]

To expand a little on what might be going on here, look at:

  http://developer.gnome.org/glib/2.31/glib-The-Main-Event-Loop.html#g-poll

which was implicated by the gdb interrupt tests (comment 4), and

  http://developer.gnome.org/glibmm/unstable/classGlib_1_1SignalTimeout.html

which is definitely involved. On non-posix systems like OpenVMS, and I think here Windows (thanks to Dave Cutler) both the system level timer function and the equivalent of select() work on event flags and not fd's. If an event flag is reused, or there is some other type of interference, the wrong timer can wake up. Here handleTimerCB is being invoked, but by which event? The Glib::signal_timeout().connect method does not explicitly specify an event flag (or an fd), but I bet it uses one. If on Windows it happens to be the same one that g_poll or some other timer in Inkscape uses then a collision will occur. The same code could work perfectly well on Linux/Mac because the timers use different code than on Windows.

This could all be tremendously off target, but it does feel an awful lot like some issues I ran into long, long ago while working on X11 programs on OpenVMS systems. Have to find the source code for g_poll and signal_timeout to see if this might be
the issue here as well.

[David Mathog (mathog)]

This sounds like a very similar issue:

http://mail.gnome.org/archives/gtkmm-list/2009-July/msg00127.html

Have sent email to "Weise" asking what the workaround was. Hopefully he/she still monitors that sourceforge.jp address.

[David Mathog (mathog)]

It turns out it is EXACTLY the same issue. I took the small example file he posted, changed the timeout value to match inkscape's (33 milliseconds) and it ran at exactly the same 16-17% cpu usage on my machine.

To build this on a windows machine (needs mingw and devlibs already installed):

1. unpack the .zip file
2. in a command shell cd to that directory
3. modify mingwenv.bat to match your system
4. mingwenv
5. buildtest_glib_bug
6. test_glib_bug
7. open task manager and look at that process.

[David Mathog (mathog)]

Since this is some Gnome/Windows bug I will report it there (when I can figure out where "there" is).
This was all on XP SP3, 32 bit, dual processor.

[David Mathog (mathog)]

Try to upload attachment again, it seems to have not made it.

[David Mathog (mathog)]

Reported this problem here:

https://bugzilla.gnome.org/show_bug.cgi?id=675485

[David Mathog (mathog)]

Moved problem from glibmm to glib, as that is where the patch to fix it must go.

https://bugzilla.gnome.org/show_bug.cgi?id=675695

Since it is a glib problem hopefully the upstream package will eventually be changed. In the meantime, whoever is maintaining devlibs could maybe put in the (tiny) changes needed to squish this CPU problem on Inkscape? Note the "fix" just disables the ability to set a timer shorter than 10ms. I could not "feel" any difference when Inkscape was run that way, but perhaps there is some tool that might be sensitive to it.

The change to glib resolves this issue through trunk 11289, which is the most recent version tested.

This is the change to the g_timeout_prepare function in glib/gmain.c that fixes the issue:

  if (now < timeout_source->expiration
#ifdef G_OS_WIN32
      && timeout_source->expiration - now > 10000) //minimum of 10msec wait
#else
      )
#endif
    {
      /* Round up to ensure that we don't try again too early */
      *timeout = (timeout_source->expiration - now + 999) / 1000;
      return FALSE;
    }

[David Mathog (mathog)]

Also, for whoever came up with the code that went in as revision 4782, why the short (33 msec) timer, and for that matter, what exactly does that code change do?

The glib bug only manifests for very short timers. Would 200 msec work here as well? I never use swatches and don't see the need for that one piece of code to be interrupting the program 30 times/second (nearly a video frame rate), especially when in Inkscape the swatch dialog is not open and the document uses no swatches!

[su_v (suv-lp)]

> Also, for whoever came up with the code that went in as revision 4782, why the
> short (33 msec) timer, and for that matter, what exactly does that code change do?

Both revisions (trunk, 0.48.x) had been by Jon Cruz, to address bug #734981:

Revision 10244:
Queue swatch updates during periods of high UI usage, such as dragging gradient handles. Fixes bug #734981.
<http://bazaar.launchpad.net/~inkscape.dev/inkscape/trunk/revision/10244>

Revision 9782:
Backport of UI performance fix.
<http://bazaar.launchpad.net/~inkscape.dev/inkscape/RELEASE_0_48_BRANCH/revision/9782>

@Jon Cruz - subscribing you to this report: any chance you could revisit the changes in revision 10244 and review the proposed workaround to avoid this CPU load on certain Windows systems (not all seem to be affected)?

[Kris (kris-degussem)]

Considering the bug as confirmed as another duplicate report (#1047874) was filed recently.

[David Mathog (mathog)]

If your machine has this problem and you are using devlibs 32 here are two versions of libglib-2.0-0.dll, the first one
with the patch that eliminated the problem on my XP machine, and the second without the patch. Copy both into
$devlibs_path/bin. Copy one or the other over libglib-2.0-0.dll and look at the CPU time used when inkscape runs (it must
be restarted after the copy!) On my system the no15cpu version eliminates the CPU usage issue, whereas the has15cpu brings it back.

http://saf.bio.caltech.edu/pub/software/windows/libglib-2.0-0.dll_no15cpu
http://saf.bio.caltech.edu/pub/software/windows/libglib-2.0-0.dll_has15cpu

The no15cpu version also works when copied into an Inkscape distributions (no separate devlib).

[Kevin (khobbs)]

I tried the above "by David wrote on 2012-09-13: "

BUT then get an error libintl-8.dll was not found.

I subsequently found a post that implied the latest release worked and fixed this so did a new download and install of Inkscape-0.48.2-1-win32 (may have been the same version as already installed).
Running this has the same 15% CPU issue and replacing the libglib file causes the libintl-*.dll error so is not a fix for my system.

[Alvin Penner (apenner)]

actually, the latest stable release is 0.48.3.1-2.exe, created on June 30. available at:

http://sourceforge.net/projects/inkscape/files/inkscape/0.48.3.1/

however, I am not sure if it is specifically related to release number, all I know is that this version does not show the bug for me on Windows 7 (32 bit)

[Kevin (khobbs)]

Thanks Alvin, using release is 0.48.3.1-2.exe plus the libglib dll posted by David has solved the 15% CPU issue!

THANK YOU TO EVERYONE.

[jazzynico (jazzynico)]

@Kevin, Mathog, could you please test again with Inkscape 0.48.4?
I've just tested it, and can't reproduce the bug on Windows XP.

[David Mathog (mathog)]

0.48.4 on XP 32 bit did NOT have the high CPU problem, even though the libglib-2.0-0.dll is the same one that I
had to patch to resolve the problem in earlier versions of Inkscape. (Files have the same md5sum value.)

Went back to my WIndows development version, r11719 in branch lp988601 and removed the special dll and put the default one
back in. No CPU usage increase.

So some change in Inkscape's code has worked around the libglib CPU issue. However, it is apparently not the case that the underlying libglib-2.0-0.dll issue has been resolved. Do you have any idea what change might have been introduced into Inkscape
to resolve this issue? I am afraid that if we mark this one as solved without knowing why, it will rear its ugly head again when some other apparently unrelated change erases the mysterious and otherwise unknown "fix".

[Lukasz Sczygiel (sczygiel)]

Hi, I am observing this bug for a while.
I am experiencing it under windows xp.
version Inkscape 0.48+devel r12685 behaves similarily as Inkscape 0.48.4 r9939 so I assume bug is still there.

I have been diagnosing it with processexplorer and found out that there is a lot of context switches for:
inkscape.exe+0x1140
And stack for it is:
ntoskrnl.exe!ExReleaseResourceLite+0x206
ntoskrnl.exe!ProbeForWrite+0x505
ntoskrnl.exe!ZwYieldExecution+0xb78
ntdll.dll!KiFastSystemCallRet
USER32.dll!GetLastInputInfo+0x105
libglib-2.0-0.dll!g_pattern_match_simple+0xf9
libglib-2.0-0.dll!g_poll+0x105
libglib-2.0-0.dll!g_main_context_dispatch+0x67a
libglib-2.0-0.dll!g_main_loop_run+0x125
libgtk-win32-2.0-0.dll!gtk_main+0xa0
libgtkmm-2.4-1.dll!ZN3Gtk4Main3runEv+0x13
inkscape.exe+0x621e
inkscape.exe+0x57276
inkscape.exe+0x595d
inkscape.exe+0x10db
inkscape.exe+0x1158
kernel32.dll!RegisterWaitForInputIdle+0x49

I have no idea if it helps but here it is ;)
For both versions (stable and development) address of a thread which switches frequenty is the same.
I have no idea how to look what it is :(

[David Mathog (mathog)]

I just built trunk (r12704) from scratch, with devlibs 47, and the problem is not present. This trunk version is not using the alternate libglib-2.0-0.dll that I posted in message 19 above. If you are running a version of inkscape on windows that still has the problem, try dropping the _no15cpu version over the libglib dll that you are currently using.