Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

High CPU load #248

Closed
tpjanssen opened this issue Jan 30, 2017 · 28 comments
Closed

High CPU load #248

tpjanssen opened this issue Jan 30, 2017 · 28 comments

Comments

@tpjanssen
Copy link

Hi Dennis,

Are there any changes in the last update that can cause high CPU load? My CPU load average is typically around 1.2 . I have 4.2 meter, read out every 5 s. The reader has stored around 135000 telegrams.

Any ideas?

Regards.
@dennissiemensma
Copy link
Member

Can you see whether it's the datalogger process of the backend process that causing the load?

If so, you could start by tailing the Supervisor logs for them, they are located in /var/log/supervisor. There are also application error logs and datalogger logs in the application folder in /home/dsmr/dsmr-reader/logs.

@dennissiemensma dennissiemensma added this to the Backlog / Other milestone Jan 30, 2017
@tpjanssen
Copy link
Author

tpjanssen commented Jan 30, 2017 •
edited by dennissiemensma

This is the output of ps aux|grep 'python'

root      1295  0.1  0.9  16028  9316 ?        Ss   17:23   0:27 /usr/bin/python /usr/bin/supervisord -c /etc/supervisor/supervisord.confdsmr      1322  0.0  1.5  18828 14264 ?        SN   17:23   0:07 /home/dsmr/.virtualenvs/dsmrreader/bin/python3 /home/dsmr/.virtualenvs/dsmrreader/bin/gunicorn --timeout 60 --max-requests 500 --bind unix:/var/tmp/gunicorn--dsmr_webinterface.socket --pid /var/tmp/gunicorn--dsmr_webinterface.pid dsmrreader.wsgi
dsmr      1328  1.1  3.4  49008 32364 ?        SN   17:23   4:04 /home/dsmr/.virtualenvs/dsmrreader/bin/python3 -u /home/dsmr/dsmr-reader/manage.py dsmr_backend
dsmr      5111  1.3  2.7  42568 26032 ?        SN   20:33   2:06 /home/dsmr/.virtualenvs/dsmrreader/bin/python3 -u /home/dsmr/dsmr-reader/manage.py dsmr_datalogger
dsmr      5218  0.2  2.9  45444 27636 ?        SN   20:40   0:24 /home/dsmr/.virtualenvs/dsmrreader/bin/python3 /home/dsmr/.virtualenvs/dsmrreader/bin/gunicorn --timeout 60 --max-requests 500 --bind unix:/var/tmp/gunicorn--dsmr_webinterface.socket --pid /var/tmp/gunicorn--dsmr_webinterface.pid dsmrreader.wsgi
pi        6659  0.0  0.1   4280  1848 pts/0    S+   23:06   0:00 grep --color=auto python

So both backend and logger seem to be high on load. No errors in std-err logs. After a telegram comes it says "Sleeping for 1 second(s)". What is happening in the meantime?

@dennissiemensma
Copy link
Member

That's weird. And sleeping should just suspend Python or something.

Can you also see the exact load (or CPU usage) of the processes with top or htop? And what does this the third line in top look like when the load is high?

It's formatted this way:

%Cpu(s):  7,3 us,  2,2 sy,  0,0 ni, 89,7 id,  0,7 wa,  0,0 hi,  0,0 si,  0,0 st

@tpjanssen
Copy link
Author

tpjanssen commented Feb 1, 2017 •
edited by dennissiemensma

I did some research, and it appears that MySQL is causing the high load. To be more precise, it's causing the iowait to be high. Not sure why this is happening, as this is not happening all the time. Furthermore I did some logging on MySQL slow queries:

