MySQL-Abfrage wird nicht richtig beendet.

[Son Goku]

Hallo

Ich haben einen PHP-Cronjob, der unter Anderem mehrere große und kleine Tabellen kopiert, um diese anschließend weiter zu verarbeiten.
Dieser Job läuft bisher seit Jahren in ohne Probleme, soll aber nun auf einen anderen Server umziehen.

Es handelt sich um einen Neu installierten Ubuntu-Server (16.04) mit PHP 7.0.22 und MySQL 5.7.19, welche über Google Cloud eingerichtet wurde.

Die Tabellen werden mit dem Befehl "INSERT INTO ... SELECT" kopiert.
Die Abfragen dauern je ca. 1000 - 1200 Sekunden. Dies sehe ich in der Processlist. Der INSERT ist auch erfolgreich. Abschließend steht die Verbindung noch für 300 Sekunden als "Sleep" in der Processlist und wird dann (vermutlich wegen des korrekt gesetzten Timeouts) beendet. Die Zeit zählt weiter, beginnt nicht bei 0.

Normal bekomme ich dann nach Abschluss der MySQL-Abfrage sofort die entsprechende Ausgabe in PHP mit der Angabe, wie lange die Abfrage gedauert hat. Gemessen wird mithilfe der time()-Funktion in PHP.

Bei einigen größeren Tabellen scheint PHP aber nicht zu bemerken, dass die Abfrage abgeschlossen wurde und bringt entsprechend kein Ausgabe. Diese kommt erst nach 7278 bzw. 7001 Sekunden mit folgenden Fehlermeldungen:

Code: Select all

Kopiere Tabelle xyz...
PHP Warning: mysqli::query(): MySQL server has gone away in /pfad/zum/script.php on line 63

Warning: mysqli::query(): MySQL server has gone away in /pfad/zum/script.php on line 63
PHP Warning: mysqli::query(): Error reading result set's header in /pfad/zum/script.php on line 63

Warning: mysqli::query(): Error reading result set's header in /pfad/zum/script.php on line 63
Fertig! (7278 Sekunden)

Wenn ich dieses Script lokal auf einem neuinstalliertem System starte, läuft es ohne Probleme durch. Auch, wenn das Script lokal läuft, die Datenbank-Abfragen auf dem entfernten Server ausführt, habe ich keine Probleme.

Die Konfigurationen sind identisch. Ich habe schon die my.cnf (mysqld.conf) sowie die php.ini vom lokalen System kopiert, allerdings auch ohne irgendeine Änderung zu bemerken.

Ich hab schon die Option "max_allowed_packet" auf 256M erhöht (Einstellung bisheriger Server), ohne dass es funktioniert hat. Auch eine exorbitante Erhöhung auf 50G (Server hat 100G RAM), brachte keine Besserung.
Außerdem hab ich die Option "sql-mode" auf '' gesetzt.


Für weitere Ideen und Vorschläge wäre ich sehr dankbar.

[rudelgurke]

Herzlichst Willkommen,

wie sieht denn das Script aus ? Werden die mysqli Verbindungen wieder geschlossen, nachdem alles durch ist ?

[Son Goku]

Ja, aber nicht an dieser Stelle.

Das Script sieht im groben so aus:
- Herstellen der Datenbankverbindungen
- Ausführen mehrerer kleiner Abfragen zum Logging, etc.
- Laden und verarbeiten einiger Dateien (manchmal auch größere) von extern, inkl. einiger SQL-Abfragen
- Import mit LOAD DATA INFILE
- Gerade erstellte Tabelle kopieren (hier tritt der Fehler auf)
- unmittelbar danach weitere SQL-Abfragen (UPDATE, weiteres INSERT) auf die gleiche Tabelle
- Einzelne Datensätze mit SELECT auslesen* (hier tritt der gleiche Fehler wieder auf, wenn es zu viele Datensätze betrifft)
- Datenbankverbindungen schließen und Script beenden.

Alle Datenbankverbindungen werden über die komplette Laufzeit beibehalten.
Ich habe mir eine Ableitung der MySQLi-Klasse geschrieben, die vor jedem Query prüft, ob die Verbindung noch besteht (mysqli::ping()) und ggf. wiederherstellt. Diese besteht fast so lange wie das Script, um das es geht und wird in mehreren Projekten verwendet, sodass ich einen Fehler an dieser Stelle zu 99% auschließen kann.

