title: Very slow writes on MySQL 8 - waiting for handler commit
body: <p>I have MySQL 8 docker installation installed on an edge device which has the following two tables to write to</p>
  <pre><code>video_paths | CREATE TABLE `video_paths` (
    `entry` int(11) NOT NULL AUTO_INCREMENT,
    `timestamp` bigint(20) NOT NULL,
    `duration` int(11) NOT NULL,
    `path` varchar(255) NOT NULL,
    `motion` int(11) NOT NULL DEFAULT '0',
    `cam_id` varchar(255) NOT NULL DEFAULT '',
    `hd` tinyint(1) NOT NULL DEFAULT '0',
    PRIMARY KEY (`entry`),
    KEY `cam_id` (`cam_id`),
    KEY `timestamp` (`timestamp`)
  ) ENGINE=InnoDB AUTO_INCREMENT=7342309 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci
  </code></pre>
  <p>AND</p>
  <pre><code>CREATE TABLE `tracker` (
    `id` int(11) NOT NULL AUTO_INCREMENT,
    `table_name` varchar(255) NOT NULL,
    `primary_key_name` varchar(255) NOT NULL,
    `pointer` int(11) NOT NULL DEFAULT '0',
    PRIMARY KEY (`id`),
    UNIQUE KEY `table_name` (`table_name`)
  ) ENGINE=InnoDB AUTO_INCREMENT=4 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci
  </code></pre>
  <p>The following queries are run every few secs for up to 32 cameras and are taking a lot of time as indicated by the slow query log.</p>
  <pre><code>UPDATE tracker SET pointer = 7342046 WHERE table_name = 'video_paths'
  
  INSERT INTO video_paths (timestamp,duration,path,cam_id,hd) VALUES (1597548365000,5000,'/s/ss/x-0/v/2020-08-16/3/1.ts','x-1',1)
  
  </code></pre>
  <p>Most of the time is spent in the <code>waiting for handler commit</code> state</p>
  <p>The total size of my data (tables + index) is ~1GB and I have the following settings enabled to optimise for write</p>
  <p><code>skip-log-bin</code> - Disabled the bin log because I don't have a replica and therefore no use for it
  <code>innodb_flush_log_at_trx_commit =2</code> - I am Optimising for performance rather than consistency here.
  <code>range_optimizer_max_mem_size =0</code> As mention in this <a href="https://dba.stackexchange.com/questions/232365/mysql-8-0-updates-are-sometimes-stalling">question</a>, I have allowed max memory to range optimiser.
  <code>inndo_buffer_pool_size= 512Mb</code> - This should be enough for my data?.<br />
  <code>innodb_log_file_size= 96Mb</code> *2 files</p>
  <p>I am seeing queries that are taking up to 90-100 secs sometimes.</p>
  <pre><code>SET timestamp=1597549337;
  INSERT INTO video_paths (timestamp,duration,path,cam_id,hd) VALUES (1597548365000,5000,'/s/ss/x-0/v/2020-08-16/3/1.ts','x-1',1);
  # Time: 2020-08-16T03:42:24.533408Z
  # Query_time: 96.712976  Lock_time: 0.000033 Rows_sent: 0  Rows_examined: 0
  </code></pre>
  <p><strong>---UPDATE---</strong>
  Here's the complete my.cnf file</p>
  <pre><code>my.cnf
  
  [mysqld]
  pid-file        = /var/run/mysqld/mysqld.pid
  socket          = /var/run/mysqld/mysqld.sock
  datadir         = /var/lib/mysql
  secure-file-priv= NULL
  # Disabling symbolic-links is recommended to prevent assorted security risks
  symbolic-links=0
  
  skip-log-bin
  innodb_buffer_pool_size=536870912
  innodb_log_file_size=100663296
  
  # Custom config should go here
  !includedir /etc/mysql/conf.d/
  
  conf.d/docker.cnf 
  [mysqld]
  skip-host-cache
  skip-name-resolve 
  </code></pre>
  <p>The docker container is using the host mode so complete 15GB memory is available to the container.</p>
  <p><strong>--- UPDATE 2 ---</strong>
  After increasing the <code>innodb_buffer_poo_size</code> to 2GB as suggested by @fyrye, the statements have now started getting stuck on <code>STATE = UPDATE</code>  instead of <code>waiting for handler commit</code>.</p>
  <p><strong>---- UPDATE 3 ---</strong>
  Looks like the CPU is causing the bottleneck
  <a href="https://i.stack.imgur.com/4EI6M.png" rel="nofollow noreferrer"><img src="https://i.stack.imgur.com/4EI6M.png" alt="enter image description here" /></a></p>
  <p>** ---- UPDATE 4 ---- **
  Additional info</p>
  <ol>
  <li>Ram Size</li>
  </ol>
  <pre><code>              total        used        free      shared  buff/cache   available
  Mem:          15909        1711        9385        2491        4813       11600
  Swap:             0           0           0
  </code></pre>
  <ol start="2">
  <li>No SSD/NVMe devices attached</li>
  <li><code>SHOW GLOBAL STATUS</code> - <a href="https://pastebin.com/vtWi0PUq" rel="nofollow noreferrer">https://pastebin.com/vtWi0PUq</a></li>
  <li><code>SHOW GLOBAL VARIABLES</code> - <a href="https://pastebin.com/MUZeG959" rel="nofollow noreferrer">https://pastebin.com/MUZeG959</a></li>
  <li><code>SHOW FULL PROCESSLIST</code> - <a href="https://pastebin.com/eebEcYk7" rel="nofollow noreferrer">https://pastebin.com/eebEcYk7</a></li>
  <li>htop - <code>htop</code> here is for the edge system which has 4 other containers running which include the main app, ffmpeg, mqtt, etc.
  <a href="https://i.stack.imgur.com/wPFsx.png" rel="nofollow noreferrer"><img src="https://i.stack.imgur.com/wPFsx.png" alt="enter image description here" /></a></li>
  <li><code>ulimit -a</code>:</li>
  </ol>
  <pre><code>core file size          (blocks, -c) 0
  data seg size           (kbytes, -d) unlimited
  scheduling priority             (-e) 0
  file size               (blocks, -f) unlimited
  pending signals                 (-i) 62576
  max locked memory       (kbytes, -l) 64
  max memory size         (kbytes, -m) unlimited
  open files                      (-n) 1024
  pipe size            (512 bytes, -p) 8
  POSIX message queues     (bytes, -q) 819200
  real-time priority              (-r) 0
  stack size              (kbytes, -s) 8192
  cpu time               (seconds, -t) unlimited
  max user processes              (-u) 62576
  virtual memory          (kbytes, -v) unlimited
  file locks                      (-x) unlimited
  </code></pre>
  <ol start="8">
  <li><code>opstat -xm 5 4</code></li>
  </ol>
  <pre><code>Linux 4.15.0-106-generic (xxxx)    08/18/2020  _x86_64_    (4 CPU)
  
  avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           26.97    0.00   22.36   22.53    0.00   28.14
  
  Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
  loop0             0.00     0.00    0.00    0.00     0.00     0.00     3.20     0.00    2.40    2.40    0.00   0.00   0.00
  sda              13.78     9.89   32.24   11.44     0.37     4.10   209.51    47.52 1079.07   44.07 3994.87  22.39  97.81
  
  avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           19.71    0.00   27.85   40.87    0.00   11.57
  
  Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
  loop0             0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
  sda               0.00     0.00    1.40    4.60     0.03     2.71   934.93   142.66 24221.33  666.29 31390.26 166.67 100.00
  
  avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           20.16    0.00   26.77   28.30    0.00   24.77
  
  Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
  loop0             0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
  sda               0.00     0.00    8.80    5.60     0.03     3.45   496.11   141.28 12507.78  194.00 31858.00  69.44 100.00
  </code></pre>
  <ol start="9">
  <li><code>mpstat -P ALL 5 3</code></li>
  </ol>
  <pre><code>Linux 4.15.0-106-generic (sn-1f0ce8)    08/18/2020  _x86_64_    (4 CPU)
  
  02:15:47 PM  CPU    %usr   %nice    %sys %iowait    %irq   %soft  %steal  %guest  %gnice   %idle
  02:15:52 PM  all   21.48    0.00   20.40   29.01    0.00    7.94    0.00    0.00    0.00   21.17
  02:15:52 PM    0   24.95    0.00   20.86    5.32    0.00    0.61    0.00    0.00    0.00   48.26
  02:15:52 PM    1   17.59    0.00   18.81   57.67    0.00    5.93    0.00    0.00    0.00    0.00
  02:15:52 PM    2   21.28    0.00   17.36    0.21    0.00   24.79    0.00    0.00    0.00   36.36
  02:15:52 PM    3   22.34    0.00   24.59   52.46    0.00    0.61    0.00    0.00    0.00    0.00
  
  02:15:52 PM  CPU    %usr   %nice    %sys %iowait    %irq   %soft  %steal  %guest  %gnice   %idle
  02:15:57 PM  all   20.56    0.00   20.00   28.26    0.00    7.08    0.00    0.00    0.00   24.10
  02:15:57 PM    0   24.44    0.00   18.89   12.32    0.00    0.21    0.00    0.00    0.00   44.15
  02:15:57 PM    1   17.73    0.00   15.46   33.20    0.00    4.95    0.00    0.00    0.00   28.66
  02:15:57 PM    2   18.93    0.00   22.22   12.35    0.00   22.84    0.00    0.00    0.00   23.66
  02:15:57 PM    3   21.06    0.00   23.31   55.21    0.00    0.41    0.00    0.00    0.00    0.00
  
  02:15:57 PM  CPU    %usr   %nice    %sys %iowait    %irq   %soft  %steal  %guest  %gnice   %idle
  02:16:02 PM  all   21.81    0.00   18.32   26.42    0.00    7.03    0.00    0.00    0.00   26.42
  02:16:02 PM    0   26.43    0.00   19.67    0.20    0.00    0.41    0.00    0.00    0.00   53.28
  02:16:02 PM    1   20.57    0.00   17.11   45.21    0.00    5.30    0.00    0.00    0.00   11.81
  02:16:02 PM    2   19.67    0.00   16.74    0.21    0.00   21.97    0.00    0.00    0.00   41.42
  02:16:02 PM    3   20.45    0.00   19.84   58.91    0.00    0.81    0.00    0.00    0.00    0.00
  
  Average:     CPU    %usr   %nice    %sys %iowait    %irq   %soft  %steal  %guest  %gnice   %idle
  Average:     all   21.28    0.00   19.57   27.90    0.00    7.35    0.00    0.00    0.00   23.90
  Average:       0   25.27    0.00   19.81    5.94    0.00    0.41    0.00    0.00    0.00   48.57
  Average:       1   18.63    0.00   17.13   45.39    0.00    5.39    0.00    0.00    0.00   13.45
  Average:       2   19.96    0.00   18.78    4.28    0.00   23.20    0.00    0.00    0.00   33.77
  Average:       3   21.28    0.00   22.57   55.54    0.00    0.61    0.00    0.00    0.00    0.00
  </code></pre>