SEO

When preparing to transfer blob data from one database to another (8.0.5
to 8.1.4), I found some interesting numbers that made me suspect that
bytea dumping is more ineffective than expectable.

I have a test dataset of 2000 rows, each row containing a bytea column.
Total disk usage of the table (no indexes) is 138MB, total data size is
1.4GB (sum(length(bytea_col)). Data is stored on a RAID5 (Areca 128MB,
SATA, 4 disks), and was dumped to a RAID1 on the same controller.

When dumping the table with psql \copy (non-binary), the resulting file
would be 6.6GB of size, taking about 5.5 minutes. Using psql \copy WITH
BINARY (modified psql as posted to -patches), the time was cut down to
21-22 seconds (filesize 1.4GB as expected), which is near the physical
throughput of the target disk. If server based COPY to file is used, The
same factor 12 can be observed, CPU is up to 100 % (single P4 3GHz 2MB
Cache HT disabled, 1GB main mem).

What's happening here?

Regards,
Andreas

---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
choose an index scan if your joining column's datatypes do not
match

Andreas Pflug <pgadmin@pse-consulting.de> writes:
> When dumping the table with psql \copy (non-binary), the resulting file
> would be 6.6GB of size, taking about 5.5 minutes. Using psql \copy WITH
> BINARY (modified psql as posted to -patches), the time was cut down to
> 21-22 seconds (filesize 1.4GB as expected), which is near the physical
> throughput of the target disk. If server based COPY to file is used, The
> same factor 12 can be observed, CPU is up to 100 % (single P4 3GHz 2MB
> Cache HT disabled, 1GB main mem).

This is with an 8.0.x server, right?

Testing a similar case with CVS HEAD, I see about a 5x speed difference,
which is right in line with the difference in the physical amount of
data written. (I was testing a case where all the bytes were emitted as
'\nnn', so it's the worst case.) oprofile says the time is being spent
in CopyAttributeOutText() and fwrite(). So I don't think there's
anything to be optimized here, as far as bytea goes: its binary
representation is just inherently a lot smaller.

Looking at CopySendData, I wonder whether any traction could be gained
by trying not to call fwrite() once per character. I'm not sure how
much per-call overhead there is in that function. We've done a lot of
work trying to optimize the COPY IN path since 8.0, but nothing much
on COPY OUT ...

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 3: Have you checked our extensive FAQ?

http://www.postgresql.org/docs/faq

Tom Lane wrote:
> Andreas Pflug <pgadmin@pse-consulting.de> writes:
>
>>When dumping the table with psql \copy (non-binary), the resulting file
>>would be 6.6GB of size, taking about 5.5 minutes. Using psql \copy WITH
>>BINARY (modified psql as posted to -patches), the time was cut down to
>>21-22 seconds (filesize 1.4GB as expected), which is near the physical
>>throughput of the target disk. If server based COPY to file is used, The
>>same factor 12 can be observed, CPU is up to 100 % (single P4 3GHz 2MB
>>Cache HT disabled, 1GB main mem).
>
>
> This is with an 8.0.x server, right?

I've tested both 8.0.5 and 8.1.4, no difference observed.

> Testing a similar case with CVS HEAD, I see about a 5x speed difference,
> which is right in line with the difference in the physical amount of
> data written.

That's what I would have expected, apparently the data is near worst case.

(I was testing a case where all the bytes were emitted as
> '\nnn', so it's the worst case.) oprofile says the time is being spent
> in CopyAttributeOutText() and fwrite(). So I don't think there's
> anything to be optimized here, as far as bytea goes: its binary
> representation is just inherently a lot smaller.

Unfortunately, binary isn't the cure for all, since copying normal data
with binary option might bloat that by factor two or so. I wish there
was a third option that's fine for both kinds of data. That's not only a
question of dump file sizes, but also of network throughput (an online
compression in the line protocol would be desirable for this).


> Looking at CopySendData, I wonder whether any traction could be gained
> by trying not to call fwrite() once per character. I'm not sure how
> much per-call overhead there is in that function. We've done a lot of
> work trying to optimize the COPY IN path since 8.0, but nothing much
> on COPY OUT ...

Hm, I'll see whether I can manage to check CVS head too, and see what's
happening, not a production alternative though.

Regards,
Andreas

---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
choose an index scan if your joining column's datatypes do not
match

Andreas Pflug <pgadmin@pse-consulting.de> writes:
> Tom Lane wrote:
>> Looking at CopySendData, I wonder whether any traction could be gained
>> by trying not to call fwrite() once per character. I'm not sure how
>> much per-call overhead there is in that function. We've done a lot of
>> work trying to optimize the COPY IN path since 8.0, but nothing much
>> on COPY OUT ...

> Hm, I'll see whether I can manage to check CVS head too, and see what's
> happening, not a production alternative though.

OK, make sure you get the copy.c version I just committed ...

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 3: Have you checked our extensive FAQ?

http://www.postgresql.org/docs/faq

Tom Lane wrote:
> Andreas Pflug <pgadmin@pse-consulting.de> writes:
>
>>Tom Lane wrote:
>>
>>>Looking at CopySendData, I wonder whether any traction could be gained
>>>by trying not to call fwrite() once per character. I'm not sure how
>>>much per-call overhead there is in that function. We've done a lot of
>>>work trying to optimize the COPY IN path since 8.0, but nothing much
>>>on COPY OUT ...
>
>
>>Hm, I'll see whether I can manage to check CVS head too, and see what's
>>happening, not a production alternative though.
>
>
> OK, make sure you get the copy.c version I just committed ...

Here are the results, with the copy patch:

psql \copy 1.4 GB from table, binary:
8.0 8.1 8.2dev
36s 34s 36s

psql \copy 1.4 GB to table, binary:
8.0 8.1 8.2dev
106s 95s 98s

psql \copy 6.6 GB from table, std:
8.0 8.1 8.2dev
375s 362s 290s (second:283s)

psql \copy 6.6 GB to table, std:
8.0 8.1 8.2dev
511s 230s 238s

INSERT INTO foo SELECT * FROM bar
8.0 8.1 8.2dev
75s 75s 75s

So obviously text COPY is enhanced by 20 % now, but it's still far from
the expected throughput. The dump disk should be capable of 60MB/s,
limiting text COPY to about 110 seconds, but the load process is CPU
restricted at the moment.

For comparision purposes, I included the in-server copy benchmarks as
well (bytea STORAGE EXTENDED; EXTERNAL won't make a noticable
difference). This still seems slower than expected to me, since the
table's on-disk footage is relatively small (138MB).

Regards,
Andreas

---------------------------(end of broadcast)---------------------------
TIP 4: Have you searched our list archives?

http://archives.postgresql.org

Andreas Pflug <pgadmin@pse-consulting.de> writes:
> Here are the results, with the copy patch:

> psql \copy 1.4 GB from table, binary:
> 8.0 8.1 8.2dev
> 36s 34s 36s

> psql \copy 6.6 GB from table, std:
> 8.0 8.1 8.2dev
> 375s 362s 290s (second:283s)

Hmph. There's something strange going on on your platform (what is it
anyway?) Using CVS HEAD on Fedora Core 4 x86_64, I get

bytea=# copy t to '/home/tgl/t.out';
COPY 1024
Time: 273325.666 ms
bytea=# copy binary t to '/home/tgl/t.outb';
COPY 1024
Time: 62113.355 ms

Seems \timing doesn't work on \copy (annoying), so

$ time psql -c "\\copy t to '/home/tgl/t.out2'" bytea

real 3m47.507s
user 0m3.700s
sys 0m36.406s
$ ls -l t.*
-rw-r--r-- 1 tgl tgl 5120001024 May 26 12:58 t.out
-rw-rw-r-- 1 tgl tgl 5120001024 May 26 13:14 t.out2
-rw-r--r-- 1 tgl tgl 1024006165 May 26 13:00 t.outb
$

This test case is 1024 rows each containing a 1000000-byte bytea, stored
EXTERNAL (no on-disk compression), all bytes chosen to need expansion to
\nnn form. So the ratio in runtimes is in keeping with the amount of
data sent. It's interesting (and surprising) that the runtime is
actually less for psql \copy than for server COPY. This is a dual Xeon
machine, maybe the frontend copy provides more scope to use both CPUs?

It would be interesting to see what's happening on your machine with
oprofile or equivalent.

I can't test psql binary \copy just yet, but will look at applying your
recent patch so that case can be checked.

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 4: Have you searched our list archives?

http://archives.postgresql.org

Tom Lane wrote:
> Andreas Pflug <pgadmin@pse-consulting.de> writes:
>
>>Here are the results, with the copy patch:
>
>
>>psql \copy 1.4 GB from table, binary:
>>8.0 8.1 8.2dev
>>36s 34s 36s
>
>
>>psql \copy 6.6 GB from table, std:
>>8.0 8.1 8.2dev
>>375s 362s 290s (second:283s)
>
>
> Hmph. There's something strange going on on your platform (what is it
> anyway?)

Debian 2.6.26.

> It's interesting (and surprising) that the runtime is
> actually less for psql \copy than for server COPY. This is a dual Xeon
> machine, maybe the frontend copy provides more scope to use both CPUs?

The dual CPU explanation sounds reasonable, but I found the same
tendency on a single 3GHz (HT disabled).
Strange observation using top:
user >90%, sys <10%, idle+wait 0% but only postmaster consumes cpu,
showing 35%, the rest neglectable.
>
> It would be interesting to see what's happening on your machine with
> oprofile or equivalent.

I'll investigate further, trying to find the missing CPU.

Regards,
Andreas

---------------------------(end of broadcast)---------------------------
TIP 4: Have you searched our list archives?

http://archives.postgresql.org

I wrote:
> I can't test psql binary \copy just yet, but will look at applying your
> recent patch so that case can be checked.

With patch applied:

$ time psql -c "\\copy t to '/home/tgl/t.out2'" bytea

real 3m46.057s
user 0m2.724s
sys 0m36.118s
$ time psql -c "\\copy t to '/home/tgl/t.outb2' binary" bytea

real 1m5.222s
user 0m0.640s
sys 0m6.908s
$ ls -l t.*
-rw-rw-r-- 1 tgl tgl 5120001024 May 26 16:02 t.out2
-rw-rw-r-- 1 tgl tgl 1024006165 May 26 16:03 t.outb2

The binary time is just slightly more than what I got before for a
server COPY:

bytea=# copy t to '/home/tgl/t.out';
COPY 1024
Time: 273325.666 ms
bytea=# copy binary t to '/home/tgl/t.outb';
COPY 1024
Time: 62113.355 ms

So those numbers seem to hang together, and it's just the text case
that is not making too much sense. I'm off for a little visit with
oprofile...

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 4: Have you searched our list archives?

http://archives.postgresql.org

I wrote:
> I'm off for a little visit with oprofile...

It seems the answer is that fwrite() does have pretty significant
per-call overhead, at least on Fedora Core 4. The patch I did yesterday
still ended up making an fwrite() call every few characters when dealing
with bytea text output, because it'd effectively do two fwrite()s per
occurrence of '\' in the data being output. I've committed a further
hack that buffers a whole data row before calling fwrite(). Even though
this presumably is adding one extra level of data copying, it seems to
make things noticeably faster:

bytea=# copy t to '/home/tgl/t.out';
COPY 1024
Time: 209842.139 ms

as opposed to 268 seconds before. We were already applying the
line-at-a-time buffering strategy for frontend copies, so that
path didn't change much (it's about 226 seconds for the same case).

At this point, a copy-to-file is just marginally faster than a
frontend copy happening on the local machine; which speaks well
for the level of optimization of the Linux send/recv calls.
More importantly, I see consistent results for the text and
binary cases.

Let me know what this does on your Debian machine ...

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 5: don't forget to increase your free space map settings

On 5/27/06, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> I wrote:
> > I'm off for a little visit with oprofile...
>
> It seems the answer is that fwrite() does have pretty significant
> per-call overhead, at least on Fedora Core 4.

That may be because of the locking ritual all stdio functions
like to do, even without _REENTRANT.

If you want to use fwrite as string operator, then maybe
should replace it with fwrite_unlocked?

--
marko

---------------------------(end of broadcast)---------------------------
TIP 5: don't forget to increase your free space map settings