Auch läut auf diesem Server zur Zeit nur dieses eine Script. Und das auch nur, wenn ich es zum testen einmalig ausführe. Zum Cronjob hat es es wegen diesem Fehler noch nicht geschafft. Also auch keine Beeinträchtigung durch evtl. nicht beendete Verbindungen früherer Scripte oder durchläufe. In der Processlist taucht zudem auch nur diese eine Abfrage auf.

* Diese Abfrage sieht so aus:

Code: Select all

SELECT a, b, c FROM TABLE xyz WHERE id IN(1, 11, 12, 22, 23, ...)

[Joe User]

Hilft https://stackoverflow.com/questions/580 ... d1-id2-idn etwas?

Wie sieht die my.cnf aus? InooDB oder MyISAM?

[Son Goku]

MyISAM, da InnoDB Performanceprobleme mit großen Tabellen hat.

Hilft https://stackoverflow.com/questions/580 ... d1-id2-idn etwas?

Das sollte zumindest das Problem mit der zweiten Abfrage lösen. Hoffe ich doch.
Und ich spare mir die Überprüfung, ob meine Abfrage zu viele Zeichen enthält.

Was ich noch mittlerweile noch herausgefunden hab:
Wenn das Script lokal läuft und die DB auf dem entfernten Server anspricht, dauert der Kopiervorgang nur ca. 600-700 Sekunden (!!). Ist mir die letzten Tage gar nicht aufgefallen, dass es in dieser Variante so schnell läuft. Dann tritt der Fehler auch nicht auf.
Nun hab ich aus Versehen nochmal in die volle Tabelle kopiert, sodass diese nach Abschluss doppelt so groß war. Entsprechend länger hat auch das kopieren gedauert. Und damit konnte ich für dieses Szenario auch den Fehler reproduzieren.

Nur wenn wirklich alles lokal läuft, hab ich diesen nicht.

Ich habe daraufhin auch nochmal die MySQL-Variablen nach einem Timeout abgesucht, welches in diesem Bereich liegt, konnte aber keines entdecken.

/etc/mysql/mysql.conf.d/mysqld.cnf

Code: Select all

#
# The MySQL database server configuration file.
#
# You can copy this to one of:
# - "/etc/mysql/my.cnf" to set global options,
# - "~/.my.cnf" to set user-specific options.
#
# One can use all long options that the program supports.
# Run program with --help to get a list of available options and with
# --print-defaults to see which it would actually understand and use.
#
# For explanations see
# http://dev.mysql.com/doc/mysql/en/server-system-variables.html

# This will be passed to all mysql clients
# It has been reported that passwords should be enclosed with ticks/quotes
# escpecially if they contain "#" chars...
# Remember to edit /etc/mysql/debian.cnf when changing the socket location.

# Here is entries for some specific programs
# The following values assume you have at least 32M ram

[mysqld_safe]
socket          = /var/run/mysqld/mysqld.sock
nice            = 0

[mysqld]
#
# * Basic Settings
#
user            = mysql
pid-file        = /var/run/mysqld/mysqld.pid
socket          = /var/run/mysqld/mysqld.sock
port            = 3306
basedir         = /usr
datadir         = /projects/db-billiger/mysql
tmpdir          = /tmp
lc-messages-dir = /usr/share/mysql
sql-mode        =
skip-external-locking
#
# Instead of skip-networking the default is now to listen only on
# localhost which is more compatible and is not less secure.
bind-address            = 0.0.0.0
#
# * Fine Tuning
#
key_buffer_size         = 16M
max_allowed_packet      = 256M
#max_allowed_packet     = 16M
thread_stack            = 192K
thread_cache_size       = 8

