• Als Spam markieren
• Beitrag melden

• 
  Diese Gruppe Alles

• Archiv
• RSS-Feeds

• Kontakt
• Hilfe
• Impressum
• Datenschutz

Sperrt Mysqldump die DB?

Guten Morgen,

habe das Problem dass meine Maschine (8 GB Ram)die letzten Tage vermehrt beim
Backup Probleme macht. Er verbraucht den gesamten Speicher und den gesamten
Swap und hat dann eine Load von über 50. Ich habe jetzt im Log etwas von der
InnoDB gefunden, kann es sein dass der Dump zu lange dauert und dann meine
Connections hängen bleiben? Wenn man reinkommt mit SSH dann sehe ich alle 256
Apacheconnections in use und er braucht ewig bzw. er steht und ist mit sich
selbst beschäftigt. Das Backup startet um 23:00 und läuft dann aber auch
morgens noch. Kollege löst dann immer einen Reset aus! :-(
Erster Teil des Logs:

Nov  4 03:42:15 monster mysqld[3344]: InnoDB: Warning: a long semaphore wait:
Nov  4 03:42:20 monster mysqld[3344]: --Thread 1200695632 has waited at btr0cur.c line 366
for 242.00 seconds the semaphore:
Nov  4 03:42:20 monster mysqld[3344]: S-lock on RW-latch at 0x359f838 created in file
dict0dict.c line 3706
Nov  4 03:42:20 monster mysqld[3344]: number of readers 1, waiters flag 0
Nov  4 03:42:20 monster mysqld[3344]: Last time read locked in file btr0cur.c line 366
Nov  4 03:42:20 monster mysqld[3344]: Last time write locked in file btr0cur.c line 359
Nov  4 03:42:20 monster mysqld[3344]: wait has ended
Nov  4 03:42:20 monster mysqld[3344]: InnoDB: ###### Starts InnoDB Monitor for 30 secs to
print diagnostic info:
Nov  4 03:42:20 monster mysqld[3344]: InnoDB: Pending preads 3, pwrites 0
Nov  4 03:42:20 monster mysqld[3344]:
Nov  4 03:42:20 monster mysqld[3344]: ====================================
Nov  4 03:42:21 monster mysqld[3344]: 091104  3:42:20 INNODB MONITOR OUTPUT
Nov  4 03:42:21 monster mysqld[3344]: ====================================
Nov  4 03:42:21 monster mysqld[3344]: Per second averages calculated from the last 54
seconds
Nov  4 03:42:21 monster mysqld[3344]: ----------
Nov  4 03:42:21 monster mysqld[3344]: SEMAPHORES
Nov  4 03:42:21 monster mysqld[3344]: ----------
Nov  4 03:42:21 monster mysqld[3344]: OS WAIT ARRAY INFO: reservation count 1882678,
signal count 1774543
Nov  4 03:42:21 monster mysqld[3344]: --Thread 1208621392 has waited at log0log.c line 204
for 0.00 seconds the semaphore:
Nov  4 03:42:21 monster mysqld[3344]: Mutex at 0x7f4445a51910 created file log0log.c line
744, lock var 1
Nov  4 03:42:21 monster mysqld[3344]: waiters flag 1
Nov  4 03:42:21 monster mysqld[3344]: --Thread 1200695632 has waited at
./../include/log0log.ic line 315 for 0.00 seconds the semaphore:
Nov  4 03:42:21 monster mysqld[3344]: Mutex at 0x7f4445a51910 created file log0log.c line
744, lock var 1
Nov  4 03:42:21 monster mysqld[3344]: waiters flag 1
Nov  4 03:42:21 monster mysqld[3344]: --Thread 1210734928 has waited at trx0trx.c line 715
for 0.00 seconds the semaphore:
Nov  4 03:42:21 monster mysqld[3344]: Mutex at 0x7f4445a4e2b8 created file srv0srv.c line
872, lock var 1
Nov  4 03:42:21 monster mysqld[3344]: waiters flag 1
Nov  4 03:42:21 monster mysqld[3344]: --Thread 1166350672 has waited at trx0trx.c line 997
for 0.00 seconds the semaphore:
Nov  4 03:42:21 monster mysqld[3344]: Mutex at 0x7f4445a4e2b8 created file srv0srv.c line
872, lock var 1
Nov  4 03:42:21 monster mysqld[3344]: waiters flag 1
Nov  4 03:42:21 monster mysqld[3344]: Mutex spin waits 0, rounds 9624319, OS waits 220291
Nov  4 03:42:21 monster mysqld[3344]: RW-shared spins 3565997, OS waits 1517130; RW-excl
spins 204711, OS waits 119743
Nov  4 03:42:21 monster mysqld[3344]: ------------------------
Nov  4 03:42:21 monster mysqld[3344]: LATEST DETECTED DEADLOCK
Nov  4 03:42:21 monster mysqld[3344]: ------------------------
Nov  4 03:42:27 monster mysqld[3344]: 091103  6:48:57
Nov  4 03:42:27 monster mysqld[3344]: *** (1) TRANSACTION:
Nov  4 03:42:28 monster mysqld[3344]: TRANSACTION 0 379929123, ACTIVE 9 sec, process no
3343, OS thread id 1282066768 starting index read
Nov  4 03:42:28 monster mysqld[3344]: mysql tables in use 1, locked 1
Nov  4 03:42:28 monster mysqld[3344]: LOCK WAIT 2 lock struct(s), heap size 368
Nov  4 03:42:28 monster mysqld[3344]: MySQL thread id 2002356, query id 232028796
localhost 127.0.0.1 ss_pages updating

und das steigert sich dann bis morgens zu 225 Queries waiting.

Nov  4 05:28:08 monster mysqld[3344]: ----------------------
Nov  4 05:28:08 monster mysqld[3344]: BUFFER POOL AND MEMORY
Nov  4 05:28:08 monster mysqld[3344]: ----------------------
Nov  4 05:28:08 monster mysqld[3344]: Total memory allocated 36548226; in additional pool
allocated 1048576
Nov  4 05:28:08 monster mysqld[3344]: Buffer pool size   512
Nov  4 05:28:08 monster mysqld[3344]: Free buffers       0
Nov  4 05:28:08 monster mysqld[3344]: Database pages     510
Nov  4 05:28:08 monster mysqld[3344]: Modified db pages  0
Nov  4 05:28:08 monster mysqld[3344]: Pending reads 0
Nov  4 05:28:08 monster mysqld[3344]: Pending writes: LRU 0, flush list 0, single page 0
Nov  4 05:28:08 monster mysqld[3344]: Pages read 60654217, created 2132060, written
11112858
Nov  4 05:28:08 monster mysqld[3344]: 0.02 reads/s, 0.00 creates/s, 0.39 writes/s
Nov  4 05:28:08 monster mysqld[3344]: Buffer pool hit rate 819 / 1000
Nov  4 05:28:08 monster mysqld[3344]: --------------
Nov  4 05:28:08 monster mysqld[3344]: ROW OPERATIONS
Nov  4 05:28:08 monster mysqld[3344]: --------------
Nov  4 05:28:08 monster mysqld[3344]: 8 queries inside InnoDB, 225 queries in queue
Nov  4 05:28:08 monster mysqld[3344]: 31 read views open inside InnoDB
Nov  4 05:28:08 monster mysqld[3344]: Main thread process no. 3343, id 1153141072, state:
sleeping
Nov  4 05:28:08 monster mysqld[3344]: Number of rows inserted 3379977, updated 446266,
deleted 3446639, read 3831114767
Nov  4 05:28:08 monster mysqld[3344]: 0.02 inserts/s, 0.00 updates/s, 0.02 deletes/s, 0.08
reads/s
Nov  4 05:28:08 monster mysqld[3344]: ----------------------------
Nov  4 05:28:08 monster mysqld[3344]: END OF INNODB MONITOR OUTPUT
Nov  4 05:28:08 monster mysqld[3344]: ===========================

Habe den gesamten Log von heute Nacht hinterlegt:

http://www.netproject.at/getit/mysql.log


Die Konfig der DB, alle Kommentare gelöscht:

[client]
port            = 3306
socket          = /var/run/mysqld/mysqld.sock

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

[mysqld]
user            = mysql
pid-file        = /var/run/mysqld/mysqld.pid
socket          = /var/run/mysqld/mysqld.sock
port            = 3306
basedir         = /usr
datadir         = /Database/mysql
tmpdir          = /tmp
language        = /usr/share/mysql/english
skip-external-locking

key_buffer              = 364M
max_allowed_packet      = 32M
thread_stack            = 512K
thread_cache_size       = 16
sort_buffer_size        = 6M
read_buffer_size        = 4M
myisam_sort_buffer_size = 64M
max_connections        = 400
table_cache            = 512
thread_concurrency     = 4

query_cache_limit       = 8M
query_cache_size        = 960M

skip-bdb

innodb_file_per_table

[mysqldump]
quick
quote-names
max_allowed_packet      = 32M

[mysql]

[isamchk]
key_buffer              = 128M


cat /etc/debian_version
5.0.2

monster:~# free
total       used       free     shared    buffers     cached
Mem:       8168364    7810232     358132          0     157272    2448260
-/+ buffers/cache:    5204700    2963664
Swap:      2097144         92    2097052

Habe noch eine Statistik installiert wo man sieht dass immer beim Backup der
Load hochgeht und der Swap steigt.

http://www.netproject.at/serverstats/

Sieht jemand das Problem im log?

Danke.

Antworten