List:General Discussion« Previous MessageNext Message »
From:Machiel Richards Date:June 2 2010 7:40am
Subject:Strange errors / messages on slave server
View as plain text  
Good day all

 

                I hope someone can assist me with this.

 

                While doing the normal routine daily health checks on one of
our clients' servers I came across some strange behaviour from the slave
server. (two servers setup in master / slave replication)

 

                While looking at the current Innodb buffer pool usage
(master server), I noticed that the usage went up from 44% yesterday to
98.7% today, however nothing on the master server suggested why.

 

                I went on to look at the save server and found very strange
behaviour (for me anyway) and I am hoping someone can assist in explaining
this to me and some possible corrective actions:

 

                When running show slave status, it seems that there was an
error logged which show in the output as below:

 

mysql> show slave status;

+----------------------------------+----------------------+-------------+---
----------+---------------+------------------+---------------------+--------
--------------+---------------+-----------------------+------------------+--
-----------------+-----------------+---------------------+------------------
--+------------------------+-------------------------+----------------------
-------+------------+-------------------------------------------------------
----------------------------------------------------------------------------
--------------------------------------------------------------------+-------
-------+---------------------+-----------------+-----------------+----------
------+---------------+--------------------+--------------------+-----------
---------+-----------------+-------------------+----------------+-----------
------------+

| Slave_IO_State                   | Master_Host          | Master_User |
Master_Port | Connect_Retry | Master_Log_File  | Read_Master_Log_Pos |
Relay_Log_File       | Relay_Log_Pos | Relay_Master_Log_File |
Slave_IO_Running | Slave_SQL_Running | Replicate_Do_DB | Replicate_Ignore_DB
| Replicate_Do_Table | Replicate_Ignore_Table | Replicate_Wild_Do_Table |
Replicate_Wild_Ignore_Table | Last_Errno | Last_Error
| Skip_Counter | Exec_Master_Log_Pos | Relay_Log_Space | Until_Condition |
Until_Log_File | Until_Log_Pos | Master_SSL_Allowed | Master_SSL_CA_File |
Master_SSL_CA_Path | Master_SSL_Cert | Master_SSL_Cipher | Master_SSL_Key |
Seconds_Behind_Master |

+----------------------------------+----------------------+-------------+---
----------+---------------+------------------+---------------------+--------
--------------+---------------+-----------------------+------------------+--
-----------------+-----------------+---------------------+------------------
--+------------------------+-------------------------+----------------------
-------+------------+-------------------------------------------------------
----------------------------------------------------------------------------
--------------------------------------------------------------------+-------
-------+---------------------+-----------------+-----------------+----------
------+---------------+--------------------+--------------------+-----------
---------+-----------------+-------------------+----------------+-----------
------------+

| Waiting for master to send event | MASTER.SERVER | repladmin   |
3306 |            60 | mysql-bin.000327 |           672223064 |
SLAVE-relay-bin.001016 |     598540830 | mysql-bin.000326      | Yes
| No                |                 |                     |
|                        |                         |
|       1206 | Error 'The total number of locks exceeds the lock table size'
on query. Default database: 'profiler'. Query: 'update profile_options set
`value` = REPLACE(`value`, '.', '') where list_item_id = 11' |            0
|           598540693 |      1746329551 | None            |                |
0 | No                 |                    |                    |
|                   |                |                  NULL |

+----------------------------------+----------------------+-------------+---
----------+---------------+------------------+---------------------+--------
--------------+---------------+-----------------------+------------------+--
-----------------+-----------------+---------------------+------------------
--+------------------------+-------------------------+----------------------
-------+------------+-------------------------------------------------------
----------------------------------------------------------------------------
--------------------------------------------------------------------+-------
-------+---------------------+-----------------+-----------------+----------
------+---------------+--------------------+--------------------+-----------
---------+-----------------+-------------------+----------------+-----------
------------+

1 row in set (0.00 sec)

 

Then looking at the log files the following was found:

 

100601  9:56:54  InnoDB: WARNING: over 67 percent of the buffer pool is
occupied by

InnoDB: lock heaps or the adaptive hash index! Check that your

InnoDB: transactions do not set too many row locks.

InnoDB: Your buffer pool size is 8 MB. Maybe you should make

InnoDB: the buffer pool bigger?

InnoDB: Starting the InnoDB Monitor to print diagnostics, including

InnoDB: lock heap and hash index sizes.

100601  9:56:54 [ERROR] Slave: Error 'The total number of locks exceeds the
lock table size' on query. Default database: 'profiler'. Query: 'update
profile_options set `value` = REPLACE(`value`, '.', '') where list_item_id =
11', Error_code: 1206

100601  9:56:54 [ERROR] Error running query, slave SQL thread aborted. Fix
the problem, and restart the slave SQL thread with "SLAVE START". We stopped
at log 'mysql-bin.000326' position 598540693

 

=====================================

100601  9:57:00 INNODB MONITOR OUTPUT

=====================================

Per second averages calculated from the last 61 seconds

----------

SEMAPHORES

----------

OS WAIT ARRAY INFO: reservation count 246260, signal count 246194

Mutex spin waits 0, rounds 2310610, OS waits 10307

RW-shared spins 423365, OS waits 208580; RW-excl spins 28923, OS waits 25636

------------

TRANSACTIONS

------------

Trx id counter 0 12672316

Purge done for trx's n:o < 0 12672314 undo n:o < 0 0

History list length 1

Total number of lock structs in row lock hash table 0

LIST OF TRANSACTIONS FOR EACH SESSION:

--------

FILE I/O

 

                Looking at the log output, firstly the same error is showing
in the logs as well.

                Secondly, It also started running this INNODB MONITOR which
generated thousands of entries in the log file (about 30000+ lines of
output).

 

                I really hope that someone can assist with this one as I am
still a fairly new dba and this is completely new to me...

Appreciate all replies.

 

Regards

Machiel


Thread
Strange errors / messages on slave serverMachiel Richards2 Jun
  • RE: Strange errors / messages on slave servermachiel.richards2 Jun
    • RE: Strange errors / messages on slave serverJerry Schwartz2 Jun
      • Re: Strange errors / messages on slave serverMachiel Richards2 Jun
      • RE: Strange errors / messages on slave serverMartin Gainty2 Jun
        • Re: Strange errors / messages on slave serverJohan De Meersman2 Jun