0

I have Mysql5.5 on windows system. Since past 1 month it is running slow.

Here is the query which are running the most:

   begin
     update  roomlogs set roomlogs.exitTime = ptime,roomlogs.`status` = 1
      where  roomlogs.netId = pnetid
        and  roomlogs.`status` = 0
        and  roomlogs.enterTime>=DATE(ptime)
        and  roomlogs.enterTime<DATE(ptime) + interval 1 day;
     INSERT
       into  roomlogs (roomlogs.roomId, roomlogs.netId, roomlogs.enterTime,
                       roomlogs.exitTime, roomlogs.hidden, roomlogs.checkinId)
            value
                (pRoomId, pnetid,ptime, pexit, phidden, pcheckid);
     select  *
       from  roomlogs
       where  roomlogs.roomlogId = LAST_INSERT_ID();
   end

AND:

begin
    select  count(*) as total
        from  roomlogs
        where  roomId = proomId
          and  roomlogs.`status` = 0
          AND  roomlogs.enterTime >= CURDATE()
          AND  roomlogs.enterTime  < CURDATE() + INTERVAL 1 DAY
          and  roomlogs.hidden!=1;
end

Here index of roomlogs are primary(roomlogId), NETID(netid,status,enterTime), ROOMID(roomID,status,enterTime)

Here is my InnoDB status when MySQL has more number of queries (around 100) running simultaneously in the server.

 =====================================
 2018-10-25 17:42:01 1728 INNODB MONITOR OUTPUT
 =====================================
 Per second averages calculated from the last 20 seconds
 -----------------
 BACKGROUND THREAD
 -----------------
 srv_master_thread loops: 148860 srv_active, 0 srv_shutdown, 271514 srv_idle
 srv_master_thread log flush and writes: 420374
 ----------
 SEMAPHORES
 ----------
 OS WAIT ARRAY INFO: reservation count 80056
 OS WAIT ARRAY INFO: signal count 80039
 Mutex spin waits 6920930, rounds 7674964, OS waits 52940
 RW-shared spins 27042, rounds 803211, OS waits 26514
 RW-excl spins 1173, rounds 9109, OS waits 211
 Spin rounds per wait: 1.11 mutex, 29.70 RW-shared, 7.77 RW-excl
 ------------
 TRANSACTIONS
 ------------
 Trx id counter 78706084
 Purge done for trx's n:o < 78706079 undo n:o < 0 state: running but idle
 History list length 2281
 LIST OF TRANSACTIONS FOR EACH SESSION:
 ---TRANSACTION 78705887, not started
 MySQL thread id 3000, OS thread handle 0x8e0, query id 4915274 localhost 127.0.0.1 root cleaning up
