Insert sometimes takes more than 2 seconds in table with +6 million records

Question

I have a table in my database that acts like a log to record accesses to some selected endpoints of my application.

That table contains:

• id (primary key)
• The http method (GET, POST, PUT, etc)
• The endpoint, some useful data that might be passed
• If the request was made by a logged in user, the user_id. Otherwise user_id is NULL (meaning that the request was made by a guest).

This table is starting to get big (already more than 6 million records) and sometimes the insert statements take more than 2 seconds. We don't perform "intensive" operations in this table: just INSERT and SELECT * FROM table WHERE user_id = xxxx.

Is it normal that sometimes this insert is done quickly and sometimes it takes more than 2 seconds? What can be done to reduce this time?

Thanks in advance!

EDIT

Table definition:

CREATE TABLE `user_actions` (
      `id` int(10) unsigned NOT NULL AUTO_INCREMENT,
      `http_method` varchar(10) COLLATE utf8mb4_unicode_ci NOT NULL,
      `endpoint` varchar(255) COLLATE utf8mb4_unicode_ci DEFAULT NULL,
      `request_data` text COLLATE utf8mb4_unicode_ci NOT NULL,
      `user_id` int(10) unsigned DEFAULT NULL,
      `user_agent` varchar(255) COLLATE utf8mb4_unicode_ci NOT NULL,
      `created_at` timestamp NULL DEFAULT NULL,
      `updated_at` timestamp NULL DEFAULT NULL,
      PRIMARY KEY (`id`),
      KEY `user_actions_user_id_foreign` (`user_id`),
      CONSTRAINT `user_actions_user_id_foreign`
      FOREIGN KEY (`user_id`) REFERENCES `users` (`id`) 
      ON DELETE NO ACTION 
      ON UPDATE NO ACTION) ENGINE=InnoDB AUTO_INCREMENT=6312242 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci; 

This is an example of one INSERT statement that took 5.3 seconds:

insert into `user_actions` 
   (`http_method`, `route_name`, `query_string`, `ip_address`, `user_agent`, `request_data`, `user_id`, `updated_at`, `created_at`) 
values 
   ('GET', '19-chars-string', '64-chars-string', '123.123.123.123', '139-chars-string', '[]', 96411, '2018-11-29 18:49:08', '2018-11-29 18:49:08');

Server RAM = 16GB
innodb_buffer_pool_size = 12G
innodb_buffer_pool_instances = 12
innodb_page_cleaners = 12

Answer 1

Well, it takes time (possibly more than 2 seconds) to shovel tens of thousands of rows. Disks, networks, etc, are not fast enough to go faster.

Meanwhile, such a SELECT is interfering, at some level, with anything else that is going on -- such as an INSERT that might be hitting the same user_id.

Also, are you using autocommit = 1, which commits each statement as you go. Or are you using =0 or BEGIN, in which case groups of statements are bunched together into a "transaction"? This can impact on how one connection is interfering with another.

When you say that a 1-row INSERT is taking 2 seconds, what tool are you using for the timing? To an end-user something can 'feel' like 2 seconds, but the real cause may be something else.

(Analysis of VARIABLES and STATUS:)

Observations:

• Version: 5.7.24-0ubuntu0.18.04.1-log
• 16 GB of RAM
• Uptime = 4d 00:07:33
• You are not running on Windows.
• Running 64-bit version
• You appear to be running entirely (or mostly) InnoDB.

The More Important Issues:

Wow! This is the first VARIABLES+STATUS I have review for which I saw nothing 'important' to fix.

Details and other observations:

( Innodb_buffer_pool_pages_free / Innodb_buffer_pool_pages_total ) = 451,008 / 786432 = 57.3% -- Pct of buffer_pool currently not in use -- innodb_buffer_pool_size is bigger than necessary?

( innodb_print_all_deadlocks ) = innodb_print_all_deadlocks = OFF -- Whether to log all Deadlocks. -- If you are plagued with Deadlocks, turn this on. Caution: If you have lots of deadlocks, this may write a lot to disk.

( net_buffer_length / max_allowed_packet ) = 16,384 / 16M = 0.10%

( local_infile ) = local_infile = ON -- local_infile = ON is a potential security issue

( Select_scan / Com_select ) = 226,117 / 2089280 = 10.8% -- % of selects doing full table scan. (May be fooled by Stored Routines.) -- Add indexes / optimize queries

( back_log / max_connections ) = 80 / 151 = 53.0%

Abnormally large:

innodb_page_cleaners = 12
performance_schema_max_file_classes = 80
performance_schema_max_mutex_classes = 210

Answer 2

Rate Per Second=RPS Suggestions to consider for your my.cnf [mysqld] section

read_rnd_buffer_size=192K  # from 256K to reduce handler_read_rnd_next RPS
innodb_io_capacity=1900  # from 200 to use more of your IOPS capacity
thread_cache_size=32  # from 8 to accomodate more connections when you grow
innodb_lru_scan_depth=100  # from 256 to reduce 60% of CPU cycles used every SECOND for this function.

Possible areas to research. Deletes, Inserts, Updates of 91 Million actions in 4 days?

Not one ALTER, ANALYZE or OPTIMIZE table in 4 days?

42 deadlocks in 4 days. If they could be eliminated, you should.

For additional suggestions, please view my profile, Network profile for contact info and get in touch via Skype, please. We do have a findfragtables.sql utility that will identify tables that are fragmented. A free utility.