2

I have a lightweight web-application with current load of about 500 reqests/sec. Almost each request generates an INSERT request to the database. Some time ago I found that my application has short periods (every 30-60 seconds) with slow response (2-3 seconds) during these periods. After some benchmarking and debugging I found that the delays came from Postgres on the INSERT queries.

I've added some debugging options to the Postgres config but nothing interesting was found in the logs. Postgres version:

PostgreSQL 9.4.5 on x86_64-unknown-linux-gnu, compiled by gcc (Ubuntu 4.8.2-19ubuntu1) 4.8.2, 64-bit

Postgres config

Hardware does not seem to be a bottleneck - all system metrics are OK.

All INSERT queries add data to one working table:

       Column      |            Type             |                            Modifiers
 ------------------+-----------------------------+-----------------------------------------------------------------
  id               | bigint                      | not null default nextval('hits_new_id_seq'::regclass)
  creature_id      | integer                     |
  spot_id          | integer                     |
  country_id       | integer                     |
  device           | integer                     |
  ip               | character varying           |
  referer          | character varying           |
  host             | character varying           |
  uuid             | character varying           |
  clicked          | boolean                     | not null default false
  created_at       | timestamp without time zone | not null
  updated_at       | timestamp without time zone | not null
  creature_type    | character varying           |
  prices_by_id     | jsonb                       |
  prices_by_type   | jsonb                       |
  user_id          | integer                     |
  bounce_to        | bigint                      |
  original_spot_id | integer                     |
  original_user_id | integer                     |
  browser          | integer                     |
  browser_version  | character varying           |
  clicked_at       | timestamp without time zone |
  type_id          | integer                     |
 Indexes:
     "hits_new_pkey" PRIMARY KEY, btree (id)
     "index_hits_on_user_id" btree (user_id)

Currently inserting about 30M record per day. Every day I copy all yesterday records to an archive table and delete them from working table.

SELECT MAX(id) FROM working WHERE date = '%yesterday%';
INSERT INTO archive(...) SELECT ... FROM working WHERE id <= %max_id%;
DELETE FROM working WHERE id <= %max_id%;

Working table has only one simple index and primary key id column. VACUUM FULL ANALYZE does not help.

Today I've wrote a simple script to add records to this table in an endless loop and log requests longer than x. When I run this on the production database and compare web application log and this script output I see that lags occurred at the same time.

Please, give any advice about how to find the reason why Postgres has these lags on insert.

UPDATE:

My application consist of few workers on seaprate ports each and nginx is balancing load between two servers with 4 workers on each (ports 8001-8004). During my investigation I've added log output for requests where INSERT took more than a second. When I grep this log I have this result: https://gist.githubusercontent.com/zozo/797e47ab80a5b975c833/raw/53a69fd8e8784904c5db04adada37ae7be284f1e/gistfile1.txt

Example:

I, [2016-02-02T09:32:11.503192 #16260]  INFO -- : ms: 1915 [8003]

Here 1915ms - time to complete INSERT request, 8003 - port of current worker. As you can see, in most cases each worker has only one slow query during lag moment. Lags delay for each worker are almost the same.

And one more interesting observation: Time between lags almost always close to x*20 seconds. I've wrote simple script to analyze lags periodicity, that is part of result: https://gist.githubusercontent.com/zozo/594aeb88476254235bdf/raw/41001c6b305dbf0046fae781de09318848c5b50c/gistfile1.txt

I can't find anything with 20 seconds periodicity. And I already changed few timers in my system - seems like it didn't impact to lags problem.

  • What else touches this table? Do you have any transactions while you're inserting? Do you ever read from it, other than to archive the data? – Chris Harrington Feb 1 '16 at 17:30
  • There are few read queries on this table, I've added some debugging information to logs but can't see any correlation with this requests yet. – Zozo Feb 1 '16 at 17:49
  • Can you add the full definition of the table, with indexes et al? – Chris Harrington Feb 1 '16 at 18:01
  • 1
    Please show the non-default contents of your postgresql.conf. It can be related to the checkpoint settings, among others. – dezso Feb 1 '16 at 19:45
  • 2
    If your UPDATE hits SET clicked = true WHERE id = xx; might happen repeatedly on the same row, it would be wise to make that: UPDATE hits SET clicked = true WHERE id = xx AND NOT clicked; to avoid expensive empty updates - which may even be the cause of your performance problem, because unlike INSERT statements, those could lead to lock contention. – Erwin Brandstetter Feb 2 '16 at 0:51

Your Answer

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

Browse other questions tagged or ask your own question.