Performance issues with many inserts

Recently, we decided to evaluate CockroachDB by swapping a single MySQL instance for a CockroachDB cluster with 4 nodes and testing it under production load.

Our service receives approximately 300 requests/second. Each request results in an INSERT ON CONFLICT.

Under these conditions, the performance was extremely poor. With MySQL, each insert took approximately 30ms. With CockroachDB, each insert took approximately 300ms, and then quickly degraded, eventually taking several seconds per insert.

The target table has 4 separate indexes.

Our “P99 latency” was quite poor while our “P50 latency” was actually quite good.

What would be the expected performance of CockroachDB in this scenario? If our experience is typical, how can we increase performance with minimal code changes? If our experience is atypical, how can we debug this issue?

2 Likes

@Squirrel Hard to say what the expected performance of this scenario would be without a few more details. In general, there is a different performance envelope for a distributed database than a single-node database like MySQL. But the performance you’re experience is outside my expectations. Can you share the schema you’re using and the queries you’re performing? It is possible there is a bug that needs fixing or a feature of CockroachDB that would improve performance.

Debugging the problem by yourself is currently difficult. CockroachDB contains a variety of tools for debugging performance problems, but they are currently poorly (or not) documented. For example, SHOW TRACE FOR ... (called EXPLAIN(TRACE) in v1.0) can provide detail tracing of an individual query (this has improved a lot in the 1.1-alpha releases). There are also builtin profiling tools. But let’s start with the schema and queries.

1 Like

We have the simliar use case and the INSERT ON CONFLICT performance is not what we expect. We also have a 4 nodes local cluster setup and testing.

The table is very simple with only primary key.

CREATE TABLE t_phone (
phone INT NOT NULL,
firstseen TIMESTAMP WITH TIME ZONE NOT NULL,
lastmodified TIMESTAMP WITH TIME ZONE NOT NULL,
CONSTRAINT “primary” PRIMARY KEY (phone ASC),
FAMILY “primary” (phone, firstseen, lastmodified)
)

and for each insert statment like

Insert into t_phone (Phone,FirstSeen,LastModified) values (1111111111, ‘2017-07-26 00:07:24’, ‘2017-07-26 00:07:24’) ON CONFLICT(Phone) do update set LastModified = if(t_phone.LastModified>‘2017-07-26 00:07:24’, t_phone.LastModified, ‘2017-07-26 00:07:24’);

Our test show it took 15 seconds to insert 144 row, in average 100ms to insert one row, and there is only one connection to the db, and the table is new with only a few thousand rows.

We are testing on v1.1-alpha.20170720.

Thanks for looking into this.

Table Schema:

CREATE TABLE crashes (
id INT NOT NULL DEFAULT unique_rowid(),
project_id STRING(255) NULL DEFAULT NULL,
message STRING(255) NULL DEFAULT NULL,
stack_trace STRING NULL,
stack_hash STRING(255) NULL DEFAULT NULL,
created_at TIMESTAMP NULL DEFAULT NULL,
updated_at TIMESTAMP NULL DEFAULT NULL,
version INT NULL DEFAULT 0:::INT,
counter INT NULL DEFAULT 0:::INT,
ignored INT NULL DEFAULT 0:::INT,
CONSTRAINT “primary” PRIMARY KEY (id ASC),
UNIQUE INDEX index_crashes_on_project_id_and_stack_hash_and_version (project_id ASC, stack_hash ASC, version ASC),
INDEX index_crashes_on_project_id (project_id ASC),
INDEX index_crashes_on_project_id_and_version (project_id ASC, version ASC),
FAMILY “primary” (id, project_id, message, stack_trace, stack_hash, created_at, updated_at, version, counter, ignored)
);

Query:

INSERT INTO crashes (project_id, message, stack_trace, stack_hash, version, counter, updated_at, created_at) VALUES (?,?,?,?,?,?,NOW(),NOW()) ON CONFLICT (project_id, stack_hash, version) DO UPDATE SET counter = crashes.counter + ?, updated_at = NOW()::TIMESTAMP

The table started with no data.

@leokwan, @squirrel I don’t see anything in either of your schemas that would explain the bad performance. Can either of you provide a reproducible tests in the form of source code I can run? I can try reproducing myself from the info you’ve provided, but it will necessarily take longer.

@leokwan Are you running all 4 nodes on the same machine? Those nodes might be interfering with each other. Such a setup is really only useful for basic testing. Any performance numbers you see should be eyed very suspiciously.

@peter I am running all my nodes on dedicated hardware.
Insert performance is really a major requirement for my use case. I cannot make all insert into one statement as “on conflict” is not supported for multiple insert statement.

Thank you for looking in to this.

@leokwan Given the schema you provided and the query you are running, I’d expect your inserts to take ~2x your network latency. Updates will be a little bit slower than that since the insert needs to fail first before the update is performed. Assuming your network latencies are reasonable in the low single digit milliseconds, then the perf numbers you’ve provided are very surprising.

I’ll take a crack at reproducing this. Do you know how often you’re inserting new rows vs updating an existing row?