# Time: 170201 17:04:13
# User@Host: dsmrreader[dsmrreader] @ localhost []
# Query_time: 0.000682  Lock_time: 0.000298 Rows_sent: 0  Rows_examined: 1
SET timestamp=1485965053;
UPDATE `dsmr_datalogger_meterstatistics` SET `voltage_sag_count_l2` = 0, `long_power_failure_count` = 0, `voltage_swell_count_l1` = 0, `timestamp` = '2017-02-01 16:04:02', `voltage_swell_count_l2` = 0, `power_failure_count` = 4, `voltage_swell_count_l3` = 0, `voltage_sag_count_l1` = 0, `voltage_sag_count_l3` = 0, `electricity_tariff` = 2;
# Time: 170201 17:04:16
# User@Host: dsmrreader[dsmrreader] @ localhost []
# Query_time: 1.740316  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 0
SET timestamp=1485965056;
commit;
# Time: 170201 17:04:22
# User@Host: dsmrreader[dsmrreader] @ localhost []
# Query_time: 0.000444  Lock_time: 0.000197 Rows_sent: 0  Rows_examined: 1
SET timestamp=1485965062;
UPDATE `dsmr_datalogger_meterstatistics` SET `voltage_sag_count_l2` = 0, `long_power_failure_count` = 0, `voltage_swell_count_l1` = 0, `timestamp` = '2017-02-01 16:04:12', `voltage_swell_count_l2` = 0, `power_failure_count` = 4, `voltage_swell_count_l3` = 0, `voltage_sag_count_l1` = 0, `voltage_sag_count_l3` = 0, `electricity_tariff` = 2;
# Time: 170201 17:04:32
# User@Host: dsmrreader[dsmrreader] @ localhost []
# Query_time: 0.000677  Lock_time: 0.000287 Rows_sent: 0  Rows_examined: 1
SET timestamp=1485965072;
UPDATE `dsmr_datalogger_meterstatistics` SET `voltage_sag_count_l2` = 0, `long_power_failure_count` = 0, `voltage_swell_count_l1` = 0, `timestamp` = '2017-02-01 16:04:22', `voltage_swell_count_l2` = 0, `power_failure_count` = 4, `voltage_swell_count_l3` = 0, `voltage_sag_count_l1` = 0, `voltage_sag_count_l3` = 0, `electricity_tariff` = 2;
# Time: 170201 17:04:35
# User@Host: dsmrreader[dsmrreader] @ localhost []
# Query_time: 1.826750  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 0
SET timestamp=1485965075;
commit;
# Time: 170201 17:04:42
# User@Host: dsmrreader[dsmrreader] @ localhost []
# Query_time: 0.000429  Lock_time: 0.000179 Rows_sent: 0  Rows_examined: 1
SET timestamp=1485965082;
UPDATE `dsmr_datalogger_meterstatistics` SET `voltage_sag_count_l2` = 0, `long_power_failure_count` = 0, `voltage_swell_count_l1` = 0, `timestamp` = '2017-02-01 16:04:32', `voltage_swell_count_l2` = 0, `power_failure_count` = 4, `voltage_swell_count_l3` = 0, `voltage_sag_count_l1` = 0, `voltage_sag_count_l3` = 0, `electricity_tariff` = 2;
# Time: 170201 17:04:54
# User@Host: dsmrreader[dsmrreader] @ localhost []
# Query_time: 2.332941  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 0
SET timestamp=1485965094;
commit;
# User@Host: dsmrreader[dsmrreader] @ localhost []
# Query_time: 0.000675  Lock_time: 0.000288 Rows_sent: 0  Rows_examined: 1
SET timestamp=1485965094;
UPDATE `dsmr_datalogger_meterstatistics` SET `voltage_sag_count_l2` = 0, `long_power_failure_count` = 0, `voltage_swell_count_l1` = 0, `timestamp` = '2017-02-01 16:04:42', `voltage_swell_count_l2` = 0, `power_failure_count` = 4, `voltage_swell_count_l3` = 0, `voltage_sag_count_l1` = 0, `voltage_sag_count_l3` = 0, `electricity_tariff` = 2;
# User@Host: dsmrreader[dsmrreader] @ localhost []
# Query_time: 2.542938  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 0
SET timestamp=1485965094;
commit;
# Time: 170201 17:05:02
# User@Host: dsmrreader[dsmrreader] @ localhost []
# Query_time: 0.000419  Lock_time: 0.000173 Rows_sent: 0  Rows_examined: 1
use dsmrreader;
SET timestamp=1485965102;
UPDATE `dsmr_datalogger_meterstatistics` SET `voltage_sag_count_l2` = 0, `long_power_failure_count` = 0, `voltage_swell_count_l1` = 0, `timestamp` = '2017-02-01 16:04:52', `voltage_swell_count_l2` = 0, `power_failure_count` = 4, `voltage_swell_count_l3` = 0, `voltage_sag_count_l1` = 0, `voltage_sag_count_l3` = 0, `electricity_tariff` = 2;
# Time: 170201 17:05:13
# User@Host: dsmrreader[dsmrreader] @ localhost []
# Query_time: 0.000422  Lock_time: 0.000173 Rows_sent: 0  Rows_examined: 1
SET timestamp=1485965113;
UPDATE `dsmr_datalogger_meterstatistics` SET `voltage_sag_count_l2` = 0, `long_power_failure_count` = 0, `voltage_swell_count_l1` = 0, `timestamp` = '2017-02-01 16:05:02', `voltage_swell_count_l2` = 0, `power_failure_count` = 4, `voltage_swell_count_l3` = 0, `voltage_sag_count_l1` = 0, `voltage_sag_count_l3` = 0, `electricity_tariff` = 2;