##tmp_table_size=20G
##max_heap_table_size=20G
# This replaces the startup script and checks MyISAM tables if needed
# the first time they are touched
myisam-recover-options  = BACKUP
#max_connections        = 100
#table_cache            = 64
#thread_concurrency     = 10
#
# * Query Cache Configuration
#
query_cache_limit       = 1M
query_cache_size        = 16M
#
# * Logging and Replication
#
# Both location gets rotated by the cronjob.
# Be aware that this log type is a performance killer.
# As of 5.1 you can enable the log at runtime!
#general_log_file        = /var/log/mysql/mysql.log
#general_log             = 1
#
# Error log - should be very few entries.
#
log_error = /var/log/mysql/error.log
#
# Here you can see queries with especially long duration
#log_slow_queries       = /var/log/mysql/mysql-slow.log
#long_query_time = 2
#log-queries-not-using-indexes
#
# The following can be used as easy to replay backup logs or for replication.
# note: if you are setting up a replication slave, see README.Debian about
#       other settings you may need to change.
#server-id              = 1
#log_bin                        = /var/log/mysql/mysql-bin.log
expire_logs_days        = 10
max_binlog_size   = 100M
#binlog_do_db           = include_database_name
#binlog_ignore_db       = include_database_name
#
# * InnoDB
#
# InnoDB is enabled by default with a 10MB datafile in /var/lib/mysql/.
# Read the manual for more InnoDB related options. There are many!
#
# * Security Features
#
# Read the manual, too, if you want chroot!
# chroot = /var/lib/mysql/
#
# For generating SSL certificates I recommend the OpenSSL GUI "tinyca".
#
# ssl-ca=/etc/#mysql/cacert.pem
# ssl-cert=/etc/mysql/server-cert.pem
# ssl-key=/etc/mysql/server-key.pem

In allen anderen Dateien stehen keine weiteren Einstellungen

[Joe User]

Bitte Deine my.cnf sichern und dann versuche es mal mit dieser my.cnf, die ist bei den MyISAM-relevanten Optionen etwas getunt:

Code: Select all

[mysqld_safe]
socket                          = /var/run/mysqld/mysqld.sock
nice                            = 0

[mysqld]
user                            = mysql
port                            = 3306
socket                          = /var/run/mysqld/mysqld.sock
pid-file                        = /var/run/mysqld/mysqld.pid
bind-address                    = 0.0.0.0
basedir                         = /usr
datadir                         = /projects/db-billiger/mysql
tmpdir                          = /tmp
lc-messages-dir                 = /usr/share/mysql
log_error                       = /var/log/mysql/error.log
sync_binlog                     = 1
binlog_cache_size               = 16M
expire_logs_days                = 30
max_binlog_size                 = 100M
myisam-recover-options          = FORCE,BACKUP
table_open_cache                = 8192
table_definition_cache          = 4096
max_allowed_packet              = 64M
key_buffer_size                 = 256M
myisam_sort_buffer_size         = 16M
bulk_insert_buffer_size         = 64M
join_buffer_size                = 512K
sort_buffer_size                = 4M
read_buffer_size                = 256K
read_rnd_buffer_size            = 512K
max_heap_table_size             = 256M
tmp_table_size                  = 256M
query_cache_type                = 0
query_cache_size                = 0
long_query_time                 = 0.05
skip-external-locking
skip-symbolic-links

[mysqldump]
max_allowed_packet              = 256M
quote_names
quick

Das sollte schon etwas bessere Performance bringen, gegebenenfalls kannst Du bulk_insert_buffer_size und/oder max_heap_table_size+tmp_table_size noch verdoppeln, aber das ist dann auch schon mit Vorsicht zu geniessen.

Das Tuning für InnoDB habe ich mal bewusst aussen vor gelassen, da Du es ja derzeit nicht nutzt.

Könntest Du eventuell auch mal https://github.com/major/MySQLTuner-perl nach Deinem Script laufen lassen und die Ausgabe hier posten? Danke.

BTW: Spätestens mit dem kommenden MySQL 8.0 musst Du auf InnoDB umsteigen, da MyISAM dann (endlich) entsorgt wird.

[Son Goku]

Läuft leider immer noch nicht durch.
Diesmal laut PHP-Timer 7268 Sekunden.

Auf den Tag, an dem wir MyISAM nicht mehr nutzen können, warte ich auch schon mit grauen. Weil wir uns dann für unsere großen Tabellen was anderes überlegen müssen.

Die Tabelle, die das Problem verursacht hat übrigens ca. 19 Mio Einträge und ist ca. 10GB groß.

