Take the 2-minute tour ×
Database Administrators Stack Exchange is a question and answer site for database professionals who wish to improve their database skills and learn from others in the community. It's 100% free, no registration required.

I am observing this lag in a continuous manner. Investigating in the bin log events, i found the following information. Slave executing the relay Logs slowly.

 1. Changing the Innodb File Format to Barracuda will improve the Situation ?

Please give me advice.

Master : Row Based :
==================
+------------+
| version()  |
+------------+
| 5.5.17-log |
+------------+
1 row in set (0.00 sec)

+--------------------------+-------------------+
| Variable_name            | Value             |
+--------------------------+-------------------+
| binlog_format            | ROW               |
| date_format              | %Y-%m-%d          |
| datetime_format          | %Y-%m-%d %H:%i:%s |
| default_week_format      | 0                 |
| innodb_file_format       | Antelope          |
| innodb_file_format_check | ON                |
| innodb_file_format_max   | Antelope          |
| time_format              | %H:%i:%s          |
+--------------------------+-------------------+
8 rows in set (0.00 sec)


Slave : Statement Based :  log_Slave_updates = off.
===========================================================
+-----------+
| version() |
+-----------+
| 5.5.17    |
+-----------+
1 row in set (0.00 sec)

+--------------------------+-------------------+
| Variable_name            | Value             |
+--------------------------+-------------------+
| binlog_format            | STATEMENT         |
| date_format              | %Y-%m-%d          |
| datetime_format          | %Y-%m-%d %H:%i:%s |
| default_week_format      | 0                 |
| innodb_file_format       | Antelope          |
| innodb_file_format_check | ON                |
| innodb_file_format_max   | Antelope          |
| time_format              | %H:%i:%s          |
+--------------------------+-------------------+
8 rows in set (0.00 sec)

     *************************** 1. row ***************************
           Slave_IO_State: Waiting for master to send event
              Master_Host: dware-master
              Master_User: replica
              Master_Port: 3306
            Connect_Retry: 60
          Master_Log_File: binlog.001620
      Read_Master_Log_Pos: 328943038
           Relay_Log_File: relay-bin.000109
            Relay_Log_Pos: 444602036
    Relay_Master_Log_File: binlog.001607
         Slave_IO_Running: Yes
        Slave_SQL_Running: Yes
          Replicate_Do_DB: 
      Replicate_Ignore_DB: 
       Replicate_Do_Table: 
   Replicate_Ignore_Table: 
  Replicate_Wild_Do_Table: 
 Replicate_Wild_Ignore_Table: 
               Last_Errno: 0
               Last_Error: 
             Skip_Counter: 0
      Exec_Master_Log_Pos: 444601893
          Relay_Log_Space: 7062540762
          Until_Condition: None
           Until_Log_File: 
            Until_Log_Pos: 0
       Master_SSL_Allowed: No
       Master_SSL_CA_File: 
       Master_SSL_CA_Path: 
          Master_SSL_Cert: 
        Master_SSL_Cipher: 
           Master_SSL_Key: 
    Seconds_Behind_Master: 32298
  Master_SSL_Verify_Server_Cert: No
            Last_IO_Errno: 0
            Last_IO_Error: 
           Last_SQL_Errno: 0
           Last_SQL_Error: 
Replicate_Ignore_Server_Ids: 
         Master_Server_Id: 1
    1 row in set (0.00 sec)
     ===

+--------------------------------+-------+
| Variable_name                  | Value |
+--------------------------------+-------+
| flush                          | OFF   |
| flush_time                     | 0     |
| innodb_adaptive_flushing       | ON    |
| innodb_flush_log_at_trx_commit | 2     |
| innodb_flush_method            |       |
+--------------------------------+-------+
5 rows in set (0.00 sec)

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

         +-------------------+-------+
         | Variable_name     | Value |
         +-------------------+-------+
         | log_slave_updates | OFF   |
         +-------------------+-------+
         1 row in set (0.00 sec)

          ===

Observing the bin logs, I found delayed inserts events:

[root@dware-master binlog]# mysqlbinlog  -v --base64-output=DECODE-ROWS --start-position=444601893 binlog.001607 | head -30
 /*!40019 SET @@session.max_insert_delayed_threads=0*/;
 /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
   DELIMITER /*!*/;
 # at 444601893
 #130323 21:35:43 server id 1  end_log_pos 444601987     Query   thread_id=216095  exec_time=1     error_code=0
SET TIMESTAMP=1364099743/*!*/;
SET @@session.pseudo_thread_id=216095/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0,
@@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=0/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
 /*!\C utf8 *//*!*/;
 SET@@session.character_set_client=33,@@session.collation_connection=33,
 @@session.collation_server=33/*!*/;
 SET @@session.time_zone='SYSTEM'/*!*/;
 SET @@session.lc_time_names=0/*!*/;
 SET @@session.collation_database=DEFAULT/*!*/;
 BEGIN
 /*!*/;
