[Bug 24044] New: Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

Summary: Miranda and wineserver consume too many CPU cycles
           Product: Wine
           Version: 1.3.0
          Platform: x86
               URL: http://miranda.googlecode.com/files/miranda-im-v0.8.27
                    -unicode.zip
        OS/Version: Linux
            Status: UNCONFIRMED
          Severity: normal
          Priority: P2
         Component: -unknown
        AssignedTo: [e-mail]
        ReportedBy: [e-mail]

Created an attachment (id=30219)
 --> (http://bugs.winehq.org/attachment.cgi?id=30219)
five (!) seconds strace of Miranda32.exe process

Steps to reproduce:

1) Register an ICQ account
2) Run Minanda with this account

Result:
Miranda + wineserver will be incessantly consuming around 8% of CPU time.

Expected result:
zero CPU usage (as in Windows).

strace of miranda32.exe process shows that it reads and writes tons of data
from and to unnamed pipes (see the attached file, fd 3 and 5 are unnamed
pipes).

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

Artem S. Tashkinov  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
           Keywords|                            |download, source

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

--- Comment #1 from Artem S. Tashkinov   2010-08-19 03:36:00 ---
Created an attachment (id=30220)
 --> (http://bugs.winehq.org/attachment.cgi?id=30220)
five seconds strace of wineserver process

fd 23 and 24 are also unnamed pipes.

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

--- Comment #2 from Alexandre Julliard   2010-08-19 05:11:32 ---
That's just the app making server calls, most likely it's normal behavior. You
can get a +server trace to find out what it's doing.

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

--- Comment #3 from Artem S. Tashkinov   2010-08-19 05:39:17 ---
Created an attachment (id=30222)
 --> (http://bugs.winehq.org/attachment.cgi?id=30222)
five seconds WINEDEBUG=+server strace log

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

Artem S. Tashkinov  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
  Attachment #30222|five seconds                |five seconds
        description|WINEDEBUG=+server strace    |WINEDEBUG=+server trace log
                   |log                         |

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

--- Comment #4 from Alexandre Julliard   2010-08-19 06:01:55 ---
Looks like a bunch of window timers are still running, and the app is trying to
delete invalid ones. Maybe some confusion with timer ids. I'd suggest to first
try a message spy under Windows to check if it also happens there.

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

--- Comment #5 from Artem S. Tashkinov   2010-08-19 06:23:10 ---
I've downloaded SpyEx (http://thesz.diecru.eu/content/spyex.php) and ran it
this way: window plus Childs (sic).

Messages window remains empty, as if nothing is happening in Miranda.

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

Dmitry Timoshkov  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
           Severity|normal                      |minor

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

Anastasius Focht  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |[e-mail]

--- Comment #6 from Anastasius Focht   2010-08-20 05:11:18 ---
Hello,

looks like the Miranda Database Driver plugin is the culprit here.
For unicode builds the default db driver is "dbx_mmap".
For ansi builds the default db driver is "dbx_3x".

The mmap plugin sets up a fast running timer (and restarts it) to flush mapped
sections to disk (hence it's not recommended to run this on network shares).

The source of the plugin is available so you can take a look by yourself:

http://addons.miranda-im.org/details.php?action=viewfile&id=3601

--- snip dbcache.c ---
void DBFlush(int setting)
{
    if(!setting) {
        log0("nflush1");
        if(safetyMode && pDbCache) {
            if (FlushViewOfFile(pDbCache, 0) == 0)
                DatabaseCorruption(NULL);
        }
        log0("nflush2");
        return;
    }
    KillTimer(NULL,flushBuffersTimerId);

flushBuffersTimerId=SetTimer(NULL,flushBuffersTimerId,50,DoBufferFlushTimerProc);
}

...
static VOID CALLBACK DoBufferFlushTimerProc(HWND hwnd,UINT message,UINT
idEvent,DWORD dwTime)
{
    if (!pDbCache) return;

KillTimer(NULL,flushBuffersTimerId);
    log0("tflush1");
    if (FlushViewOfFile(pDbCache, 0) == 0)
        DatabaseCorruption(NULL);
    log0("tflush2");
}
--- snip dbcache.c ---

This creates a lot of context switches, responsible for some cpu load (on older
machines).
On modern machines the load should be well below 1-2%, if any. Though it's
still a lot of context switches which drops overall performance.

Anyway, you can't directly compare Windows CPU usage with Linux. It's
calculated differently and Windows technically cheats/lies about it.
I explained it partly here (emule cpu usage):
http://bugs.winehq.org/show_bug.cgi?id=6936#c25

If you ask me -> not fixable in Wine. Switch to ANSI build which uses
dbx_3x.dll.

Regards

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

--- Comment #7 from Anastasius Focht   2010-08-20 05:35:41 ---
Hello,

well the real cause seems to be the icq.dll plugin itself which causes rewrite
of contact settings in short intervals that internally triggers DBFlush(1) from
dbx_mmap() plugin.
Still looking into this ...

Regards

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

--- Comment #8 from Anastasius Focht   2010-08-20 07:49:25 ---
Hello again,

well I came to conclusion this is an app multithreading bug (race) exposed by
different thread timing (execution profile) between Windows and Linux.

Although the icq plugin commits lots of setting changes initially, triggering
the flushes, it should be done after a certain amount of time and not recurring
in so fast intervals (except if the server packet loop brings back large amount
of change data which triggers settings write again).

http://miranda.googlecode.com/files/miranda-im-v0.8.27-src.zip
http://miranda.googlecode.com/files/miranda-im-v0.8.27-unicode-pdb.zip

dbx_mmap plugin source: miranda\plugins\db3x_mmap
ICQ plugin source: miranda\protocols\IcqOscarJ\

I previously posted the snippet, hence again when looking from "multithreaded"
perspective creating and killing timers in that way this is rather bad and
prone races (flushBuffersTimerId is not guarded in any way!):
Due to races, some of the created "flush" timers might escape destruction and
continue to be "free running", resulting in cpu load.

--- snip ---
static UINT_PTR flushBuffersTimerId;

static VOID CALLBACK DoBufferFlushTimerProc(HWND hwnd, UINT message, UINT_PTR
idEvent, DWORD dwTime)
{
    if (!pDbCache) return;

KillTimer(NULL,flushBuffersTimerId);
    log0("tflush1");
    if (FlushViewOfFile(pDbCache, 0) == 0)
        DatabaseCorruption(NULL);
    log0("tflush2");
}

void DBFlush(int setting)
{
    if(!setting) {
        log0("nflush1");
        if(safetyMode && pDbCache) {
            if (FlushViewOfFile(pDbCache, 0) == 0)
                DatabaseCorruption(NULL);
        }
        log0("nflush2");
        return;
    }
    KillTimer(NULL,flushBuffersTimerId);

flushBuffersTimerId=SetTimer(NULL,flushBuffersTimerId,50,DoBufferFlushTimerProc);
}
--- snip ---

Using a critical section should cure this (maybe the already present
"csDbAccess" one).

Regards

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

Artem S. Tashkinov  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|UNCONFIRMED                 |RESOLVED
         Resolution|                            |INVALID

--- Comment #9 from Artem S. Tashkinov   2010-08-20 08:06:40 ---
(In reply to comment #8)
> Hello again,
>
> well I came to conclusion this is an app multithreading bug (race) exposed by
> different thread timing (execution profile) between Windows and Linux.

You are insightful! Thank you very much. I will try to notify Miranda
developers of this bug.

And you were really right about ICQ plugin: as soon as I disabled it, wine and
miranda had their CPU usage decreased to 0%.

I suppose we can safely close this bug report as INVALID.

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

Nikolay Sivov  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|RESOLVED                    |CLOSED

--- Comment #10 from Nikolay Sivov   2010-08-20 08:09:52 ---
Closing. Artem, please find a time to file a bug to miranda, cause a problem is
obvious now after such analysis.

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

--- Comment #11 from Artem S. Tashkinov   2010-08-20 08:16:41 ---
And BTW this problem mostly concerns only a custom plugin by SSS:
http://sss.chaoslab.ru:81/tracker/icqjplus/

I've now reverted to a default ICQ plugin and CPU usage has vastly improved
(was ~8%, now 2%).

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

Alexandr  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
     Ever Confirmed|0                           |1

--- Comment #12 from Alexandr   2010-08-23 21:41:56 ---
*** This bug has been confirmed by popular vote. ***

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

Sergiy Zuban  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |[e-mail]

--- Comment #13 from Sergiy Zuban  2011-02-22 03:41:29 CST ---
(In reply to comment #11)
> And BTW this problem mostly concerns only a custom plugin by SSS:
> http://sss.chaoslab.ru:81/tracker/icqjplus/
>
> I've now reverted to a default ICQ plugin and CPU usage has vastly improved
> (was ~8%, now 2%).

I used miranda with ubuntu+wine for more than 3 years and CPU load wasn't a big
problem for me. But I've just migrated from ext3 to ext4 and noticed that
miranda cause continuous hard disk accesses (HDD led is always ON). I worry
that my HDD will die in near future with such activity.

In WINEDEBUG=trace+all log (attached) I see continuous 
KERNEL32.FlushViewOfFile calls when miranda is idle. Could someone take a look
on the log and confirm HDD activity caused by miranda itself but not wine?

I'm using the latest miranda 0.9.16 with standard plugins. Per what I see core
of the problem not only in ICQ plugin - jabber cause the same activity. I
believe problem in dbx_mmap.dll driver. In any case i'm going to file a but to
miranda, but anyway I can't figure out why ext4 cause such problems. Could this
be related to the way how Wine maps KERNEL32.FlushViewOfFile calls?
I've tried different mounting options in fstab, even commit=10 option which per
my understanding should avoid so frequent flushing to disk - all attempts with
no luck.

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

--- Comment #14 from Sergiy Zuban  2011-02-22 03:42:30 CST ---
Created an attachment (id=33399)
 --> (http://bugs.winehq.org/attachment.cgi?id=33399)
WINEDEBUG=trace+all

[Bug 24044] Miranda and wineserver consume too many CPU cycles

http://bugs.winehq.org/show_bug.cgi?id=24044

--- Comment #15 from Artem S. Tashkinov  2011-02-22 09:06:41 CST ---
(In reply to comment #13)
> (In reply to comment #11)

-- cut --

This bug is being tracked here:
https://bugzilla.kernel.org/show_bug.cgi?id=14972

Unfortunately Linux kernel ext4fs developers don't care.