Code: Select all

root@server:/projects/mysqltuner# perl mysqltuner.pl
 >>  MySQLTuner 1.7.3 - Major Hayden <major@mhtx.net>
 >>  Bug reports, feature requests, and downloads at http://mysqltuner.com/
 >>  Run with '--help' for additional options and output filtering

[--] Skipped version check for MySQLTuner script
[OK] Logged in using credentials from debian maintenance account.
[OK] Currently running supported MySQL version 5.7.19-0ubuntu0.16.04.1
[OK] Operating on 64-bit architecture

-------- Log file Recommendations ------------------------------------------------------------------
[--] Log file: /var/log/mysql/error.log(14K)
[OK] Log file /var/log/mysql/error.log exists
[OK] Log file /var/log/mysql/error.log is readable.
[OK] Log file /var/log/mysql/error.log is not empty
[OK] Log file /var/log/mysql/error.log is smaller than 32 Mb
[!!] /var/log/mysql/error.log contains 37 warning(s).
[!!] /var/log/mysql/error.log contains 1 error(s).
[--] 1 start(s) detected in /var/log/mysql/error.log
[--] 1) 2017-08-19T12:18:08.269484Z 0 [Note] /usr/sbin/mysqld: ready for connections.
[--] 1 shutdown(s) detected in /var/log/mysql/error.log
[--] 1) 2017-08-19T12:18:07.517974Z 0 [Note] /usr/sbin/mysqld: Shutdown complete

-------- Storage Engine Statistics -----------------------------------------------------------------
[--] Status: +ARCHIVE +BLACKHOLE +CSV -FEDERATED +InnoDB +MEMORY +MRG_MYISAM +MyISAM +PERFORMANCE_SCHEMA
[--] Data in InnoDB tables: 16K (Tables: 1)
[--] Data in MyISAM tables: 20G (Tables: 13)
[--] Data in MEMORY tables: 0B (Tables: 30)
[OK] Total fragmented tables: 0

-------- Security Recommendations ------------------------------------------------------------------
[OK] There are no anonymous accounts for any database users
[OK] All database users have passwords assigned
[!!] User 'db@%' hasn't specific host restriction.
[--] There are 612 basic passwords in the list.

-------- CVE Security Recommendations --------------------------------------------------------------
[OK] NO SECURITY CVE FOUND FOR YOUR VERSION

-------- Performance Metrics -----------------------------------------------------------------------
[--] Up for: 7h 51m 11s (445 q [0.016 qps], 43 conn, TX: 131K, RX: 36K)
[--] Reads / Writes: 100% / 0%
[--] Binary logging is disabled
[--] Physical Memory     : 28.3G
[--] Max MySQL memory    : 1.5G
[--] Other process memory: 2.8G
[--] Total buffers: 656.0M global + 5.5M per thread (151 max threads)
[--] P_S Max memory usage: 72B
[--] Galera GCache Max memory usage: 0B
[OK] Maximum reached memory usage: 667.0M (2.30% of installed RAM)
[OK] Maximum possible memory usage: 1.5G (5.14% of installed RAM)
[OK] Overall possible memory usage with other process is compatible with memory available
[OK] Slow queries: 0% (0/445)
[OK] Highest usage of available connections: 1% (2/151)
[!!] Aborted connections: 23.26%  (10/43)
[!!] name resolution is active : a reverse name resolution is made for each new connection and can reduce performance
[OK] Query cache is disabled by default due to mutex contention on multiprocessor machines.
[OK] Sorts requiring temporary tables: 0% (0 temp sorts / 27 sorts)
[OK] No joins without indexes
[OK] Temporary tables created on disk: 12% (50 on disk / 389 total)
[OK] Thread cache hit rate: 95% (2 created / 43 connections)
[OK] Table cache hit rate: 47% (72 open / 153 opened)
[OK] Open file limit used: 5% (53/1K)
[OK] Table locks acquired immediately: 100% (170 immediate / 170 locks)

-------- Performance schema ------------------------------------------------------------------------
[--] Memory used by P_S: 72B
[--] Sys schema is installed.

-------- ThreadPool Metrics ------------------------------------------------------------------------
[--] ThreadPool stat is disabled.

