search

dsmrreader / dsmr-reader

DSMR-telegram reader & data visualizer for hobbyists. Free for non-commercial use.
https://dsmr-reader.readthedocs.io
Other
461 stars 95 forks source link

High CPU load #248

Closed tpjanssen closed 6 years ago

tpjanssen commented 7 years ago

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 commented 7 years ago

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.

tpjanssen commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

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

dennissiemensma commented 7 years ago

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

tpjanssen commented 7 years ago

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

dennissiemensma commented 7 years ago

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

dennissiemensma commented 7 years ago

@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 commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

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

dennissiemensma commented 7 years ago

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

tpjanssen commented 6 years ago

Beste Dennis,

Lange tijd niet meer mee bezig geweest, maar ik tracht nu toch eens te updaten... Hopelijk kan en wil je me helpen.

Ik gebruik nu 1.5.5. Als ik het goed begrijp kan ik enkel het migrate script draaien vanaf 1.6.0 ? Hoe kan ik nu mijn bestaande installatie updaten naar 1.6.0, de data migreren, en daarna updaten naar de latest and the greatest? Heb PostgreSQL en alles al opgezet, alleen loop ik nu vast omdat 1.5.5 het migrate script nog niet kent.

Mvg,

Thijs

From: Dennis Siemensma notifications@github.com Sent: Saturday, April 8, 2017 6:10 PM To: dennissiemensma/dsmr-reader Cc: tpjanssen; Mention Subject: Re: [dennissiemensma/dsmr-reader] High CPU load (#248)

sudo us - dsmr git checkout -b 223-mysql-to-postgresql-migration origin/223-mysql-to-postgresql-migration

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

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHubhttps://github.com/dennissiemensma/dsmr-reader/issues/248#issuecomment-292727599, or mute the threadhttps://github.com/notifications/unsubscribe-auth/AYAL5gn9nU3Z6SEkZwQtDyX02z7CNzoTks5rt7FagaJpZM4Lx1KR.

dennissiemensma commented 6 years ago

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 commented 6 years ago

Volgens mij heb ik dit al geprobeerd, maakte geen verschil. Ik wil gewoon naar de laatste versie, en hopelijk is de hoge load dan ook verdwenen. Hoe kan ik dit het beste aanpakken?

dennissiemensma commented 6 years ago

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

Als het goed is kom je daarmee op v1.10

tpjanssen commented 6 years ago

Thanks. De reden dat ik de upgrade niet gedaan heb was omdat ik in de veronderstelling was dat MySQL niet meer werkte. Zojuist de upgrade gedraaid, en het draait weer.

Betekent dit dat je nog met het upgrade script bezig bent?

dennissiemensma commented 6 years ago

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 commented 6 years ago

Duidelijk verhaal. Dit issue kun je wat mij betreft weer sluiten. Ik wacht af of mijn problemen nog terug komen. Als dit zo is, dan lost een update naar PostgreSQL hopelijk alles op.

Bedankt in ieder geval.

From: Dennis Siemensma notifications@github.com Sent: Tuesday, November 21, 2017 8:30 PM To: dennissiemensma/dsmr-reader Cc: tpjanssen; Mention Subject: Re: [dennissiemensma/dsmr-reader] High CPU load (#248)

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.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHubhttps://github.com/dennissiemensma/dsmr-reader/issues/248#issuecomment-346135479, or mute the threadhttps://github.com/notifications/unsubscribe-auth/AYAL5uj0Hx2CaC6fpUjfmAS5sNO0Ddnyks5s4yS6gaJpZM4Lx1KR.