**------------ SKIPPING SOME DATA HERE--------------**
 ---TRANSACTION 78701492, not started
 MySQL thread id 15, OS thread handle 0x12c4, query id 4889345 localhost 127.0.0.1 root cleaning up
 ---TRANSACTION 78697207, not started
 MySQL thread id 16, OS thread handle 0x408, query id 4889123 localhost 127.0.0.1 root cleaning up
 ---TRANSACTION 78701491, not started
 MySQL thread id 14, OS thread handle 0x11c8, query id 4889320 localhost 127.0.0.1 root cleaning up
 ---TRANSACTION 78697202, not started
 MySQL thread id 13, OS thread handle 0x10dc, query id 4889098 localhost 127.0.0.1 root cleaning up
 ---TRANSACTION 78706073, ACTIVE 1 sec starting index read
 mysql tables in use 1, locked 1
 LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
 MySQL thread id 2989, OS thread handle 0x157c, query id 4916082 localhost 127.0.0.1 root updating
 update roomlogs set roomlogs.exitTime = ptime,roomlogs.`status` = 1  where roomlogs.netId = pnetid and roomlogs.`status` = 0 and
       roomlogs.enterTime>=DATE(ptime) and 
       roomlogs.enterTime<DATE(ptime) + interval 1 day
 ------- TRX HAS BEEN WAITING 1 SEC FOR THIS LOCK TO BE GRANTED:
 RECORD LOCKS space id 1461 page no 6 n bits 328 index `PRIMARY` of table `indoormap_v2_beta4`.`roomlogs` trx id 78706073 lock_mode X waiting
 Record lock, heap no 2 PHYSICAL RECORD: n_fields 10; compact format; info bits 0
  0: len 4; hex 80000011; asc     ;;
  1: len 6; hex 0000028a4fc7; asc     O ;;
  2: len 7; hex c3000001ed0110; asc        ;;
  3: len 7; hex 726f6f6d313038; asc room108;;
  4: len 7; hex 7973756e313032; asc ysun102;;
  5: len 5; hex 999d1f25db; asc    % ;;
  6: len 5; hex 999d1d2a13; asc    * ;;
  7: len 4; hex 80000001; asc     ;;
  8: len 4; hex 80000000; asc     ;;
  9: len 4; hex 7fffffff; asc     ;;

 ------------------
 ---TRANSACTION 78706056, ACTIVE 4 sec starting index read
 mysql tables in use 1, locked 1
 LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
 MySQL thread id 2942, OS thread handle 0x15e0, query id 4916017 localhost 127.0.0.1 root updating
 update roomlogs set roomlogs.exitTime = ptime,roomlogs.`status` = 1  where roomlogs.netId = pnetid and roomlogs.`status` = 0 and
       roomlogs.enterTime>=DATE(ptime) and 
       roomlogs.enterTime<DATE(ptime) + interval 1 day
 ------- TRX HAS BEEN WAITING 4 SEC FOR THIS LOCK TO BE GRANTED:
 RECORD LOCKS space id 1461 page no 6 n bits 328 index `PRIMARY` of table `indoormap_v2_beta4`.`roomlogs` trx id 78706056 lock_mode X waiting
 Record lock, heap no 2 PHYSICAL RECORD: n_fields 10; compact format; info bits 0
  0: len 4; hex 80000011; asc     ;;
  1: len 6; hex 0000028a4fc7; asc     O ;;
  2: len 7; hex c3000001ed0110; asc        ;;
  3: len 7; hex 726f6f6d313038; asc room108;;
  4: len 7; hex 7973756e313032; asc ysun102;;
  5: len 5; hex 999d1f25db; asc    % ;;
  6: len 5; hex 999d1d2a13; asc    * ;;
  7: len 4; hex 80000001; asc     ;;
  8: len 4; hex 80000000; asc     ;;
  9: len 4; hex 7fffffff; asc     ;;

 ------------------
 ---TRANSACTION 78706045, ACTIVE 5 sec starting index read
 mysql tables in use 1, locked 1
 LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
 MySQL thread id 2976, OS thread handle 0x125c, query id 4915976 localhost 127.0.0.1 root updating
 update roomlogs set roomlogs.exitTime = ptime,roomlogs.`status` = 1  where roomlogs.netId = pnetid and roomlogs.`status` = 0 and
       roomlogs.enterTime>=DATE(ptime) and 
       roomlogs.enterTime<DATE(ptime) + interval 1 day
 ------- TRX HAS BEEN WAITING 5 SEC FOR THIS LOCK TO BE GRANTED:
 RECORD LOCKS space id 1461 page no 6 n bits 328 index `PRIMARY` of table `indoormap_v2_beta4`.`roomlogs` trx id 78706045 lock_mode X waiting
 Record lock, heap no 2 PHYSICAL RECORD: n_fields 10; compact format; info bits 0
  0: len 4; hex 80000011; asc     ;;
  1: len 6; hex 0000028a4fc7; asc     O ;;
  2: len 7; hex c3000001ed0110; asc        ;;
  3: len 7; hex 726f6f6d313038; asc room108;;
  4: len 7; hex 7973756e313032; asc ysun102;;
  5: len 5; hex 999d1f25db; asc    % ;;
  6: len 5; hex 999d1d2a13; asc    * ;;
  7: len 4; hex 80000001; asc     ;;
  8: len 4; hex 80000000; asc     ;;
  9: len 4; hex 7fffffff; asc     ;;

 ------------------
 ---TRANSACTION 78706009, ACTIVE 9 sec starting index read
 mysql tables in use 1, locked 1
 LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
 MySQL thread id 2946, OS thread handle 0xb98, query id 4915824 localhost 127.0.0.1 root updating
 update roomlogs set roomlogs.exitTime = ptime,roomlogs.`status` = 1  where roomlogs.netId = pnetid and roomlogs.`status` = 0 and
       roomlogs.enterTime>=DATE(ptime) and 
       roomlogs.enterTime<DATE(ptime) + interval 1 day
 ------- TRX HAS BEEN WAITING 9 SEC FOR THIS LOCK TO BE GRANTED:
 RECORD LOCKS space id 1461 page no 6 n bits 328 index `PRIMARY` of table `indoormap_v2_beta4`.`roomlogs` trx id 78706009 lock_mode X waiting
 Record lock, heap no 2 PHYSICAL RECORD: n_fields 10; compact format; info bits 0
  0: len 4; hex 80000011; asc     ;;
  1: len 6; hex 0000028a4fc7; asc     O ;;
  2: len 7; hex c3000001ed0110; asc        ;;
  3: len 7; hex 726f6f6d313038; asc room108;;
  4: len 7; hex 7973756e313032; asc ysun102;;
  5: len 5; hex 999d1f25db; asc    % ;;
  6: len 5; hex 999d1d2a13; asc    * ;;
  7: len 4; hex 80000001; asc     ;;
  8: len 4; hex 80000000; asc     ;;
  9: len 4; hex 7fffffff; asc     ;;

 ------------------
 ---TRANSACTION 78706004, ACTIVE 10 sec starting index read
 mysql tables in use 1, locked 1
 LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
 MySQL thread id 2995, OS thread handle 0x1234, query id 4915806 localhost 127.0.0.1 root updating
 update roomlogs set roomlogs.exitTime = ptime,roomlogs.`status` = 1  where roomlogs.netId = pnetid and roomlogs.`status` = 0 and
       roomlogs.enterTime>=DATE(ptime) and 
       roomlogs.enterTime<DATE(ptime) + interval 1 day
 ------- TRX HAS BEEN WAITING 10 SEC FOR THIS LOCK TO BE GRANTED:
 RECORD LOCKS space id 1461 page no 6 n bits 328 index `PRIMARY` of table `indoormap_v2_beta4`.`roomlogs` trx id 78706004 lock_mode X waiting
 Record lock, heap no 2 PHYSICAL RECORD: n_fields 10; compact format; info bits 0
  0: len 4; hex 80000011; asc     ;;
  1: len 6; hex 0000028a4fc7; asc     O ;;
  2: len 7; hex c3000001ed0110; asc        ;;
  3: len 7; hex 726f6f6d313038; asc room108;;
  4: len 7; hex 7973756e313032; asc ysun102;;
  5: len 5; hex 999d1f25db; asc    % ;;
  6: len 5; hex 999d1d2a13; asc    * ;;
  7: len 4; hex 80000001; asc     ;;
  8: len 4; hex 80000000; asc     ;;
  9: len 4; hex 7fffffff; asc     ;;

 ------------------
 ---TRANSACTION 78705997, ACTIVE 12 sec starting index read
 mysql tables in use 1, locked 1
 LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
 MySQL thread id 2948, OS thread handle 0x1708, query id 4915783 localhost 127.0.0.1 root updating
 update roomlogs set roomlogs.exitTime = ptime,roomlogs.`status` = 1  where roomlogs.netId = pnetid and roomlogs.`status` = 0 and
       roomlogs.enterTime>=DATE(ptime) and 
       roomlogs.enterTime<DATE(ptime) + interval 1 day
 ------- TRX HAS BEEN WAITING 12 SEC FOR THIS LOCK TO BE GRANTED:
 RECORD LOCKS space id 1461 page no 6 n bits 328 index `PRIMARY` of table `indoormap_v2_beta4`.`roomlogs` trx id 78705997 lock_mode X waiting
 Record lock, heap no 2 PHYSICAL RECORD: n_fields 10; compact format; info bits 0
  0: len 4; hex 80000011; asc     ;;
  1: len 6; hex 0000028a4fc7; asc     O ;;
  2: len 7; hex c3000001ed0110; asc        ;;
  3: len 7; hex 726f6f6d313038; asc room108;;
  4: len 7; hex 7973756e313032; asc ysun102;;
  5: len 5; hex 999d1f25db; asc    % ;;
  6: len 5; hex 999d1d2a13; asc    * ;;
  7: len 4; hex 80000001; asc     ;;
  8: len 4; hex 80000000; asc     ;;
  9: len 4; hex 7fffffff; asc     ;;

 ------------------
 ---TRANSACTION 78705985, ACTIVE 14 sec starting index read
 mysql tables in use 1, locked 1
 LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
 MySQL thread id 2986, OS thread handle 0x1640, query id 4915747 localhost 127.0.0.1 root updating
 update roomlogs set roomlogs.exitTime = ptime,roomlogs.`status` = 1  where roomlogs.netId = pnetid and roomlogs.`status` = 0 and
       roomlogs.enterTime>=DATE(ptime) and 
       roomlogs.enterTime<DATE(ptime) + interval 1 day
 ------- TRX HAS BEEN WAITING 14 SEC FOR THIS LOCK TO BE GRANTED:
 RECORD LOCKS space id 1461 page no 6 n bits 328 index `PRIMARY` of table `indoormap_v2_beta4`.`roomlogs` trx id 78705985 lock_mode X waiting
 Record lock, heap no 2 PHYSICAL RECORD: n_fields 10; compact format; info bits 0
  0: len 4; hex 80000011; asc     ;;
  1: len 6; hex 0000028a4fc7; asc     O ;;
  2: len 7; hex c3000001ed0110; asc        ;;
  3: len 7; hex 726f6f6d313038; asc room108;;
  4: len 7; hex 7973756e313032; asc ysun102;;
  5: len 5; hex 999d1f25db; asc    % ;;
  6: len 5; hex 999d1d2a13; asc    * ;;
  7: len 4; hex 80000001; asc     ;;
  8: len 4; hex 80000000; asc     ;;
  9: len 4; hex 7fffffff; asc     ;;

 ------------------
 ---TRANSACTION 78705977, ACTIVE 16 sec fetching rows
 mysql tables in use 1, locked 1
 4610 lock struct(s), heap size 539064, 1001945 row lock(s)
 MySQL thread id 2938, OS thread handle 0x10bc, query id 4915725 localhost 127.0.0.1 root updating
 update roomlogs set roomlogs.exitTime = ptime,roomlogs.`status` = 1  where roomlogs.netId = pnetid and roomlogs.`status` = 0 and
       roomlogs.enterTime>=DATE(ptime) and 
       roomlogs.enterTime<DATE(ptime) + interval 1 day
 --------
 FILE I/O
 --------
 I/O thread 0 state: wait Windows aio (insert buffer thread)
 I/O thread 1 state: wait Windows aio (log thread)
 I/O thread 2 state: wait Windows aio (read thread)
 I/O thread 3 state: wait Windows aio (read thread)
 I/O thread 4 state: wait Windows aio (read thread)
 I/O thread 5 state: wait Windows aio (read thread)
 I/O thread 6 state: wait Windows aio (write thread)
 I/O thread 7 state: wait Windows aio (write thread)
 I/O thread 8 state: wait Windows aio (write thread)
 I/O thread 9 state: wait Windows aio (write thread)
 Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
  ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
 Pending flushes (fsync) log: 0; buffer pool: 0
 23467 OS file reads, 931766 OS file writes, 524775 OS fsyncs
 0.00 reads/s, 0 avg bytes/read, 1.00 writes/s, 1.00 fsyncs/s
 -------------------------------------
 INSERT BUFFER AND ADAPTIVE HASH INDEX
 -------------------------------------
 Ibuf: size 1, free list len 39, seg size 41, 61 merges
 merged operations:
  insert 57, delete mark 5, delete 0
 discarded operations:
  insert 0, delete mark 0, delete 0
 Hash table size 4425293, node heap has 2003 buffer(s)
 30.00 hash searches/s, 19.95 non-hash searches/s
 ---
 LOG
 ---
 Log sequence number 7396884835
 Log flushed up to   7396884835
 Pages flushed up to 7396717673
 Last checkpoint at  7396717673
 0 pending log writes, 0 pending chkp writes
 164342 log i/o's done, 1.00 log i/o's/second
 ----------------------
 BUFFER POOL AND MEMORY
 ----------------------
 Total memory allocated 2197815296; in additional pool allocated 0
 Dictionary memory allocated 2793588
 Buffer pool size   131072
 Free buffers       101935
 Database pages     27102
 Old database pages 9967
 Modified db pages  377
 Pending reads 0
 Pending writes: LRU 0, flush list 0, single page 0
 Pages made young 498, not young 0
 0.00 youngs/s, 0.00 non-youngs/s
 Pages read 22500, created 4602, written 613885
 0.00 reads/s, 0.10 creates/s, 0.00 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: 27102, unzip_LRU len: 0
 I/O sum[0]:cur[0], unzip sum[0]:cur[0]
 ----------------------
 INDIVIDUAL BUFFER POOL INFO
 ----------------------
 ---BUFFER POOL 0
 Buffer pool size   16384
 Free buffers       12818
 Database pages     3312
 Old database pages 1240
 Modified db pages  63
 Pending reads 0
 Pending writes: LRU 0, flush list 0, single page 0
 Pages made young 72, not young 0
 0.00 youngs/s, 0.00 non-youngs/s
 Pages read 2713, created 599, written 81358
 0.00 reads/s, 0.00 creates/s, 0.00 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: 3312, unzip_LRU len: 0
 I/O sum[0]:cur[0], unzip sum[0]:cur[0]
 ---BUFFER POOL 1
 Buffer pool size   16384
 Free buffers       12809
 Database pages     3319
 Old database pages 1215
 Modified db pages  27
 Pending reads 0
 Pending writes: LRU 0, flush list 0, single page 0
 Pages made young 15, not young 0
 0.00 youngs/s, 0.00 non-youngs/s
 Pages read 2770, created 549, written 78718
 0.00 reads/s, 0.00 creates/s, 0.00 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: 3319, unzip_LRU len: 0
 I/O sum[0]:cur[0], unzip sum[0]:cur[0]
 ---BUFFER POOL 2
 Buffer pool size   16384
 Free buffers       12717
 Database pages     3411
 Old database pages 1256
 Modified db pages  28
 Pending reads 0
 Pending writes: LRU 0, flush list 0, single page 0
 Pages made young 77, not young 0
 0.00 youngs/s, 0.00 non-youngs/s
 Pages read 2795, created 616, written 49290
 0.00 reads/s, 0.00 creates/s, 0.00 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: 3411, unzip_LRU len: 0
 I/O sum[0]:cur[0], unzip sum[0]:cur[0]
 ---BUFFER POOL 3
 Buffer pool size   16384
 Free buffers       12733
 Database pages     3395
 Old database pages 1246
 Modified db pages  51
 Pending reads 0
 Pending writes: LRU 0, flush list 0, single page 0
 Pages made young 45, not young 0
 0.00 youngs/s, 0.00 non-youngs/s
 Pages read 2780, created 615, written 91680
 0.00 reads/s, 0.00 creates/s, 0.00 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: 3395, unzip_LRU len: 0
 I/O sum[0]:cur[0], unzip sum[0]:cur[0]
 ---BUFFER POOL 4
 Buffer pool size   16384
 Free buffers       12812
 Database pages     3318
 Old database pages 1217
 Modified db pages  47
 Pending reads 0
 Pending writes: LRU 0, flush list 0, single page 0
 Pages made young 108, not young 0
 0.00 youngs/s, 0.00 non-youngs/s
 Pages read 2645, created 673, written 95064
 0.00 reads/s, 0.00 creates/s, 0.00 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: 3318, unzip_LRU len: 0
 I/O sum[0]:cur[0], unzip sum[0]:cur[0]
 ---BUFFER POOL 5
 Buffer pool size   16384
 Free buffers       12590
 Database pages     3538
 Old database pages 1294
 Modified db pages  51
 Pending reads 0
 Pending writes: LRU 0, flush list 0, single page 0
 Pages made young 35, not young 0
 0.00 youngs/s, 0.00 non-youngs/s
 Pages read 2905, created 633, written 89554
 0.00 reads/s, 0.00 creates/s, 0.00 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: 3538, unzip_LRU len: 0
 I/O sum[0]:cur[0], unzip sum[0]:cur[0]
 ---BUFFER POOL 6
 Buffer pool size   16384
 Free buffers       12563
 Database pages     3567
 Old database pages 1307
 Modified db pages  52
 Pending reads 0
 Pending writes: LRU 0, flush list 0, single page 0
 Pages made young 32, not young 0
 0.00 youngs/s, 0.00 non-youngs/s
 Pages read 3127, created 440, written 56311
 0.00 reads/s, 0.00 creates/s, 0.00 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: 3567, unzip_LRU len: 0
 I/O sum[0]:cur[0], unzip sum[0]:cur[0]
 ---BUFFER POOL 7
 Buffer pool size   16384
 Free buffers       12893
 Database pages     3242
 Old database pages 1192
 Modified db pages  58
 Pending reads 0
 Pending writes: LRU 0, flush list 0, single page 0
 Pages made young 114, not young 0
 0.00 youngs/s, 0.00 non-youngs/s
 Pages read 2765, created 477, written 71910
 0.00 reads/s, 0.10 creates/s, 0.00 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: 3242, unzip_LRU len: 0
 I/O sum[0]: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 id 5080, state: sleeping
 Number of rows inserted 97780, updated 862074, deleted 219, read 468159566176
 1.55 inserts/s, 1.20 updates/s, 0.00 deletes/s, 3363648.47 reads/s
 ----------------------------
 END OF INNODB MONITOR OUTPUT
 ============================