-------- MyISAM Metrics ----------------------------------------------------------------------------
[!!] Key buffer used: 18.2% (48M used / 268M cache)
[!!] Key buffer size / total MyISAM indexes: 256.0M/1.8G
[!!] Read Key buffer hit rate: 93.6% (78 cached / 5 reads)

-------- InnoDB Metrics ----------------------------------------------------------------------------
[--] InnoDB is enabled.
[--] InnoDB Thread Concurrency: 0
[OK] InnoDB File per table is activated
[OK] InnoDB buffer pool / data size: 128.0M/16.0K
[!!] Ratio InnoDB log file size / InnoDB Buffer pool size (75 %): 48.0M * 2/128.0M should be equal 25%
[OK] InnoDB buffer pool instances: 1
[--] Number of InnoDB Buffer Pool Chunk : 1 for 1 Buffer Pool Instance(s)
[OK] Innodb_buffer_pool_size aligned with Innodb_buffer_pool_chunk_size & Innodb_buffer_pool_instances
[OK] InnoDB Read buffer efficiency: 97.79% (8107 hits/ 8290 total)
[!!] InnoDB Write Log efficiency: 0% (2 hits/ 0 total)
[OK] InnoDB log waits: 0.00% (0 waits / 2 writes)

-------- AriaDB Metrics ----------------------------------------------------------------------------
[--] AriaDB is disabled.

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

-------- XtraDB Metrics ----------------------------------------------------------------------------
[--] XtraDB is disabled.

-------- RocksDB Metrics ---------------------------------------------------------------------------
[--] RocksDB is disabled.

-------- Spider Metrics ----------------------------------------------------------------------------
[--] Spider is disabled.

-------- Connect Metrics ---------------------------------------------------------------------------
[--] Connect 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.

-------- Recommendations ---------------------------------------------------------------------------
General recommendations:
    Control warning line(s) into /var/log/mysql/error.log file
    Control error line(s) into /var/log/mysql/error.log file
    Restrict Host for user@% to user@SpecificDNSorIp
    MySQL started within last 24 hours - recommendations may be inaccurate
    Reduce or eliminate unclosed connections and network issues
    Configure your accounts with ip or subnets only, then update your configuration with skip-name-resolve=1
Variables to adjust:
    key_buffer_size (> 1.8G)
    innodb_log_file_size should be (=16M) if possible, so InnoDB total log files size equals to 25% of buffer pool size.

[Son Goku]

Ich hab Problem lösen können.

Ich hab mir heute morgen ein Shell-Script geschrieben, welches mir SQL-Abfragen an die DB weiter gereicht hat.
Dieses brauchte dann folgende Meldung:

Code: Select all

Kopiere Tabelle xyz...                                                                                                                    
ERROR 2013 (HY000) at line 2: Lost connection to MySQL server during query                                                                                                                                                                   
Fertig! (7262 Sekunden)

Kombiniert mit dem Suchwort "google cloud", war es dann relativ einfach.

Der Keepalive-Wert für TCP-Verbindungen war zu niedrig gesetzt:

Code: Select all

user@server:/projects/scripte$ cat /proc/sys/net/ipv4/tcp_keepalive_time
7200
user@server:/projects/scripte$ cat /proc/sys/net/ipv4/tcp_keepalive_intvl
75
user@server:/projects/scripte$ cat /proc/sys/net/ipv4/tcp_keepalive_probes
9

Note that idle TCP connections are disconnected after 10 minutes.

https://cloud.google.com/compute/docs/t ... thinternet

Daher auch diese 7200 Sekunden.

Ich hab die Werte auf die Empfehlung gesetzt, die Google vorgibt und entsprechend in die "/etc/sysctl.conf" eingetragen:

Code: Select all

net.ipv4.tcp_keepalive_time = 60
net.ipv4.tcp_keepalive_intvl = 60
net.ipv4.tcp_keepalive_probes = 5

https://stackoverflow.com/questions/265 ... -cloud-sql

http://www.tldp.org/HOWTO/html_single/T ... gkeepalive


An dieser Stelle auch nochmal vielen Dank für deine Hilfe.

[Joe User]

Kein Problem, danke für Dein Feedback.