93_DbLog - Überlegungen zur Optimierung (RPI und andere Systeme)

[DS_Starter]

1 GB ist eventuell etwas viel weil das DBM dann diesen Speicher verwalten muß.  Ich suche mal meine cfg noch raus. Die 415+ hatte ich auf 8 GB RAM erweitert (Standard 2 GB).
Aber hilfreicher ist wahrscheinlich wenn du das Perlscript  MysqlTuner verwendest (http://mysqltuner.com/).
Das benutze ich um die DB-Einstellungen zu optimieren.

Lade es dir runter und lege es auf der Syno in ein Verzeichnis. Du kannst es dann so starten wie in dem angegebenen Beispiel. "forcemem" würden deinen 16GB Speicher entsprechen. Als "forceswap" hatte ich bei mir einen Daumenwert angegeben, müßte ich jetzt überlegen wo das herkommt ....

Code Auswählen Erweitern


cd /volume1/ApplicationBackup/Backup_FHEM
perl mysqltuner.pl --forcemem 16000 --forceswap 6700 --user root --pass <Passwort>


Probier mal, ich denke damit kommst du sicherlich gut klar.

EDIT:  Es kommt dann so etwas heraus:

Code Auswählen Erweitern


-------- General Statistics --------------------------------------------------
[--] Skipped version check for MySQLTuner script
[OK] Currently running supported MySQL version 5.0.51a-24+lenny2+spu1
[OK] Operating on 32-bit architecture with less than 2GB RAM

-------- Storage Engine Statistics -------------------------------------------
[--] Status: +Archive -BDB -Federated +InnoDB -ISAM -NDBCluster
[--] Data in MyISAM tables: 1M (Tables: 26)
[--] Data in InnoDB tables: 22M (Tables: 39)
[--] Data in MEMORY tables: 0B (Tables: 1)
[!!] Total fragmented tables: 10

-------- Performance Metrics -------------------------------------------------
[--] Up for: 11d 16h 28m 56s (8M q [8.714 qps], 597K conn, TX: 2B, RX: 1B)
[--] Reads / Writes: 93% / 7%
[--] Total buffers: 58.0M global + 2.6M per thread (100 max threads)
[OK] Maximum possible memory usage: 320.5M (15% of installed RAM)
[OK] Slow queries: 0% (0/8M)
[OK] Highest usage of available connections: 19% (19/100)
[OK] Key buffer size / total MyISAM indexes: 16.0M/1.9M
[OK] Key buffer hit rate: 99.4% (266K cached / 1K reads)
[OK] Query cache efficiency: 70.2% (4M cached / 6M selects)
[!!] Query cache prunes per day: 2132
[OK] Sorts requiring temporary tables: 0% (0 temp sorts / 586K sorts)
[!!] Temporary tables created on disk: 30% (24K on disk / 81K total)
[OK] Thread cache hit rate: 99% (1K created / 597K connections)
[!!] Table cache hit rate: 14% (64 open / 433 opened)
[OK] Open file limit used: 0% (6/1K)
[OK] Table locks acquired immediately: 100% (2M immediate / 2M locks)
[!!] InnoDB data size / buffer pool: 22.1M/8.0M

-------- Recommendations -----------------------------------------------------
General recommendations:
    Run OPTIMIZE TABLE to defragment tables for better performance
    Enable the slow query log to troubleshoot bad queries
    When making adjustments, make tmp_table_size/max_heap_table_size equal
    Reduce your SELECT DISTINCT queries without LIMIT clauses
    Increase table_cache gradually to avoid file descriptor limits
Variables to adjust:
    query_cache_size (> 16M)
    tmp_table_size (> 32M)
    max_heap_table_size (> 16M)
    table_cache (> 64)
    innodb_buffer_pool_size (>= 22M)


-> Nicht wundern, das ist ein altes Beispiel aus meinen Aufzeichnungen..

Grüße
Heiko

[DS_Starter]

Hi Joe,

kennst du noch ein besseres Hilfsmittel als das mysqltuner- Script für die Optimierung , oder wie machst du das ?

LG
Heiko

[DS_Starter]

Und hier noch meine DB-Parametrisierung:

Code Auswählen Erweitern


root@SDS1:~# more /var/packages/MariaDB/etc/my.cnf
[mysqld]
# 19.12.2016
innodb_buffer_pool_size = 300M
innodb_log_file_size=75M
# innodb_buffer_pool_size = 128M
innodb_additional_mem_pool_size = 24M
# innodb_additional_mem_pool_size = 64M
key_buffer_size = 10M
# key_buffer_size = 256M
sort_buffer_size = 512K
read_buffer_size = 512K
read_rnd_buffer_size = 512K
query_cache_limit = 4M
query_cache_size = 64M
max_allowed_packet = 2M
table_open_cache = 1024
key_buffer = 256M
thread_cache_size = 4
join_buffer_size = 256K


[SusisStrolch]

Hmm, da kommt dann folgender Vorschlag:

Code Auswählen Erweitern

General recommendations:
    Run OPTIMIZE TABLE to defragment tables for better performance
      OPTIMIZE TABLE fhem.historyOLD; -- can free 4079 MB
    Total freed space after theses OPTIMIZE TABLE : 4079 Mb
Variables to adjust:
    query_cache_type (=0)
    innodb_buffer_pool_size (>= 24G) if possible.


[DS_Starter]

Hmm... naja, irgendwie nicht so toll (außer optimize table) 

Vielleicht nimmst du tatsächlich erst einmal meine Konfig als Ausgangspunkt und lässt das Script nach längerer DB-Laufzeit nochmal drüber laufen.
Gleich nach dem DB-Start macht das keinen Sinn.  Es sollte etwas Zeit vergangen sein, damit sich die DB/der Memory eingeschwungen hat.

ACHTUNG:  innodb_log_file_size  nicht einfach ändern !  lass diesen Parameter bei dir erstmal wie er ist.

[SusisStrolch]

ACHTUNG:  innodb_log_file_size  nicht einfach ändern !  lass diesen Parameter bei dir erstmal wie er ist.

Jo - da hatte ich mal ne leidvolle Erfahrung, weil mir beim Update meine optimierte my.cnf verloren ging...

[JoeALLb]

Wenn Du experimentierfreudig bist, versuche mal die Engine umzustellen auf Aria.
Gerade auf solchen Kisten sollte das deutlich besser funktionieren....

[SusisStrolch]

Läuft seit längerem schon auf Aria - die Innodb ist disabled...

Hier noch einige Details von mysqltuner:

Code Auswählen Erweitern


-------- Storage Engine Statistics -----------------------------------------------------------------
[--] Status: +ARCHIVE +Aria +BLACKHOLE +CSV +FEDERATED -InnoDB +MEMORY +MRG_MYISAM +MyISAM +PERFORMANCE_SCHEMA

[--] Data in MyISAM tables: 4K (Tables: 4)
[--] Data in Aria tables: 36G (Tables: 81)
[OK] Total fragmented tables: 0

-------- Performance Metrics -----------------------------------------------------------------------
[--] Up for: 1h 59m 20s (10K q [1.491 qps], 485 conn, TX: 87M, RX: 998K)
[--] Reads / Writes: 69% / 31%
[--] Binary logging is disabled
[--] Physical Memory     : 15.7G
[--] Max MySQL memory    : 11.3G
[--] Other process memory: 922.6M
[--] Total buffers: 10.6G global + 3.2M per thread (100 max threads)
[--] P_S Max memory usage: 376M
[--] Galera GCache Max memory usage: 0B
[OK] Maximum reached memory usage: 11.0G (70.05% of installed RAM)
[OK] Maximum possible memory usage: 11.3G (71.99% of installed RAM)
[OK] Overall possible memory usage with other process is compatible with memory available
[OK] Slow queries: 0% (64/10K)
[OK] Highest usage of available connections: 4% (4/100)
[OK] Aborted connections: 0.82%  (4/485)
[OK] Query cache is disabled by default due to mutex contention on multiprocessor machines.
[OK] Sorts requiring temporary tables: 10% (17 temp sorts / 159 sorts)
[OK] No joins without indexes
[OK] Temporary tables created on disk: 5% (101 on disk / 1K total)
[OK] Table cache hit rate: 122% (134 open / 109 opened)
[OK] Open file limit used: 3% (308/8K)
[OK] Table locks acquired immediately: 100% (15K immediate / 15K locks)

-------- Performance schema ------------------------------------------------------------------------
[--] Performance schema is enabled.
[--] Memory used by P_S: 376.2M
[--] Sys schema isn't installed.

-------- ThreadPool Metrics ------------------------------------------------------------------------
[--] ThreadPool stat is enabled.
[--] Thread Pool Size: 4 thread(s).
[--] Using default value is good enough for your version (5.5.54-MariaDB)

-------- MyISAM Metrics ----------------------------------------------------------------------------
[!!] Key buffer used: 18.2% (97M used / 536M cache)
[OK] Key buffer size / total MyISAM indexes: 512.0M/103.0K
[!!] Read Key buffer hit rate: 80.0% (5 cached / 1 reads)

-------- AriaDB Metrics ----------------------------------------------------------------------------
[--] AriaDB is enabled.
[OK] Aria pagecache size / total Aria indexes: 10.0G/9.3G
[OK] Aria pagecache hit rate: 99.8% (100M cached / 225K reads)

-------- InnoDB Metrics ----------------------------------------------------------------------------
[--] InnoDB is disabled.
[!!] InnoDB Storage engine is disabled. InnoDB is the default storage engine

-------- TokuDB Metrics ----------------------------------------------------------------------------
[--] TokuDB is disabled.

-------- Galera Metrics ----------------------------------------------------------------------------
[--] Galera is disabled.

-------- Replication Metrics -----------------------------------------------------------------------
[--] Galera Synchronous replication: NO
[--] No replication slave(s) for this server.
[--] This is a standalone server.



Ein "CREATE INDEX Reading_Time_Idx" läuft jetzt schon seit 2h...

[DS_Starter]

Jetzt habe ich den Search_Idx gelöscht und mit

Code Auswählen Erweitern


CREATE INDEX Search_Idx ON `history` (DEVICE, READING, TIMESTAMP) USING BTREE


anlegen lassen.

Laufzeit war rund 3 Min. bei 6.738.467 Datensätzen , rund 1,5 GB.

Code Auswählen Erweitern


MySQL lieferte ein leeres Resultat zurück (d.h. null Datensätze). (Die Abfrage dauerte 180.5843 Sekunden.)


Die CPU der Syno war dabei ca. 20% durch MariaDB 5 ausgelastet, aber das Volume während dieser Zeit fast 100%.  Das könnte bei dir ein Flaschenhals sein. Die CPU (4 Cores) ist bei meiner und deiner Syno identisch glaube ich.
Ich habe auch noch InnoDB. Auf MariaDB 10, auf die ich nach und nach umstelle, setze ich dann auch Aria ein.

EDIT: Also Daten sind rund 1GB, der Rest ist dann die Datenmenge für den Index !

Grüße
Heiko

[SusisStrolch]

Code Auswählen Erweitern

root@DiskStation:/var/packages/MariaDB/target/mysql# time dd if=ibdata1 of=/dev/null bs=16M
1076+1 records in
1076+1 records out
18062770176 bytes (18 GB) copied, 166.295 s, 109 MB/s


Viel schneller bekomm' ichs nicht hin...

[DS_Starter]

Meine ist  ca. 1/3 schneller:

Code Auswählen Erweitern


root@SDS1:/var/packages/MariaDB/target/mysql#  time dd if=ibdata1 of=/dev/null bs=16M
245+1 records in
245+1 records out
4112515072 bytes (4.1 GB) copied, 30.8802 s, 133 MB/s


Das kann m.M. nach doch nicht der Grund für derart drastische Unterschiede bei der Indexerstellungsgeschwindigkeit sein ....

Was sagt denn deine CPU ?

[SusisStrolch]

Die eine CPU mit dem mysqld pendelt um die 99%. Gesamtsystem pendelt zwischen 40% und 60%.

[DS_Starter]

Die eine CPU mit dem mysqld pendelt um die 99%

Jetzt habe ich lange darüber nachgedacht wieso deine CPU-Auslastung gegenüber meiner Beobachtung so hoch ist und wahrscheinlich den Bottleneck darstellt.
Könnte es sein, dass du Filesystemverschlüsselung auf der Syno benutzt ?

[SusisStrolch]

Nope, ich verwende auch keine verschlüsselten Partitionen.
Volume1 (ext4) und Volume2 (btrfs) sind beide RAID5, (4x 6TB), Volume3 ist ein Single Volume (3TB, ext4).
Die Datenbank-Durchsätze sind auf allen Volumes gleich schlecht (in der Vergangenheit schon getestet).

So - hatte nochmal die Sache mit dem Cache ausprobiert.
Gestern nachmittag (mit den lt. mysqltuner "optimierten" Werten):

Code Auswählen Erweitern


CREATE INDEX Reading_Time_Idx ON `history` (READING, TIMESTAMP) USING BTREE;
Query OK, 102681848 rows affected, 1 warning (12 hours 16 min 31.49 sec)
Records: 102681848  Duplicates: 0  Warnings: 1


Ergebnis in der Datenbank:

Code Auswählen Erweitern


('2017-07-14 14:40:54', 'Hauptzaehler_sysinfo', 'ESPEASY', 'uptime: 13242.00', 'uptime', '13242.00', ''),
('2017-07-14 14:41:54', 'Hauptzaehler_sysinfo', 'ESPEASY', 'uptime: 13243.00', 'uptime', '13243.00', ''),
('2017-07-14 14:42:55', 'Hauptzaehler_sysinfo', 'ESPEASY', 'uptime: 13244.00', 'uptime', '13244.00', ''),
('2017-07-15 01:02:10', 'Hauptzaehler_sysinfo', 'ESPEASY', 'uptime: 13863.00', 'uptime', '13863.00', ''),
('2017-07-15 01:03:10', 'Hauptzaehler_sysinfo', 'ESPEASY', 'uptime: 13864.00', 'uptime', '13864.00', ''),
('2017-07-15 01:04:11', 'Hauptzaehler_sysinfo', 'ESPEASY', 'uptime: 13865.00', 'uptime', '13865.00', '');

Es fehlen also genau die 12 Stunden...

[DS_Starter]

Es fehlen also genau die 12 Stunden...

Ich gebe zu dass es mich sehr irritiert und ich es auch nicht nachvollziehen kann.

Gibt es denn irgendwelche Fehlermeldungen im Log ?

Nur nochmal zur Funktionsweise ........

Im asynchronen Betrieb werden die Events im Cache (RAM) gesammelt und alle X Sekunden bzw. bei Überschreiten der Anzahl "cacheLimit" wird versucht diese Daten in die DB zu schreiben. Kann nicht auf die DB/Tabelle zugegriffen werden bleiben die Daten im Cache und bauen sich immer weiter auf. Man sieht das schön mit "set ... listCache". 
Gleichzeitig wird im state entweder eine Fehlermeldung (wenn z.B. die DB nicht verfügbar ist) angezeigt oder, und das ist wichtig, die Meldung "Commit already running - resync at NextSync" angezeigt wenn z.B. die Tabelle history gesperrt ist.
Mit jedem weiteren Event baut sich der Cache dann weiter auf ...

Hast du während der Indexerstellung das mal verfolgt und kannst es bestätigen ?

Sobald die DB wieder da ist bzw. die Tabellensperre weg ist wird beim nächsten Synclauf der gesammte Cache in die DB weggeschrieben. Das funktioniert bei mir z.B. während der Backupphasen mit Synology Hyper Backup ausgezeichnet (dabei wird die DB gestoppt).

Momentan simuliere ich gerade einen Fehlerzustand indem ich das PW des Benutzers in der DB falsch gesetzt habe. Dadurch kommt im state des Moduls:

Code Auswählen Erweitern


DBI connect('database=fhemtest;host=192.168.2.10;port=3307','fhemtest',...) failed: Access denied for user 'fhemtest'@'fhemtest.myds.me' (using password: YES) at ./FHEM/93_DbLog.pm line 1683.


Auch im Log tauchen entsprechende Meldungen auf:

Code Auswählen Erweitern


2017.07.15 20:10:18.071 2: DbLog LogDB - Error: DBI connect('database=fhemtest;host=192.168.2.10;port=3307','fhemtest',...) failed: Access denied for user 'fhemtest'@'fhemtest.myds.me' (using password: YES) at ./FHEM/93_DbLog.pm line 1683.


So ist es auch richtig in diesem Fall.
Wichtig ist, das sich der Cache aufbaut. Das macht er und enthält inzwischen 650 Einträge (cachUsage) seit 19:50.

Ich lasse das noch ein bisschen so laufen und setze dann das PW wieder richtig damit die Verbindung funktioniert. Dann wird der Cache in der Gesamtheit in die DB geschrieben. Das kontrolliere ich nachher.

Vielleicht kannst du es in dieser  Form auch nochmal nachvollziehen.

Zu deiner mangelhaften Performance auf der Syno fällt mir momentan nichts mehr ein. Nicht das es mit dem von dir beschriebenen Problem einen Zusammenhang gibt den wir noch nicht sehen.

Grüße
Heiko