COPY speedup

Replying to myself...

I've been examining the code path for COPY FROM too, and I think it is
possible to get the same kind of speedups on COPY FROM that the patch in
the previous message did for COPY TO, that is to say perhaps 2-3x faster
in BINARY mode and 10-20% faster in TEXT mode (these figures are
ballparks, only based on very quick checks however).

The idea is to avoid most (actually, all) palloc()'ing and memcpy()'ing
for types that are pass-by-value like INT.

Is there interest in such a patch (for 8.6) ?

=?utf-8?Q?Pierre_Fr=C3=A9d=C3=A9ric_Caillau?= =?utf-8?Q?d?= <lists@peufeu.com> writes:

I've been examining the code path for COPY FROM too, and I think it is
possible to get the same kind of speedups on COPY FROM that the patch in
the previous message did for COPY TO, that is to say perhaps 2-3x faster
in BINARY mode and 10-20% faster in TEXT mode (these figures are
ballparks, only based on very quick checks however).

The idea is to avoid most (actually, all) palloc()'ing and memcpy()'ing
for types that are pass-by-value like INT.

Is there interest in such a patch (for 8.6) ?

If you do as much damage to the I/O function API as the other patch
did, it will probably be rejected. We don't touch datatype APIs
lightly, because it affects too much code.

regards, tom lane

If you do as much damage to the I/O function API as the other patch
did, it will probably be rejected.

You mean, as the COPY patch in my previous message, or as another patch ?
(I just search the archives and found one about CopyReadLine, but that's
probably not what you are talking about)

We don't touch datatype APIs
lightly, because it affects too much code.

regards, tom lane

I definitely agree with that.

2009/8/12 Pierre Frédéric Caillaud <lists@peufeu.com>:

If you do as much damage to the I/O function API as the other patch
did, it will probably be rejected.

       You mean, as the COPY patch in my previous message, or as another
