Bug 382152 - Skrooge over network data maxes CPU on one core during several seconds when setting an operation's category
Summary: Skrooge over network data maxes CPU on one core during several seconds when s...
Status: RESOLVED FIXED
Alias: None
Product: skrooge
Classification: Applications
Component: general (show other bugs)
Version: unspecified
Platform: Other Linux
: NOR normal
Target Milestone: ---
Assignee: Stephane MANKOWSKI
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-07-09 12:35 UTC by Benoît Robin
Modified: 2017-08-13 10:54 UTC (History)
1 user (show)

See Also:
Latest Commit:
Version Fixed In:


Attachments
Profiling when the issue occurs (16.15 KB, text/plain)
2017-08-12 10:34 UTC, Benoît Robin
Details
Report of Profiling + SQL (28.00 KB, text/plain)
2017-08-13 06:47 UTC, Benoît Robin
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Benoît Robin 2017-07-09 12:35:14 UTC
I run Skrooge 2.8.1 on Ubuntu 16.04 LTS using KDE fw 5.18.0, Qt 5.5.1 and xcb. My main Skrooge file is around 9 MB large.

Since migrating to Skrooge 2.8.1 from the previous version I got from Ubuntu standard software repos (don't remember which one it was), I noticed that, when validating an operation's category, Skrooge freezed a few split-seconds, along with a CPU surge briefly maxing out one core.

Then I switched all my data to NAS (Thecus N3200 over 1 Gbps) to share them over several computers, including of course the Skrooge data.

Now the freeze and CPU max-out last several seconds, I roughly measured from 15s to 30s.

I've searched for such issue, FAQ indicates to disable balance computing, I did it, it didn't improve anything and I need balances, so I re-enabled them.

My best (wild) guess is for a cumulative effect of 3 factors :
- Never removed history over several years (just learned it could be done !),
- Migration from Ubuntu's older Skrooge to 2.8.1,
- Added network latency.

I'll first try removing the history (but I'm currently doing my accounting and just stopped a couple minutes to file this bug report, so I'll do it afterwards and post the result as a follow-up.

For the rest I have no idea... Thanks if anyone has...
Comment 1 Benoît Robin 2017-07-09 12:52:06 UTC
Seemingly regardless of the number of operations to catgorize, CPU surge is between 25-35s.
Comment 2 Benoît Robin 2017-07-09 12:56:42 UTC
Also remarked there is no network activity at all during the CPU surge.
Comment 3 Benoît Robin 2017-07-09 13:30:52 UTC
Removing history reduces file size to 3.5 MB, but doesn't change anything to the CPU surge.

I also remarked that, when opening the file, there was a brief (5s) network peak, corresponding to the file read, then the CPU climbed to one core 100% and stayed there for the usual 30-some seconds. Still no network activity during CPU surge.
Comment 4 Benoît Robin 2017-07-09 13:37:47 UTC
Copied the file to a local disk and tested. Just the same CPU surge as before, so my conclusion is now that NETWORK IS NOT GUILTY !

Seems my first observation of a second-long surge was wrong... It's a memory from 3 weeks ago, so don't take it into account...

Unfortunately, I now have no box left on the old Skrooge version to check with my save of the old file before migration. Btw, I found the old version number : it was 1.9.3 !
Comment 5 Stephane MANKOWSKI 2017-07-09 17:35:39 UTC
Hi,

Could you try this from a console?
export SKGTRACEPERFO=1
skrooge
Play your scenario except the action causing the issue.
Click on Tools/Restart Profiling
Play the last action causing the issue.
Click on Tools/Open Profiling
==> A page has been opened.
Copy and paste the content here.
Comment 6 Stephane MANKOWSKI 2017-07-11 09:43:23 UTC
Did you do the test?
Comment 7 Stephane MANKOWSKI 2017-07-18 15:00:01 UTC
Did you do the test?
I need your help to be able to correct this potential issue.
Comment 8 Christoph Feck 2017-07-26 18:04:41 UTC
If you can provide the information requested in comment #5, please add it.
Comment 9 Christoph Feck 2017-08-07 18:20:29 UTC
To further investigate this issue, KDE developers need the information requested in comment #5. If you can provide it, or need help with finding that information, please add a comment.
Comment 10 Benoît Robin 2017-08-07 19:49:08 UTC
Hi Stephane, just read your comments, I'll run the test when I got time, tomorrow evening at best or by next week-end at worst.
Comment 11 Benoît Robin 2017-08-12 10:34:29 UTC
Created attachment 107224 [details]
Profiling when the issue occurs

Scenario :
- Console : export SKGTRACEPERFO=1,
- Launch Skrooge,
- Open my accounting file : shows around 35s of CPU max,
- Go to any account,
- Tools > Restart Profiling,
- Change the category on an operation : shows around 35s of CPU max,
- Tools > Open Profiling,
- Copy and Paste in 2017-08-12-Profiling-Report.csv file.
Comment 12 Benoît Robin 2017-08-12 10:35:59 UTC
Hi Stephane, hi Christoph,


Just attached the profiling information.

Hope it'll help you to do Skuld job on the bug ^-^


Best regards,

Benoît 'Mutos' Robin
Comment 13 Stephane MANKOWSKI 2017-08-12 11:10:21 UTC
Hi,

This helps a lot.
Indeed, we can see that line:
virtual SKGAdviceList SKGPayeePlugin::advice(const QStringList&) ;1; 32888.54614 ; 32888.54614 ; 32888.54614 ; 32888.54614 ; 32888.54614 ; 32888.54614

It means that the computation of the advices around "Payee" took 32000 ms (32s).
This is really interesting.

First: You certainly have a dashboard opened when you do a modification on operation. On this dashboard, you have the "Advice" widget. This widget takes time. So you have 2 workarounds:
1- You can close your dashboard when you do a modification but you will still have bad performances when you will open it again.
2- You can remove the "Advice" widget from the dashboard.

Second: I published today a new version of Skrooge (2.9.0). On this version, the dashboard is not refreshed when this is not the displayed page. This should be better for you. It means that you don't have to close the dashboard when you do a modification on operations but you will still have bad performances when you will switch on dashboard.

Last: This could be interesting to find why the "Payee" advice has so bad performances. Could you do that?
export SKGTRACESQL=10000
run skrooge, play you scenario and send me the traces (you should see the SQL query causing issue)

Could you give me the number of payees you have in your document too?

Regards.
Comment 14 Stephane MANKOWSKI 2017-08-12 11:12:30 UTC
One last question: Are you french?

I am.
Comment 15 Stephane MANKOWSKI 2017-08-12 11:16:33 UTC
On last comment:
In 2.9.0, I did the correction Better performance in advice "Some payees seem to be identical".
This new version should be good for you.
To install it: https://launchpad.net/~s-mankowski/+archive/ubuntu/ppa-kf5
Comment 16 Benoît Robin 2017-08-13 06:10:36 UTC
Hi Stephane,


Thanks for the fix and advice ! This morning, I remarked a skrooge update passed and thought you might have found the issue ^-^

I don't know what is a payee, so I can't answer your question about their number. I'll search that. Accounting for me is just importing my bank's files, marking operations with categories and from time to time issuing a report of category summaries.

But indeed I have a dashboard with the "advices" widget. I don't need that widget anyway, but it was there, so I kept it. I'll remove it and that's all...

Anyway, I'll run the same scenario with the up-trace and we'll see what comes out of it...
Comment 17 Benoît Robin 2017-08-13 06:25:57 UTC
Hi Stéphane,


And yes, I am French ^-^

As for the test, as the update to 2.9.0 passed on my main computer, I now just can't get the bug anymore. I tried to refresh the advices widget, even turned on all advices, but to no avail.

Oh, and as for payees, in French it should be what is called a "tiers", if I understand well. I never bothered to look at those, they're not even displayed in my custom operation format.

I'll try on another computer, which didn't get the update, and I give you what I found.
Comment 18 Benoît Robin 2017-08-13 06:47:51 UTC
Created attachment 107245 [details]
Report of Profiling + SQL

Hi Stéphane,


I doubled up with the previous trace and the file, which is copied from the console, contains both trace and SQL. This is probably redundant.

From your diagnostic, I guess the statement that causes the issue is the following :

##executeSqliteOrder:SELECT EXISTS(SELECT 1 FROM payee WHERE EXISTS (SELECT 1 FROM payee p2 WHERE p2.id<>payee.id AND upper(p2.t_name)=upper(payee.t_name) AND p2.t_name<>payee.t_name)) TIME=27582 ms,  (with fetch):27582 ms

It was executed twice, which matches with my observing two CPU max-outs, one at startup and one when I updated the operation's category.

Hope that could help you improve that operation. It seems a quite simple brute-force statement on all the base and I'm not SQL-wise enough to know if such a seemingly simple request can be improved ^-^


Benoît 'Mutos' Robin
Comment 19 Benoît Robin 2017-08-13 06:48:47 UTC
Ah, and I'll keep 2.8.1 on the laptop until you tell me you don't need further information...
Comment 20 Stephane MANKOWSKI 2017-08-13 08:48:53 UTC
Hi Benoit,

Thank you I have the confirmation of my analysis.
You can install Skrooge 2.9.0.
You should not have the issue.
Could you confirm here after the update?
Regards.
Comment 21 Benoît Robin 2017-08-13 10:42:01 UTC
Hi Stéphane,


I confirm 2.9.0, which is already installed onmy desktop machine, doesn't have the issue anymore. I'll install it on the laptop.

Merci de ton aide ^-^

Btw, who can close the case ?
Comment 22 Stephane MANKOWSKI 2017-08-13 10:54:32 UTC
Already fixed 2.9.0.