# at 444601987
# at 444602072
# at 444603110
# at 444604148
# at 444605186
# at 444606224
# at 444607262
# at 444608300
# at 444609338
# at 444610372
# at 444611410
# at 444612448
# at 444613486
===========

             EDIT : 28th March,2013
             ========
          *************************** 1. row ***************************
              Slave_IO_State: Waiting for master to send event
                 Master_Host: dware-master
                 Master_User: replica
                 Master_Port: 3306
               Connect_Retry: 60
             Master_Log_File: binlog.001761
         Read_Master_Log_Pos: 147709683
              Relay_Log_File: relay-bin.000126
               Relay_Log_Pos: 166343455
       Relay_Master_Log_File: binlog.001740
            Slave_IO_Running: Yes
           Slave_SQL_Running: Yes
             Replicate_Do_DB: 
         Replicate_Ignore_DB: 
          Replicate_Do_Table: 
      Replicate_Ignore_Table: 
     Replicate_Wild_Do_Table: 
 Replicate_Wild_Ignore_Table: 
                  Last_Errno: 0
                  Last_Error: 
                Skip_Counter: 0
         Exec_Master_Log_Pos: 166343312
             Relay_Log_Space: 11142734247
             Until_Condition: None
              Until_Log_File: 
               Until_Log_Pos: 0
          Master_SSL_Allowed: No
          Master_SSL_CA_File: 
          Master_SSL_CA_Path: 
          Master_SSL_Cert: 
        Master_SSL_Cipher: 
           Master_SSL_Key: 
          Seconds_Behind_Master: 49451
  Master_SSL_Verify_Server_Cert: No
                  Last_IO_Errno: 0
                  Last_IO_Error: 
                 Last_SQL_Errno: 0
                 Last_SQL_Error: 
    Replicate_Ignore_Server_Ids: 
               Master_Server_Id: 1
             1 row in set (0.00 sec)



  +-------+-------------+---------------------------------------+------+---------+------
  --+------------------------------------------+------------------+
  | Id    | User        | Host                                  | db   | Command | Time
  | State                                    | Info             |
  +-------+-------------+---------------------------------------+------+---------+------
  --+------------------------------------------+------------------+
  |  1135 | system user |                                       | NULL | Connect | 
  195917 | Waiting for master to send event         | NULL             |
  |  1136 | system user |                                       | NULL | Connect | 
    49451 | invalidating query cache entries (table) | NULL             |
  | 11608 | dbuser1     | dware.prod:36246 | NULL | Query   |    0 | NULL  
                                   | show processlist |
  +-------+-------------+---------------------------------------+------+---------+------
  --+------------------------------------------+------------------+

  Query Cache Status on Slave :
  =============================
  +-------------------------+----------+
  | Variable_name           | Value    |
  +-------------------------+----------+
  | Qcache_free_blocks      | 1        |
  | Qcache_free_memory      | 33536856 |
  | Qcache_hits             | 0        |
  | Qcache_inserts          | 1        |
  | Qcache_lowmem_prunes    | 0        |
  | Qcache_not_cached       | 5223     |
  | Qcache_queries_in_cache | 0        |
  | Qcache_total_blocks     | 1        |
  +-------------------------+----------+
   8 rows in set (0.00 sec)

 =====
 +--------------------+---------------------------+--------------------------+
 | @@query_cache_size | @@global.query_cache_type | @@local.query_cache_type |
 +--------------------+---------------------------+--------------------------+
 |           33554432 | ON                        | ON                       |
 +--------------------+---------------------------+--------------------------+

  Will Disabling the Query Cache Increase the Performance on the Slave, by Observing the 
  Qcache Status.
share|improve this question
add comment

1 Answer

First of all, you aren't seeing the actual useful information from the binlog (like, what query is actually being executed at that binlog position) because you aren't using the --verbose option, yet you say your master's binlog_format is row.

DECODE-ROWS specifies to mysqlbinlog that you intend for row events to be decoded and displayed as commented SQL statements by also specifying the --verbose option.

Use --verbose to actually see what the event you're looking at contains, because DECODE-ROWS isn't meant to be used without it.

Next, the binlog_format on the slave isn't very relevant in a 2-server environment, because it only specifies the format the slave will use when originating its own binlog entries for additional slave servers further downstream, and for issuing updates it received from its master (if log_slave_updates is enabled). Using binlog_format = statement on the slave isn't a logical thing to do when the master is writing row events, because row events are never translated back to statement events (although the opposite is possible, and quite correctly so)... so your slave's binlogs will contain row-based logging of events received from the master.

If you are constrained for disk performance, you should probably have the slave's binary logging disabled unless it's on its own set of platters.

I found delayed inserts events

I have no idea what this means, although I assume you are looking at this:

/*!40019 SET @@session.max_insert_delayed_threads=0*/;

These statements and the others you show are how replication keeps the slave thread's environment sane as it moves from event to event. They're normal, and there's really nothing to see here... but if you'll use the --verbose option to mysqlbinlog, you can see what the server is doing at those coordinates.

Changing the Innodb File Format to Barracuda will improve the Situation?

No... or maybe. Just changing to Barracuda won't make anything different... although if your real problem on the slave is a disk I/O bottleneck, and if you have sufficient memory and cpu, then you could ALTER TABLE ... ROW_FORMAT=COMPRESSED on selected InnoDB tables after enabling Barracuda and possibly eliminate some bottleneck because on-disk compression should mean less disk I/O, but means more demand on CPU as well as more demand on the InnoDB Buffer Pool, which will try to store both the compressed and uncompressed versions of some pages.

But the first step is to identify what about your server is making it slow. Are you using swap space? You should have it available but it should be all free, or almost all free. Is your InnoDB Buffer Pool appropriately sized? Is anything else on the system competing for resources? Are you blocking on CPU or blocking on I/O?

share|improve this answer
    
Thanks Michael for a Brief Explanation. I will have a look at your recommendations. –  Gopinath Mar 26 '13 at 12:52
add comment

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.