# My slave servers, are delaying (Connect invalidating query cache entrie (table))

**URL:** <https://forums.percona.com/t/my-slave-servers-are-delaying-connect-invalidating-query-cache-entrie-table/2740>\
**Category:** Other MySQL® Questions\
**Created:** [June 5, 2013, 2:12pm UTC](https://forums.percona.com/t/my-slave-servers-are-delaying-connect-invalidating-query-cache-entrie-table/2740 "2013-06-05T14:12:15Z")\
**Posts on this page:** 5\
**Page:** 1

<div class="post-metadata">

**Author:** ![wsantana](https://avatars.discourse-cdn.com/v4/letter/w/3d9bf3/32.png) [@wsantana](https://forums.percona.com/u/wsantana)\
**Post date:** [June 5, 2013, 2:12pm UTC](https://forums.percona.com/t/my-slave-servers-are-delaying-connect-invalidating-query-cache-entrie-table/2740/1 "2013-06-05T14:12:15Z")

</div>

Hello guys, I need you, I have one problem and don’t know to solve. My slave servers, are delaying, delaying about 1 minute and a half and return to normal. And by the time delay, this message appears: “Connect invalidating query cache entrie (table)” … I disabled query\_cache\_type and query\_cache\_size, but the problem was not solved. Version mysql 5.1.69. Thank you very much.

---

<div class="post-metadata">

**Author:** ![mirfan](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/mirfan/32/16890_2.png) [@mirfan](https://forums.percona.com/u/mirfan)\
**Post date:** [June 6, 2013, 2:07am UTC](https://forums.percona.com/t/my-slave-servers-are-delaying-connect-invalidating-query-cache-entrie-table/2740/2 "2013-06-06T02:07:58Z")

</div>

This requires more information to diagnose the slave lag. Can you please share the processlist, innodb status, slave status etc or run pt-stalk during slave lag with --no-stock option. It will help to identify the issue.

FYI, some reasons of slave lag

1. Replication is single threaded and if transaction on master is changing alot of rows this way slave can lag behind.
2. If there are lot of read queries are running on slave this can bring slave lag because of locking.

I would also suggest that to enable slow query log on slave and identify the culprit queries and fix them.

---

<div class="post-metadata">

**Author:** ![wsantana](https://avatars.discourse-cdn.com/v4/letter/w/3d9bf3/32.png) [@wsantana](https://forums.percona.com/u/wsantana)\
**Post date:** [June 6, 2013, 12:21pm UTC](https://forums.percona.com/t/my-slave-servers-are-delaying-connect-invalidating-query-cache-entrie-table/2740/3 "2013-06-06T12:21:00Z")

</div>

Thank you for answering mirfan and help me figure out the problem. Below is the results you see, the same runtime process ID 11, is the same delay time. This problem started from nothing, did rollback to version 5.1.63, but the problem persists. The slow query log is also enabled, I’ll take a parsed. Thank you for your information, helped me a lot, especially the pt-stalk, I did not know him.

wsantana@edipo:(none)-\> show full processlist; show innodb status\G show slave status\G  
±------±------------±-------------------±--------±--------±------±-----------------------------------------±----------------------+  
| Id | User | Host | db | Command | Time | State | Info |  
±------±------------±-------------------±--------±--------±------±-----------------------------------------±----------------------+  
| 10 | system user | | NULL | Connect | 73684 | Waiting for master to send event | NULL |  
| 11 | system user | | NULL | Connect | 55 | invalidating query cache entries (table) | NULL |  
| 45389 | wsantana | 172.16.18.22:44803 | NULL | Query | 0 | NULL | show full processlist |  
| 45407 | ci\_vagas | 10.41.21.30:56392 | conline | Sleep | 1 | | NULL |  
±------±------------±-------------------±--------±--------±------±-----------------------------------------±----------------------+  
4 rows in set (0.00 sec)

# \*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\* 1. row \*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\* Type: InnoDB Name: Status:

# 130606 11:52:00 INNODB MONITOR OUTPUT

## Per second averages calculated from the last 5 seconds

## BACKGROUND THREAD

## srv\_master\_thread loops: 61610 1\_second, 61609 sleeps, 6042 10\_second, 6081 background, 6077 flush srv\_master\_thread log flush and writes: 61931

## SEMAPHORES

## OS WAIT ARRAY INFO: reservation count 38287, signal count 222611 Mutex spin waits 361197, rounds 1012970, OS waits 22385 RW-shared spins 50511, OS waits 12166; RW-excl spins 4205, OS waits 3505 Spin rounds per wait: 2.80 mutex, 10.31 RW-shared, 74.48 RW-excl

## TRANSACTIONS

## Trx id counter 2827A8402 Purge done for trx’s n:o \< 2827A83E1 undo n:o \< 0 History list length 11 LIST OF TRANSACTIONS FOR EACH SESSION: —TRANSACTION 2827A83F5, not started, process no 20489, OS thread id 140424495904512 MySQL thread id 45407, query id 4702285 10.41.21.30 ci\_vagas —TRANSACTION 0, not started, process no 20489, OS thread id 140424434325248 MySQL thread id 45389, query id 4702309 172.16.18.22 wsantana show innodb status —TRANSACTION 2827A8401, ACTIVE 0 sec, process no 20489, OS thread id 140424495105792 fetching rows mysql tables in use 1, locked 1 7610 lock struct(s), heap size 948664, 79377 row lock(s), undo log entries 1 MySQL thread id 11, query id 4702307 invalidating query cache entries (table)

## FILE I/O

## I/O thread 0 state: waiting for i/o request (insert buffer thread) I/O thread 1 state: waiting for i/o request (log thread) I/O thread 2 state: waiting for i/o request (read thread) I/O thread 3 state: waiting for i/o request (read thread) I/O thread 4 state: waiting for i/o request (read thread) I/O thread 5 state: waiting for i/o request (read thread) I/O thread 6 state: waiting for i/o request (write thread) I/O thread 7 state: waiting for i/o request (write thread) I/O thread 8 state: waiting for i/o request (write thread) I/O thread 9 state: waiting for i/o request (write thread) Pending normal aio reads: 0, aio writes: 0, ibuf aio reads: 0, log i/o’s: 0, sync i/o’s: 0 Pending flushes (fsync) log: 0; buffer pool: 0 469096 OS file reads, 2601641 OS file writes, 2035578 OS fsyncs 0.80 reads/s, 16384 avg bytes/read, 56.99 writes/s, 33.39 fsyncs/s

## INSERT BUFFER AND ADAPTIVE HASH INDEX

## Ibuf: size 1, free list len 687, seg size 689, 139722 inserts, 145505 merged recs, 97389 merges Hash table size 31874747, node heap has 17975 buffer(s) 805291.14 hash searches/s, 3482.70 non-hash searches/s

## LOG

## Log sequence number 9526051723870 Log flushed up to 9526051723630 Last checkpoint at 9526015758438 0 pending log writes, 0 pending chkp writes 1925300 log i/o’s done, 31.39 log i/o’s/second

## BUFFER POOL AND MEMORY

## Total memory allocated 16467886080; in additional pool allocated 0 Dictionary memory allocated 3965962 Buffer pool size 983040 Free buffers 421349 Database pages 543659 Old database pages 200706 Modified db pages 19948 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 8099, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 530302, created 16070, written 854406 0.80 reads/s, 0.00 creates/s, 53.19 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 543659, unzip\_LRU len: 0 I/O sum[1046]:cur[0], unzip sum[0]:cur[0]

## ROW OPERATIONS

## 0 queries inside InnoDB, 0 queries in queue 1 read views open inside InnoDB Main thread process no. 20489, id 140406392428288, state: sleeping Number of rows inserted 1903838, updated 566562, deleted 1263229, read 18118733133 27.99 inserts/s, 17.40 updates/s, 24.00 deletes/s, 807927.01 reads/s

# END OF INNODB MONITOR OUTPUT

1 row in set, 1 warning (0.01 sec)

\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\* 1. row \*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*  
Slave\_IO\_State: Waiting for master to send event  
Master\_Host: 10.40.41.11  
Master\_User: slave  
Master\_Port: 3306  
Connect\_Retry: 15  
Master\_Log\_File: afrodite-bin.000332  
Read\_Master\_Log\_Pos: 78044461  
Relay\_Log\_File: relay-bin.001005  
Relay\_Log\_Pos: 78033814  
Relay\_Master\_Log\_File: afrodite-bin.000332  
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: mysql.%,temporario.%  
Last\_Errno: 0  
Last\_Error:  
Skip\_Counter: 0  
Exec\_Master\_Log\_Pos: 78041766  
Relay\_Log\_Space: 78044860  
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: 55  
Master\_SSL\_Verify\_Server\_Cert: No  
Last\_IO\_Errno: 0  
Last\_IO\_Error:  
Last\_SQL\_Errno: 0  
Last\_SQL\_Error:  
1 row in set (0.00 sec)

---

<div class="post-metadata">

**Author:** ![przemek](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/przemek/32/3_2.png) [@przemek](https://forums.percona.com/u/przemek)\
**Post date:** [June 7, 2013, 4:09pm UTC](https://forums.percona.com/t/my-slave-servers-are-delaying-connect-invalidating-query-cache-entrie-table/2740/4 "2013-06-07T16:09:19Z")

</div>

Wsantana,

Are you running with ROW based replication?  
It seems similar to the bug described here: [url][MySQL Bugs: #60696: invalidating query cache entries (table) hangs replication](http://bugs.mysql.com/bug.php?id=60696%5B/url%5D)  
I think you should try to disable query cache in my.cnf and restart the server to see if you still get into this “invalidating query cache entries” state again.  
Add following to configuration, since disabling dynamically may not have exactly the same effect.  
query\_cache\_type=0  
query\_cache\_size=0

---

<div class="post-metadata">

**Author:** ![wsantana](https://avatars.discourse-cdn.com/v4/letter/w/3d9bf3/32.png) [@wsantana](https://forums.percona.com/u/wsantana)\
**Post date:** [June 10, 2013, 9:40am UTC](https://forums.percona.com/t/my-slave-servers-are-delaying-connect-invalidating-query-cache-entrie-table/2740/5 "2013-06-10T09:40:41Z")

</div>

Thank you very much for answering przemek and help me figure out the problem, my based replication is MIXED.  
I read about bug, described here: [http://bugs.mysql.com/bug.php?id=60696](http://bugs.mysql.com/bug.php?id=60696), and I disabled as you directed me, because I had disabled dynamically. Even disabling in the my.cnf, the problem persisted.

I managed to find the cause of the problem, is a php script which is scheduled to run from 12 to 12 minutes. The pt-stalk helped me find the problem.

Just Could not understand why the lag, below is the error that is happening, the error is CONSTRAINT, has warned developers to correct them.

Foreign key constraint fails for table `atende_produto_especial`.`produto_distribuicao_texto`:

* * *

## LATEST FOREIGN KEY ERROR

130607 15:37:24 Transaction:  
TRANSACTION 2AE56991E, ACTIVE 0 sec, process no 21066, OS thread id 140289406871296 inserting, thread declared inside InnoDB 500  
mysql tables in use 1, locked 1  
4 lock struct(s), heap size 1248, 2 row lock(s), undo log entries 1  
MySQL thread id 21335800, query id 1397584584 10.81.21.113 modulos\_produto update  
INSERT INTO^M  
produto\_distribuicao\_texto^M  
SET^M  
produto\_distribuicao\_texto.produto\_distribuicao\_id = “2729727” , produto\_distribuicao\_texto.texto = "Telefone Principal: 11-**^M  
Telefone Secund?rio: 11-**\*\*^M  
Email: \*\*\*_@gmail.com" / — /www\_mounted/intranet/htdocs/siscorp/action/cron/cron\_atende\_distribuicao\_especial.php_/

Foreign key constraint fails for table `atende_produto_especial`.`produto_distribuicao_texto`:  
,  
CONSTRAINT `produto_distribuicao_texto_ibfk_1` FOREIGN KEY (`produto_distribuicao_id`) REFERENCES `produto_distribuicao` (`produto_distribuicao_id`) ON DELETE NO ACTION ON UPDATE NO ACTION  
Trying to add in child table, in index `produto_distribuicao_id` tuple:  
DATA TUPLE: 2 fields;  
0: len 4; hex 0029a6ff; asc ) ;;  
1: len 4; hex 802a4caf; asc \*L ;;

But in parent table `atende_produto_especial`.`produto_distribuicao`, in index `PRIMARY`,  
the closest match we can find is record:  
PHYSICAL RECORD: n\_fields 9; compact format; info bits 0  
0: len 4; hex 0029a700; asc ) ;;  
1: len 6; hex 0002ae5128d1; asc Q( ;;  
2: len 7; hex 80000000330110; asc 3 ;;  
3: len 4; hex 0000014d; asc M;;  
4: len 3; hex 06adc3; asc ;;  
5: len 4; hex 51b20642; asc Q B;;  
6: len 4; hex 0000004b; asc K;;  
7: len 1; hex 02; asc ;;  
8: len 4; hex 80000000; asc ;;