patch ?
       (I just search the archives and found one about CopyReadLine, but
that's probably not what you are talking about)

We don't touch datatype APIs
lightly, because it affects too much code.

                       regards, tom lane

       I definitely agree with that.

Is there any way to do this that is not as invasive?

merlin

Merlin Moncure escribi�:

2009/8/12 Pierre Fr�d�ric Caillaud <lists@peufeu.com>:

If you do as much damage to the I/O function API as the other patch
did, it will probably be rejected.

� � � �You mean, as the COPY patch in my previous message, or as another
patch ?
� � � �(I just search the archives and found one about CopyReadLine, but
that's probably not what you are talking about)

We don't touch datatype APIs
lightly, because it affects too much code.

� � � � � � � � � � � �regards, tom lane

� � � �I definitely agree with that.

Is there any way to do this that is not as invasive?

Maybe add new methods, fastrecv/fastsend etc. Types that don't
implement them would simply use the slow methods, maintaining
backwards compatibility.

--
Alvaro Herrera http://www.CommandPrompt.com/
The PostgreSQL Company - Command Prompt, Inc.

We don't touch datatype APIs
lightly, because it affects too much code.

                       regards, tom lane

       I definitely agree with that.

Actually, let me clarify:

When I modified the datatype API, I was feeling uneasy, like "I shouldn't
really touch this".
But when I see a big red button, I just press it to see what happens.
Ugly hacks are useful to know how fast the thing can go ; then the
interesting part is to reimplement it cleanly, trying to reach the same
performance...

Is there any way to do this that is not as invasive?

Maybe add new methods, fastrecv/fastsend etc. Types that don't
implement them would simply use the slow methods, maintaining
backwards compatibility.

Well, this would certainly work, and it would be even faster.

I considered doing it like this, but it is a lot more work : adding
entries to the system catalogs, creating all the new functions, deciding
what to do with getTypeBinaryOutputInfo (since there would be 2 variants),
etc. Types that don't support the new functions would need some form of
indirection to call the old functions instead, etc. In a word, doable, but
kludgy, and I would need help from a system catalog expert. Also, on
upgrade, information about the new functions must be inserted in the
system catalogs ? (I don't know how this process works). If you want to
help...

The way I see COPY BINARY is that its speed should be really something
massive.
COPY foo FROM ... BINARY should be as fast as CREATE TABLE foo AS SELECT *
FROM bar (which is extremely fast).
COPY foo TO ... BINARY should be as fast as the disk allows.

Why else would anyone use a binary format if it's slower than portable
text ?

So, there are two other ways (besides fastsend/fastrecv) that I can see :

1- The way I implemented

I'm not saying it's the definitive solution : just a simple way to see how
much overhead is introduced by the current API, returning BYTEAs and
palloc()'ing every tuple of every row. I think this approach gave two
interesting answers :

- once COPY's output buffer has been made more efficient, with things like
removing fwrite() for every row etc (see patch), all that remains is the
API overhead, which is very significant for binary mode, since I could get
massive speedups (3-4x !) by bypassing it. The table scan itself is
super-fast.

- however, for text mode, it is not so significant, as the speedups
bypassing the API were roughly 0-20%, since most of the time is spent in
datum to text conversions.

Now, I don't think the hack is so ugly. It does make me feel a bit uneasy,
but :

- The context field in the fcinfo struct is there for a reason, so I used
it.
- I checked every place in the code where SendFunctionCall() appears
(which are quite few actually).
- The context field is never used for SendFuncs or ReceiveFuncs (it is
always set to NULL)

2- Another way

- palloc() could be made faster for short blocks
- a generous sprinkling of inline's
- a few modifications to pq_send*
- a few modifications to StringInfo
- bits of my previous patch in copy.c (like not fwriting every row)

This would be less fast, but you'd still get a substantial speedup.

As a conclusion, I think :

- Alvaro's fastsend/fastrecv provides the cleanest solutin
- Method 2 is the easiest, but slower
- Method 1 is an intermediate, but the use of the context field is a
touchy subject.

Also, I will work on COPY FROM ... BINARY. I should be able to make it
also much faster. This will be useful for big imports.

Regards,
Pierre

Pierre Fr�d�ric Caillaud escribi�:

But when I see a big red button, I just press it to see what happens.
Ugly hacks are useful to know how fast the thing can go ; then the
interesting part is to reimplement it cleanly, trying to reach the
same performance...

Right -- now that you've shown a 6x speedup increase, it is clear that
it makes sense to attempt a reimplementation. It also means it makes
sense to have an additional pair or two of input/output functions.

Maybe add new methods, fastrecv/fastsend etc. Types that don't
implement them would simply use the slow methods, maintaining
backwards compatibility.

I considered doing it like this, but it is a lot more work : adding
entries to the system catalogs, creating all the new functions,
deciding what to do with getTypeBinaryOutputInfo (since there would
be 2 variants), etc. Types that don't support the new functions
would need some form of indirection to call the old functions
instead, etc. In a word, doable, but kludgy, and I would need help
from a system catalog expert.

Right.

Also, on upgrade, information about the new functions must be inserted
in the system catalogs ? (I don't know how this process works).

No, that's not how pg_migrator works. Catalog upgrades are handled by
pg_dump/pg_restore, so you don't need to worry about it at all.

--
Alvaro Herrera http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

But when I see a big red button, I just press it to see what happens.
Ugly hacks are useful to know how fast the thing can go ; then the
interesting part is to reimplement it cleanly, trying to reach the
same performance...

Right -- now that you've shown a 6x speedup increase, it is clear that
it makes sense to attempt a reimplementation. It also means it makes
sense to have an additional pair or two of input/output functions.

Okay.

Here are some numbers. The tables are the same as in the previous email,
and it also contains the same results as "copy patch 4", aka "API hack"
for reference.

I benchmarked these :

* p5 = no api changes, COPY TO optimized :
- Optimizations in COPY (fast buffer, much less fwrite() calls, etc)
remain.
- SendFunction API reverted to original state (actually, the API changes
are still there, but deactivated, fcinfo->context = NULL).

=> small performance gain ; of course the lower per-row overhead is more
visible on "test_one_int", because that table has 1 column.
=> the (still huge) distance between p5 and "API hack" is split between
overhead in pq_send*+stringInfo (that we will tackle below) and palloc()
overhead (that was removed by the "API hack" by passing the destination
buffer directly).

* p6 = p5 + optimization of pq_send*
- inlining strategic functions
- probably benefits many other code paths

=> small incremental performance gain

* p7 = p6 + optimization of StringInfo
- inlining strategic functions
- probably benefits many other code paths

=> small incremental performance gain (they start to add up nicely)

* p8 = p7 + optimization of palloc()
- actually this is extremely dumb :
- int4send and int2send simply palloc() 16 bytes instead of 1024......
- the initial size of the allocset is 64K instead of 8K

=> still it has interesting results...

The three patches above are quite simple (especially the inlines) and yet,
speedup is already nice.

* p9 = p8 + monstrously ugly hack
copy looks at the sendfunc, notices it's int{2,4}send , and replaces it
with int{2,4}fastsend which is called directly from C, bypassing the fmgr
(urrrgghhhhhh)
of course it only works for ints.
This gives information about fmgr overhead : fmgr is pretty damn fast.

* p10 no copy
does everything except calling the SendFuncs, it writes dummy data instead.
This gives the time used in everything except the SendFuncs : table scan,
deform_tuple, file writes, etc, which is an interesting thing to know.

RESULTS :

COPY annonces TO '/dev/null' BINARY :
Time | Speedup | Table | KRows | MTuples | Name
(s) | | MB/s | /s | /s |
------|---------|--------|--------|---------|---------------------------------------------
2.149 | 2.60 x | 151.57 | 192.40 | 7.50 | copy to patch 4
3.055 | 1.83 x | 106.64 | 135.37 | 5.28 | p8 = p7 + optimization of
palloc()
3.202 | 1.74 x | 101.74 | 129.15 | 5.04 | p7 = p6 + optimization of
StringInfo
3.754 | 1.49 x | 86.78 | 110.15 | 4.30 | p6 = p5 + optimization of
pq_send*
4.434 | 1.26 x | 73.47 | 93.26 | 3.64 | p5 no api changes, COPY TO
optimized
5.579 | --- | 58.39 | 74.12 | 2.89 | compiled from source

COPY archive_data TO '/dev/null' BINARY :
Time | Speedup | Table | KRows | MTuples | Name
(s) | | MB/s | /s | /s |
-------|---------|-------|--------|---------|---------------------------------------------
5.372 | 3.75 x | 73.96 | 492.88 | 13.80 | copy to patch 4
8.545 | 2.36 x | 46.49 | 309.83 | 8.68 | p8 = p7 + optimization of
palloc()
10.229 | 1.97 x | 38.84 | 258.82 | 7.25 | p7 = p6 + optimization of
StringInfo
12.869 | 1.57 x | 30.87 | 205.73 | 5.76 | p6 = p5 + optimization of
pq_send*
15.559 | 1.30 x | 25.54 | 170.16 | 4.76 | p5 no api changes, COPY TO
optimized
20.165 | --- | 19.70 | 131.29 | 3.68 | 8.4.0 / compiled from source

COPY test_one_int TO '/dev/null' BINARY :
Time | Speedup | Table | KRows | MTuples | Name
(s) | | MB/s | /s | /s |
------|---------|--------|---------|---------|---------------------------------------------
1.493 | 4.23 x | 205.25 | 6699.22 | 6.70 | p10 no copy
1.660 | 3.80 x | 184.51 | 6022.33 | 6.02 | p9 monstrously ugly hack
2.003 | 3.15 x | 152.94 | 4991.87 | 4.99 | copy to patch 4
2.803 | 2.25 x | 109.32 | 3568.03 | 3.57 | p8 = p7 + optimization of
palloc()
2.976 | 2.12 x | 102.94 | 3360.05 | 3.36 | p7 = p6 + optimization of
StringInfo
3.165 | 2.00 x | 96.82 | 3160.05 | 3.16 | p6 = p5 + optimization of
pq_send*
3.698 | 1.71 x | 82.86 | 2704.43 | 2.70 | p5 no api changes, COPY TO
optimized
6.318 | --- | 48.49 | 1582.85 | 1.58 | 8.4.0 / compiled from source

COPY test_many_ints TO '/dev/null' BINARY :
Time | Speedup | Table | KRows | MTuples | Name
(s) | | MB/s | /s | /s |
------|---------|--------|--------|---------|---------------------------------------------
1.007 | 8.80 x | 127.23 | 993.34 | 25.83 | p10 no copy
1.114 | 7.95 x | 114.95 | 897.52 | 23.34 | p9 monstrously ugly hack
1.706 | 5.19 x | 75.08 | 586.23 | 15.24 | copy to patch 4
3.396 | 2.61 x | 37.72 | 294.49 | 7.66 | p8 = p7 + optimization of
palloc()
4.588 | 1.93 x | 27.92 | 217.98 | 5.67 | p7 = p6 + optimization of
StringInfo
5.821 | 1.52 x | 22.00 | 171.80 | 4.47 | p6 = p5 + optimization of
pq_send*
6.890 | 1.29 x | 18.59 | 145.14 | 3.77 | p5 no api changes, COPY TO
optimized
8.861 | --- | 14.45 | 112.85 | 2.93 | 8.4.0 / compiled from source

In the previous mails I made a mistake, writing "MTuples/s" instead of
"MDatums/s", sorry about that. It is the number of rows x columns. The
title was wrong, but the data was right.

I've been doing some tests on COPY FROM ... BINARY.

- inlines in various pg_get* etc
- a faster buffer handling for copy
- that's about it...

In the below tables, you have "p17" (ie test patch 17, the last one) and
straight postgres compared.

COPY annonces_2 FROM 'annonces.bin' BINARY :
Time | Speedup | Table | KRows | MDatums | Name
(s) | | MB/s | /s | /s |
-------|---------|--------|--------|---------|----------------------------------------------------
8.417 | 1.40 x | 38.70 | 49.13 | 1.92 | 8.4.0 / p17
11.821 | --- | 27.56 | 34.98 | 1.36 | 8.4.0 / compiled from source

COPY archive_data_2 FROM 'archive_data.bin' BINARY :
Time | Speedup | Table | KRows | MDatums | Name
(s) | | MB/s | /s | /s |
-------|---------|-------|--------|---------|----------------------------------------------------
15.314 | 1.93 x | 25.94 | 172.88 | 4.84 | 8.4.0 / p17 COPY FROM BINARY
all
29.520 | --- | 13.46 | 89.69 | 2.51 | 8.4.0 / compiled from source

COPY test_one_int_2 FROM 'test_one_int.bin' BINARY :
Time | Speedup | Table | KRows | MDatums | Name
(s) | | MB/s | /s | /s |
-------|---------|--------|---------|---------|----------------------------------------------------
10.003 | 1.39 x | 30.63 | 999.73 | 1.00 | 8.4.0 / p17 COPY FROM
BINARY all
13.879 | --- | 22.08 | 720.53 | 0.72 | 8.4.0 / compiled from
source

COPY test_many_ints_2 FROM 'test_many_ints.bin' BINARY :
Time | Speedup | Table | KRows | MDatums | Name
(s) | | MB/s | /s | /s |
-------|---------|-------|--------|---------|----------------------------------------------------
6.009 | 2.08 x | 21.31 | 166.42 | 4.33 | 8.4.0 / p17 COPY FROM BINARY
all
12.516 | --- | 10.23 | 79.90 | 2.08 | 8.4.0 / compiled from source

I thought it might be interesting to get split timings of the various
steps in COPY FROM, so I simply commented out bits of code and ran tests.

The "delta" columns are differences between two lines, that is the time
taken in the step mentioned on the right.

reading data only = reading all the data and parsing it into chunks, doing
everything until the RecvFunc is called.
RecvFuncs = same, + RecvFunc is called
heap_form_tuple = same + heap_form_tuple is called
triggers = same + triggers are applied
insert = actual tuple insertion
p17 = total time (post insert triggers, constraint check, etc)

Time | Delta | Row delta | Datum delta | Name
(s) | (s) | (us) | (us) |
-------|-------|-----------|-------------|----------------------
1.311 | --- | --- | --- | reading data only
4.516 | 3.205 | 7.750 | 0.199 | RecvFuncs
4.534 | 0.018 | 0.043 | 0.001 | heap_form_tuple
5.323 | 0.789 | 1.908 | 0.049 | triggers
8.182 | 2.858 | 6.912 | 0.177 | insert
8.417 | 0.236 | 0.570 | 0.015 | p17

COPY archive_data_2 FROM 'archive_data.bin' BINARY :
Time | Delta | Row delta | Datum delta | Name
(s) | (s) | (us) | (us) |
-------|--------|-----------|-------------|---------------------
4.729 | --- | --- | --- | reading data only
8.508 | 3.778 | 1.427 | 0.051 | RecvFuncs
8.567 | 0.059 | 0.022 | 0.001 | heap_form_tuple
10.804 | 2.237 | 0.845 | 0.030 | triggers
14.475 | 3.671 | 1.386 | 0.050 | insert
15.314 | 0.839 | 0.317 | 0.011 | p17

COPY test_one_int_2 FROM 'test_one_int.bin' BINARY :
Time | Delta | Row delta | Datum delta | Name
(s) | (s) | (us) | (us) |
-------|-------|-----------|-------------|----------------------
1.247 | --- | --- | --- | reading data only
1.745 | 0.498 | 0.050 | 0.050 | RecvFuncs
1.750 | 0.004 | 0.000 | 0.000 | heap_form_tuple
3.114 | 1.364 | 0.136 | 0.136 | triggers
9.984 | 6.870 | 0.687 | 0.687 | insert
10.003 | 0.019 | 0.002 | 0.002 | p17

COPY test_many_ints_2 FROM 'test_many_ints.bin' BINARY :
Time | Delta | Row delta | Datum delta | Name
(s) | (s) | (us) | (us) |
-------|-------|-----------|-------------|----------------------
1.701 | --- | --- | --- | reading data only
3.122 | 1.421 | 1.421 | 0.055 | RecvFuncs
3.129 | 0.008 | 0.008 | 0.000 | heap_form_tuple
3.754 | 0.624 | 0.624 | 0.024 | triggers
5.639 | 1.885 | 1.885 | 0.073 | insert
6.009 | 0.370 | 0.370 | 0.014 | p17

We can see that :

- reading and parsing the data is still slow (actually, everything is
copied something like 3-4 times)
- RecvFuncs take quite long, too
- triggers use some time, although the table has no triggers ....? This is
suspicious...
- the actual insertion (which is really what we are interested in when
loading a table) is actually very fast

Ideally in COPY the insertion time in the table should take most of the
time used in the operation...

I'm doing some more exploration with oprofile...

I've got the glibc-debug package installed (on kubuntu), but oprofile
doesn't seem to know about it. I wonder what part of glibc gets 60% of the
run time... do I have to set a magic option in the postgres config ?

samples % image name app name symbol
name
155312 61.7420 libc-2.7.so libc-2.7.so
/lib/tls/i686/cmov/libc-2.7.so
35921 14.2799 postgres postgres
CopyOneRowTo
7485 2.9756 postgres postgres
CopySendData
5626 2.2365 postgres postgres
MemoryContextAlloc
5174 2.0568 postgres postgres
FunctionCall1
5167 2.0541 no-vmlinux no-vmlinux
/no-vmlinux
5087 2.0223 postgres postgres
AllocSetAlloc
4340 1.7253 postgres postgres int4out
3896 1.5488 postgres postgres
heap_deform_tuple

On 8/18/09, Pierre Frédéric Caillaud <lists@peufeu.com> wrote:

I'm doing some more exploration with oprofile...

I've got the glibc-debug package installed (on kubuntu), but oprofile
doesn't seem to know about it. I wonder what part of glibc gets 60% of the
run time... do I have to set a magic option in the postgres config ?

AFAIK you need to run app with LD_LIBRARY_PATH=/usr/lib/debug,
otherwise the debug packages won't be used.

--
marko

AFAIK you need to run app with LD_LIBRARY_PATH=/usr/lib/debug,
otherwise the debug packages won't be used.

I had stupidly put the LD_LIBRARY_PATH on make rather than on postgres,
ahem.
OK, it works, thanks.

I'm very carefully benchmarking everything everytime I make a
modification : sometimes just a simple change creates an unexpected
performance loss.
So the process is slow, but performance patch should not make it slower ;)