So, Here you can see that transaction was waiting for a record lock, Also the last transaction with ID 78705977 is locking 1001945 rows which it should be as it is not updating that much rows. Also Why it is taking time to fetch the rows like 16 seconds?

Here is create Table of roomlogs:

CREATE TABLE `roomlogs` (
   `roomId` varchar(200) CHARACTER SET latin1 DEFAULT NULL,
   `netId` varchar(50) CHARACTER SET latin1 DEFAULT NULL,
   `enterTime` datetime DEFAULT NULL,
   `exitTime` datetime DEFAULT NULL,
   `roomlogId` int(11) NOT NULL AUTO_INCREMENT,
   `status` int(11) DEFAULT '0',
   `hidden` int(11) DEFAULT '0',
   `checkinId` int(11) DEFAULT '-1',
   PRIMARY KEY (`roomlogId`),
   KEY `NETID` (`netId`,`status`,`enterTime`),
   KEY `RoomLogIndex` (`roomId`,`status`,`enterTime`)
 ) ENGINE=InnoDB AUTO_INCREMENT=1315726 DEFAULT CHARSET=utf8
Nilesh
  • 884
  • 3
  • 11
  • 22

4 Answers4

0

Normally the contention should not happen because of the status - attribute which is updated at the same time. But because of MVCC the different transaction do not recognize that the records are not to be changed anymore. Therefore they all see the same records and lock them even if they would not have to do that because of the already changed status.