Also table dsmr_datalogger_meterstatistics is updated without an index. I don't think this is not causing my issue, but my guess is that it's better to add a WHERE clause to the update query.

I can't imagine the used SD card has anything to do with it, as it is a class 10 SanDisk Ultra Micro SDHC.

Maybe it is wise to switch to PostgreSQL? Can this be done easily?

@dennissiemensma
Copy link
Member

The dsmr_datalogger_meterstatistics table contains only a single record, which is updated each time. It should be fast and the query time shows that as well.
However, the commit following the update seems slow. And think committing makes the data persist on the SD card. So it does seem related to the card, but I'm no expert in SD brands, SD performance and stuff.

I'm not sure whether switching to PostgreSQL will reduce the load. I think you could try playing around with MySQL settings, by having it write more or less frequent to the SD card. Or try some of these suggestions (except for the tempfs). Please be careful and make sure you create a fresh database backup first.

@tpjanssen
Copy link
Author

I agree updating the dsmr_datalogger_meterstatistics table is not the problem, but is makes debugging slow queries in general a bit easier. To migrate to PostreSQL is worth a try, I read that you want stop support MySQL?

@dennissiemensma
Copy link
Member

The support will be dropped somewhere in the future, I will only deprecate it the next release. Since a month or two the project is being used a lot and PostgreSQL seems to have a lot less (small) issues.

For now the support for MySQL continues and will so for a few releases, until I've also created a script for migrating data easily. And that script isn't finished yet.

@tpjanssen
Copy link
Author

When I run iotop -oPa it shows that the MySQL daemon generates 4 MB of writes every minute. Can you please check what's the number on your Pi? With that amount of writes I can imagine that my Pi slows down, combined with the journaling filesystem. When I stop the supervisor all writes are gone.

@dennissiemensma
Copy link
Member

I think that there might be something with your MySQL installation. The application shouldm't generate that much data. Here it's idle most of the time. When it's writing it's only using 25 K/s.

Does the Status page of the application indicate any lagging behind regarding data processing?

@tpjanssen
Copy link
Author

I'm using the default MySQL configuration, did not touch the config file. Status page is ok, no lagging behind.

Maybe some other users with MySQL server can report their I/O rates?

@tpjanssen
Copy link
Author

I'm using the InnoDB engine now. As this is my default engine, I'm not sure if you explicitly want to use this engine. Is it safe to switch to MyISAM?

@dennissiemensma
Copy link
Member

I've checked another MySQL installation for you running this project, and it only consumes slightly more than PostgreSQL. Definitely not the 4 MB/s you're having. It's also on the default InnoDB engine.

MyISAM is faster, but only because it lack any data integrity builtin. It's also no longer the default engine for newer versions of MySQL for that reason.

Did the performance degrade slowly or was it already like this, since you've installed this project?

@tpjanssen
Copy link
Author

I guess that the performance was bad from the beginning. Can you please share your MySQL configuration?

@dennissiemensma
Copy link
Member

What would you like to know about the configuration? It's running the default one that comes with installing mysql-server. No changes.

@tpjanssen
Copy link
Author

