3

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
  • 1
    Hello guys, thanks for your replies. I've edited the question to include the requested details. Thanks in advance! – TJ is too short Nov 20 '18 at 16:33
  • 1
    Hello @eckes, thanks for your reply. I didn't try to remove it yet. Is it ok to remove the constraint? I just wanted to be sure that the user_id actually exists when adding a record to this table. – TJ is too short Nov 22 '18 at 17:06
  • 1
    I would at least try to see how much slower it is with the FK in place. For extreme TP you often trust the apps to do the right thing in these matters. – eckes Nov 22 '18 at 20:38
  • 1
    Hi @eckes! Thanks for your reply. Is that the only option? I see foreign keys as a tool for data integrity protection (like storing things for customers that actually exist). I understand that it takes an extra step checking if the provided id actually exists in the referenced table, but does it take that long? – TJ is too short Nov 23 '18 at 17:11
  • 2
    @TJistooshort Please post your COMPLETE - INSERT statement so we can see all the things the optimizer has to deal with. And it looks like you may run EXPLAIN INSERT ...... in your 5.7 version of MySQL. Post complete text of EXPLAIN INSERT results and SHOW WARNINGS; will have the content of HOW the optimizer rearranged your query for processing. Thanks – Wilson Hauck Nov 29 '18 at 12:23
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
  • 1
    Thanks very much for your reply @RickJames. The current setting is autocommit = 1. I used a client called Sequel Pro in order to see how long it took to run that query. – TJ is too short Nov 26 '18 at 11:45
  • There's gotta be something else that we are not seeing. 2 seconds for a simple INSERT is "impossible". – Rick James Nov 26 '18 at 20:08
  • 1
    I agree. I will inspect the code to see if I can find other issues (that could eventually lead to this situation) – TJ is too short Nov 28 '18 at 10:14
  • @TJistooshort Please post to pastebin.com TEXT results of A) SHOW GLOBAL STATUS: B) SHOW GLOBAL VARIABLES; C) from your Linux Command prompt results of ulimit -a please for discovery of how your instance is really configured and running. – Wilson Hauck Nov 30 '18 at 17:21
  • 1
    @TJistooshort - The hits/misses say "nothing needs changing". The ulimit and table_open_cache are inconsistent, so I don't what the issue is. Normally, the OS's ulimit (1024) is noticed (by mysqld), and table_open_cache is set to about 1/3 of that. Other than that, the 2000` is a reasonable setting. – Rick James Dec 4 '18 at 17:36
0

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.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

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