I’ve did a ping test in my environment, the average rtt is around 0.2 ms.

The ratio of inserting or updateing is around 50/50, but my test is starting with a new table so that’s 100% insert.

Thanks. One last question: how many threads do you have concurrently inserting/updating?

Only one thread.

A test below took 1.2 second to do 10 insert, at around 120ms per insert. If the expect insert time is 2x network latency, my insert should be less than 10ms each.


CREATE TABLE if not exists FILU.T_Test_Phone (
phone INT NOT NULL,
carrierid int not null,
firstseen TIMESTAMP WITH TIME ZONE NOT NULL,
lastmodified TIMESTAMP WITH TIME ZONE NOT NULL,
CONSTRAINT “primary” PRIMARY KEY (phone ASC),
FAMILY “primary” (phone, carrierid, firstseen, lastmodified)
);

SET TIME ZONE ‘America/New_York’;
Insert into FILU.T_Test_Phone (Phone,CarrierID, FirstSeen, LastModified) values (1111151111, 6, ‘2017-07-26 00:07:25’, ‘2017-07-26 00:07:25’) ON CONFLICT(Phone) do update set CarrierID = if(T_Test_Phone.LastModified > ‘2017-07-26 00:07:25’,T_Test_Phone.CarrierID,6), LastModified = if(T_Test_Phone.LastModified>‘2017-07-26 00:07:25’, T_Test_Phone.LastModified, ‘2017-07-26 00:07:25’);
Insert into FILU.T_Test_Phone (Phone,CarrierID, FirstSeen, LastModified) values (1111161111, 56, ‘2017-07-26 00:07:25’, ‘2017-07-26 00:07:25’) ON CONFLICT(Phone) do update set CarrierID = if(T_Test_Phone.LastModified > ‘2017-07-26 00:07:25’,T_Test_Phone.CarrierID,56), LastModified = if(T_Test_Phone.LastModified>‘2017-07-26 00:07:25’, T_Test_Phone.LastModified, ‘2017-07-26 00:07:25’);
Insert into FILU.T_Test_Phone (Phone,CarrierID, FirstSeen, LastModified) values (1111171111, 56, ‘2017-07-26 00:07:25’, ‘2017-07-26 00:07:25’) ON CONFLICT(Phone) do update set CarrierID = if(T_Test_Phone.LastModified > ‘2017-07-26 00:07:25’,T_Test_Phone.CarrierID,56), LastModified = if(T_Test_Phone.LastModified>‘2017-07-26 00:07:25’, T_Test_Phone.LastModified, ‘2017-07-26 00:07:25’);
Insert into FILU.T_Test_Phone (Phone,CarrierID, FirstSeen, LastModified) values (1111181111, 26, ‘2017-07-26 00:07:25’, ‘2017-07-26 00:07:25’) ON CONFLICT(Phone) do update set CarrierID = if(T_Test_Phone.LastModified > ‘2017-07-26 00:07:25’,T_Test_Phone.CarrierID,26), LastModified = if(T_Test_Phone.LastModified>‘2017-07-26 00:07:25’, T_Test_Phone.LastModified, ‘2017-07-26 00:07:25’);
Insert into FILU.T_Test_Phone (Phone,CarrierID, FirstSeen, LastModified) values (1111191111, 66, ‘2017-07-26 00:07:25’, ‘2017-07-26 00:07:25’) ON CONFLICT(Phone) do update set CarrierID = if(T_Test_Phone.LastModified > ‘2017-07-26 00:07:25’,T_Test_Phone.CarrierID,66), LastModified = if(T_Test_Phone.LastModified>‘2017-07-26 00:07:25’, T_Test_Phone.LastModified, ‘2017-07-26 00:07:25’);
Insert into FILU.T_Test_Phone (Phone,CarrierID, FirstSeen, LastModified) values (1111112111, 66, ‘2017-07-26 00:07:25’, ‘2017-07-26 00:07:25’) ON CONFLICT(Phone) do update set CarrierID = if(T_Test_Phone.LastModified > ‘2017-07-26 00:07:25’,T_Test_Phone.CarrierID,66), LastModified = if(T_Test_Phone.LastModified>‘2017-07-26 00:07:25’, T_Test_Phone.LastModified, ‘2017-07-26 00:07:25’);
Insert into FILU.T_Test_Phone (Phone,CarrierID, FirstSeen, LastModified) values (1111113111, 26, ‘2017-07-26 00:07:25’, ‘2017-07-26 00:07:25’) ON CONFLICT(Phone) do update set CarrierID = if(T_Test_Phone.LastModified > ‘2017-07-26 00:07:25’,T_Test_Phone.CarrierID,26), LastModified = if(T_Test_Phone.LastModified>‘2017-07-26 00:07:25’, T_Test_Phone.LastModified, ‘2017-07-26 00:07:25’);
Insert into FILU.T_Test_Phone (Phone,CarrierID, FirstSeen, LastModified) values (1111114111, 66, ‘2017-07-26 00:07:25’, ‘2017-07-26 00:07:25’) ON CONFLICT(Phone) do update set CarrierID = if(T_Test_Phone.LastModified > ‘2017-07-26 00:07:25’,T_Test_Phone.CarrierID,66), LastModified = if(T_Test_Phone.LastModified>‘2017-07-26 00:07:25’, T_Test_Phone.LastModified, ‘2017-07-26 00:07:25’);
Insert into FILU.T_Test_Phone (Phone,CarrierID, FirstSeen, LastModified) values (1111115111, 6, ‘2017-07-26 00:07:25’, ‘2017-07-26 00:07:25’) ON CONFLICT(Phone) do update set CarrierID = if(T_Test_Phone.LastModified > ‘2017-07-26 00:07:25’,T_Test_Phone.CarrierID,6), LastModified = if(T_Test_Phone.LastModified>‘2017-07-26 00:07:25’, T_Test_Phone.LastModified, ‘2017-07-26 00:07:25’);
Insert into FILU.T_Test_Phone (Phone,CarrierID, FirstSeen, LastModified) values (1111116111, 24216, ‘2017-07-26 00:07:25’, ‘2017-07-26 00:07:25’) ON CONFLICT(Phone) do update set CarrierID = if(T_Test_Phone.LastModified > ‘2017-07-26 00:07:25’,T_Test_Phone.CarrierID,24216), LastModified = if(T_Test_Phone.LastModified>‘2017-07-26 00:07:25’, T_Test_Phone.LastModified, ‘2017-07-26 00:07:25’);