Tried on another Pi, with another (brand of) SD-card. Same result. Are you running MySQL or MariaDB?

@dennissiemensma
Copy link
Member

That's still weird, and It's MariaDB that I installed there.

@dennissiemensma
Copy link
Member

@tpjanssen what revision of the Pi are you using? I asume the 2 or 3?

The biggest change between the last two major releases of this project (v1.4 / v1.5) is the upgrade of the framework I'm using (Django), but it should not relate to any performance issues related to the commit; statement used.

If you have a spare Pi, you could try running a second clean installation of this project, with PostgreSQL (to determine whether it's related to the database backend) simultaneously.
It requires you to disable you current (default) datalogger and replace it with this one, having it send the readings through the API of both your MySQL and PostgreSQL Pi's running the project. You will have to enable the API in both projects and enter a API key as well (in the projects and the script mentioned above).

It's actually the same setup I'm using here, to have a spare semi-production enviroment to test before releasing stuff.

@tpjanssen
Copy link
Author

Hi Dennis,

Sorry for the late response. Been quite busy lately. Before trying your suggestion, I would like to update first. Not sure, but with installing the update, is data migrated to PostgreSQL automatically?

@dennissiemensma
Copy link
Member

You should upgrade when possible, but the data will not be migrated automatically to PostgreSQL. I do however have a script to copy the data between two databases. But it is not quite ready yet as it slows down the longer the script runs. I'll have to improve it a bit to make it run smooth.

@tpjanssen
Copy link
Author

Can you please send me the script so I can give it a try.

@dennissiemensma
Copy link
Member

dennissiemensma commented Apr 8, 2017 •
edited

  • Make sure you have updated to the latest version (v1.6).
  • Then switch to the branch containing the script:
sudo su - dsmr
git checkout -b 223-mysql-to-postgresql-migration origin/223-mysql-to-postgresql-migration

  • Follow the docs here.

  • Please note that the script currently will slow down the longer it runs. So you'll have to abort and restart it some times. It will resume where it left.

  • Also note that you should make sure you have a database backup before you do anything at all, limiting any risks.

Whether you succeed or not, you may switch back to the regular branch by running git checkout master again, after you're done.

@tpjanssen
Copy link
Author

tpjanssen commented Nov 17, 2017 via email

@dennissiemensma
Copy link
Member

Ik denk dat ik daarvoor eerst het migratiescript weer moet bijwerken. Sowieso zit het migratiescript nog steeds in een (oude) branch.

Heb je nog steeds issues met MySQL-performance? Je zou ook nog kunnen kijken naar eventuele optimalisatie: https://www.percona.com/blog/2013/09/20/innodb-performance-optimization-basics-updated/

Bijvoorbeeld innodb_flush_log_at_trx_commit = 2

@tpjanssen
Copy link
Author

tpjanssen commented Nov 21, 2017 via email •
edited by dennissiemensma

@dennissiemensma
Copy link
Member

Ik denk dat je dan gewoon moet upgraden en kijken of het iets verandert. Volgens mij is dit afdoende:

  • sudo su - dsmr
  • git fetch
  • git checkout master
  • ./deploy.sh

Als het goed is kom je daarmee op v1.10

@tpjanssen
Copy link
Author

tpjanssen commented Nov 21, 2017 via email •
edited by dennissiemensma

@dennissiemensma
Copy link
Member

Jazeker, maar het heeft geen hoge priotiteit t.o.v. van andere tickets. Mijn plan was om eerst MySQL uit te faseren in de docs, zodat er geen nieuwe installaties meer gedaan worden met MySQL. Vervolgens op een later punt zou ik MySQL daadwerkelijk uitfaseren.
Echter, op dat punt ben ik nog lang niet en tot die tijd blijft MySQL werken (alle tests draaien zowel onder MySQL als PostgreSQL). Helaas helpt dit jou niet direct, wanneer mocht blijken dat ook de laatste release niet lekker performt in jouw situatie.

@tpjanssen
Copy link
Author

tpjanssen commented Nov 21, 2017 via email

@dennissiemensma dennissiemensma mentioned this issue Jul 15, 2024
Closed
4 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@dennissiemensma @tpjanssen