I suspect, that for you it is important, that the single change is done.

At the moment the transaction A (for example) locks all the records as they seem to be changed, according to the state of the data beginning of the transaction.

As soon as all records could be locked by A because all transactions running parallel at the beginning have been committed, transaction A locks and fetches those records, finds out, that the status has already been changed and does the changes on the leftovers.

After that change the originally locked set of records are unlocked.

The leftovers might not be many, but the contention is heavy.

The solution I see: There seem to be many parallel threads changing the records with the same netid. Can that be avoided?

if not, I never tried that, but perhaps changing the isolation level can help: See: https://dev.mysql.com/doc/refman/8.0/en/innodb-transaction-isolation-levels.html

aschoerk
  • 3,333
  • 2
  • 15
  • 29
  • Any solution to this? – Nilesh Oct 26 '18 at 05:11
  • I just added an additional question – aschoerk Oct 26 '18 at 05:11
  • See: https://stackoverflow.com/questions/51852498/mysql-holds-and-waiting-for-the-same-lock?rq=1 – aschoerk Oct 26 '18 at 05:31
  • Hello, @aschoerk, Thank you for your answer. Here Status will have a default value of 0 and this query change it to 1. Status never goes from 1 to 0. So, by this transaction A will not have any leftover record that another query has changed because it select with status. Also, do you have a reasoning for the last transaction with ID 78705977 is locking 1001945 rows? Because normally the records ny query will update will be around 10-15. – Nilesh Oct 26 '18 at 06:45
  • I don't know, what else did this transaction do. It is puzzling, that some transactions wait for more than 10 seconds to change one record. Is it only this statement that causes the contention, or are there other changes during these transactions as well? – aschoerk Oct 26 '18 at 06:57
  • I have updated the stored procedure call and index information which might be useful. – Nilesh Oct 26 '18 at 07:10
  • 1
    You also very frequently change the index, that also can lead to contention. You are only interested in Records with status 0, either dont index records with status 0 (not sure if that is possible with mysql) or remove status from index. I would prefer the latter. How many records does a netid generate per day? – aschoerk Oct 26 '18 at 08:46
  • Let us [continue this discussion in chat](https://chat.stackoverflow.com/rooms/182608/discussion-between-nilesh-and-aschoerk). – Nilesh Oct 26 '18 at 17:49
0

I don't (yet) see why the update is stumbling over itself. But I see some things that might speed up other things, thereby helping indirectly:

Item 1, faster select

 select  *
   from  roomlogs
   where  roomlogs.roomlogId = LAST_INSERT_ID();

Could (perhaps) be replaced by

 SELECT LAST_INSERT_ID(),
        pRoomId, pnetid, ptime, pexit, phidden, pcheckid;

Caution: I am assuming that those are the only columns, and that the order is correct. Please provide SHOW CREATE TABLE roomlogs so we don't have to guess.

Item 2, covering index

INDEX (roomID, status, enterTime)

-->

INDEX (roomID, status, enterTime, hidden)

This would be a "covering index", thereby speeding up the SELECT COUNT(*) ...

Item 3, better optimization

If hidden has only values 0 and 1, then

hidden != 1

-->

hidden = 0

The Optimizer can handle = better than !=. At that point, this is an even better index for item 2:

INDEX (roomID, status, hidden, enterTime)

Note: I did not recommend this in Item 2 because of the !=.

Item 4, datatype:

If status is not some form of INT, then I will have the answer. Again, need SHOW CREATE TABLE roomlogs

Rick James
  • 135,179
  • 13
  • 127
  • 222
  • I have updated create table. Also because status is the index and we are updating it, It make the update queries to wait for one another? – Nilesh Oct 26 '18 at 17:46
  • @Nilesh - Valid question. I don't know what gets locked in a situation like this. – Rick James Oct 26 '18 at 17:57
  • Is there a way to find out? Also, I do not have logical reasoning for for the last transaction with ID 78705977 is locking 1001945 rows also takes 16 second for fetching? Because normally the records any query will update will be around 10-15. – Nilesh Oct 26 '18 at 19:02
  • @Nilesh - How many rows are involved in the `UPDATE`? Sounds like thousands?? – Rick James Oct 26 '18 at 19:07
  • After evaluating the where condition in update.It should be around 10-15. P.S.: My current isolation level is REPEATABLE READ. – Nilesh Oct 26 '18 at 19:11
0

Something to try:

begin
    START TRANSACTION;
        SELECT *
            FROM roomlogs
            WHERE  netId = pnetid
              AND  `status` = 0
              AND  enterTime >= DATE(ptime)
              AND  enterTime  < DATE(ptime) + interval 1 day;
            FOR UPDATE;    -- This might cause different locking action
            -- WHERE clause is equivalent to UPDATE's
        -- The following are as before (or as further optimized):
        UPDATE ...
        INSERT ...
        SELECT ...
    COMMIT;
end;

A possible reason: In older versions of MySQL, a different, less sophisticated, Optimizer was used in UPDATE and DELETE. Hence, upgrading might be a solution.

Check for errors. You could get a timeout or deadlock. Either need to be handled.

Rick James
  • 135,179
  • 13
  • 127
  • 222
  • Here, in the stored procedure, I did not use the transaction. then should I include the transaction now? you can see my stored procedure in the question. from begin to end block! – Nilesh Oct 26 '18 at 20:05
  • @Nilesh - I was hoping you would answer my question about `autocommit`. If it is `ON` and you don't have `START TRANSACTION`, then each statement is a transaction unto itself. Some programs happily work in that mode. However, I _think_ your app needs some explicit, multi-statemet, transactions. Yes, that is what I am suggesting in this Answer (along with some other differences). In particular, `FOR UPDATE` has no impact unless it is inside a transaction. – Rick James Oct 26 '18 at 22:40
  • Currently, my auto-commit is OFF. – Nilesh Oct 26 '18 at 23:55
  • @Nilesh - Oops. That means you need to do a `COMMIT` sooner or later. I prefer never to use OFF -- for fear that I will forget to `COMMIT`. Instead, I use `BEGIN` (`START`) as a reminder that I need to do `COMMIT`. – Rick James Oct 27 '18 at 00:34
0

(Yeah, I know this is my 3rd answer. But it is in a different direction.)

Consider moving status out of the table. This is especially since multiple rows need to be changed. Also since you have a datetime, but the status is associated with a date.

The new table would have

roomid ...
status TINYINT UNSIGNED NOT NULL (default 0?)
date  DATE NOT NULL   -- comes from  DATE(enterTime)
PRIMARY KEY(roomid)

You would JOIN to the table when you need to see the status.

You would update the one row when you need to change the status. And you would not necessarily touch the other table.

This idea will probably fail if you need some rows to be status=0 and some status=1 simultaneously. However, if only 'older' rows have =0, then adding a time to the table would say "status is 0 before the time". This would make the JOIN a bit more complex, but still doable.

Please tell us what status "means". And consider changing the column name to reflect the semantics.

Rick James
  • 135,179
  • 13
  • 127
  • 222
  • (1) The default value of status is 0 and any query will update it from 0 to 1. No query will update it from 1 to 0. (2) Status will depend upon netId, roomId and entertime. – Nilesh Oct 26 '18 at 19:22
  • Also, does the isolation level REPEATABLE READ affect the locking system? Should I change that to READ COMMITED? – Nilesh Oct 26 '18 at 19:23
  • @Nilesh - Maybe. It _may_ depend on whether you keep the 'transaction' like you had it or like I suggested in another answer of mine. – Rick James Oct 26 '18 at 19:35
  • Perhaps https://stackoverflow.com/questions/52923678/lock-and-isolation-for-resource-reservation-pattern the question showed clearly the effects of read_committed against REPEATABLE_READ – aschoerk Oct 26 '18 at 21:22
  • Does changing the isolation level helps to prevent the locks by update queries? As per my study, due to the update statement, It can be a Next-Key Locks. https://dev.mysql.com/doc/refman/8.0/en/innodb-locking.html#innodb-next-key-locks and https://dev.mysql.com/doc/refman/8.0/en/innodb-locks-set.html – Nilesh Oct 26 '18 at 21:34
  • @aschoerk - I especially like that Question. However, it is unclear whether it is relevant to _this_ question. – Rick James Oct 26 '18 at 22:47