@leokwan I whipped up a little simulation of your workload and the inserts are taking ~10ms for me. This is on a 6-node cluster that I had available, but given the data sizes that isn’t important.

Ok, just saw your last message. Let me test that out.

Hmm, I’m seeing about 5x better:

~ time cat phone.sql | ./cockroach sql --url "postgres://root@192.168.1.4:26257/test?sslmode=disable"
CREATE DATABASE
CREATE TABLE
SET
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1

real	0m0.187s
user	0m0.048s
sys	0m0.008s

For my simulation of your load, I’m seeing 99%-tile latencies that are ~7ms. Note that my comment about network latencies was in reference to cockroach network latencies, not ping times which are usually faster due to being entirely handled in the kernel. But your ping times are plenty fast (faster than on my cluster). The delta in performance here is quite odd. Note that I’ve been testing on 1.1-alpha. Let me try 1.0.4.

1.0.4 is showing the same performance as 1.1-alpha.

@leokwan The perf I’m seeing isn’t matching up with your numbers. So what is different between our setups? Are you running on SSD or spinning disk?

That’s great news! Good to know crdb is much faster than my test.

4 nodes,
i7-3770S CPU @ 3.10GHz
32G Ram
5 spinning JBOD for each node.

Therefore, there is 5 data store for each node.

My starting command for the first node would like this

ulimit -n 65536 && ./cockroach start --background --store=d1 --store=d2 --store=d3 --store=d4 --store=d5 --log-dir=d1 --certs-dir=certs

and the rest would like

ulimit -n 65536 && ./cockroach start --background --join=192.168.8.21 --store=d1 --store=d2 --store=d3 --store=d4 --store=d5 --log-dir=d1 --certs-dir=certs

Build Tag: v1.1-alpha.20170720
Build Time: 2017/07/20 15:23:28
Distribution: CCL
Platform: linux amd64
Go Version: go1.8.3
C Compiler: gcc 6.3.0
Build SHA-1: a1af558e5859b668ee9823267bb27bb5929481b4
Build Type: release-gnu

I will also spin up some cloud machine to test for this.

Thank you very much!!

The spinning disk is probably the difference. By default, Cockroach syncs each write to disk. This is much more expensive on spinning disk than SSD. You can disable this via set cluster setting kv.raft_log.synchronize = false. There is a risk in data loss in doing this (under power failure scenarios), but I think it would be worth an experiment.

You are the man!

My old setting

CREATE TABLE
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1

real 0m0.933s
user 0m0.032s
sys 0m0.014s

If I set kv.raft_log.synchronize = false

SET
CREATE TABLE
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1
INSERT 1

real 0m0.233s
user 0m0.035s
sys 0m0.015s

and for my original test, the query time drop from 11 seconds to 0.5s.

This could also fix @Squirrel question,

Once again. Thank you for all the time you spend on this issue.

Leo

With kv.raft_log.synchronize = false, how often are writes synced? Is this adjustable?

@leokwan Glad we could get to the bottom of this, though running with kv.raft_log.synchronize = false is dangerous. Fine for testing, though I wouldn’t recommend running with that setting in production. I imagine Cockroach is more sensitive to disk sync performance than other systems.

@davetait With kv.raft_log.synchronize = false your writes are synchronized every 256KB of data that is written to a node. This isn’t currently adjustable, but adding more knobs wouldn’t be difficult. The big downside with kv.raft_log.synchronize = false is that it can cause Raft invariants to be violated which could cause more significant data loss than just the unsynchronized data. Again, I would (strongly) recommend against running with that setting in production (at this time).