Re: [PERFORM] 8.4 COPY performance regression on Solaris
Hi, Looking at the XLogInsert() from 8.3 and 8.4, the 8.4 version includes a call to RecoveryInProgress() at the top as well as a call to TRACE_POSTGRESQL_XLOG_INSERT(). Could either of those have caused a context switch or cache flush resulting in worse performance. Cheers, Ken -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] 8.4 COPY performance regression on Solaris
Kenneth Marshall k...@rice.edu writes: Looking at the XLogInsert() from 8.3 and 8.4, the 8.4 version includes a call to RecoveryInProgress() at the top as well as a call to TRACE_POSTGRESQL_XLOG_INSERT(). Could either of those have caused a context switch or cache flush resulting in worse performance. Hmm. TRACE_POSTGRESQL_XLOG_INSERT() should be a no-op (or at least, none of the complainants have admitted to building with --enable-dtrace). RecoveryInProgress() should be just a quick test of a local boolean, so it's hard to believe that it costs anything noticeable; but if anyone who is able to reproduce the problem wants to test this theory, try taking out these lines /* cross-check on whether we should be here or not */ if (RecoveryInProgress()) elog(FATAL, cannot make new WAL entries during recovery); which are only a sanity check anyway. regards, tom lane -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] 8.4 COPY performance regression on Solaris
Alan Li wrote: Hi, It seems that a COPY of 8M rows to a table to 8.4rc1 takes 30% longer than it does to 8.3.7 on Solaris. Here are the steps I've taken to reproduce this problem on two different solaris boxes (Solaris 10 11/06 s10x_u3wos_10 X86 and Solaris 10 8/07 s10x_u4wos_12b X86). I've tried this on a Linux box, and I do not see the problem there. tried that on my box (though I increased the testset size by 10x to get more sensible runtimes) and I can reproduce that on Linux(CentoS 5.3/x86_64, Nehalem Xeon E5530) as well. I get ~45 rows/s on 8.3 and only ~33/s on 8.4 on 8.4 I get: 3m59/4m01/3m56s runtime and a profile of samples %symbol name 636302 19.6577 XLogInsert 415510 12.8366 CopyReadLine 2253476.9618 DoCopy 1311434.0515 ParseDateTime 1220433.7703 DecodeNumber 81730 2.5249 DecodeDate 81045 2.5038 DecodeDateTime 80900 2.4993 pg_verify_mbstr_len 80235 2.4787 pg_next_dst_boundary 67571 2.0875 LWLockAcquire 64548 1.9941 heap_insert 64178 1.9827 LWLockRelease 63609 1.9651 PageAddItem 63402 1.9587 heap_form_tuple 56544 1.7468 timestamp_in 48697 1.5044 heap_fill_tuple 45248 1.3979 pg_atoi 42390 1.3096 IsSystemRelation 41287 1.2755 BufferGetBlockNumber 38936 1.2029 ValidateDate 36619 1.1313 ExecStoreTuple 35367 1.0926 DecodeTime on 8.3.7 I get 2m58s,2m54s,2m55s and a profile of: samples %symbol name 460966 16.2924 XLogInsert 307386 10.8643 CopyReadLine 301745 10.6649 DoCopy 1534525.4236 pg_next_dst_boundary 1197574.2327 DecodeNumber 1053563.7237 heap_formtuple 83456 2.9497 ParseDateTime 83020 2.9343 pg_verify_mbstr_len 72735 2.5708 DecodeDate 70425 2.4891 LWLockAcquire 65820 2.3264 LWLockRelease 61823 2.1851 DecodeDateTime 55895 1.9756 hash_any 51305 1.8133 PageAddItem 47440 1.6767 AllocSetAlloc 47218 1.6689 heap_insert 38912 1.3753 DecodeTime 34871 1.2325 ReadBuffer_common 34519 1.2200 date2j 33093 1.1696 DetermineTimeZoneOffset 31334 1.1075 MemoryContextAllocZero 30951 1.0939 RelationGetBufferForTuple If I do the same test utilizing WAL bypass the picture changes: 8.3 runtimes:2m16,2min14s,2min22s and profile: samples %symbol name 445583 16. CopyReadLine 332772 12.5300 DoCopy 1569745.9106 pg_next_dst_boundary 1319524.9684 heap_formtuple 1191144.4850 DecodeNumber 94340 3.5522 ParseDateTime 81624 3.0734 pg_verify_mbstr_len 75012 2.8245 DecodeDate 74950 2.8221 DecodeDateTime 64467 2.4274 hash_any 62859 2.3669 PageAddItem 62054 2.3365 LWLockAcquire 57209 2.1541 LWLockRelease 45812 1.7250 hash_search_with_hash_value 41530 1.5637 DetermineTimeZoneOffset 40790 1.5359 heap_insert 39694 1.4946 AllocSetAlloc 38855 1.4630 ReadBuffer_common 36056 1.3576 MemoryContextAllocZero 36030 1.3567 DecodeTime 29057 1.0941 UnpinBuffer 28291 1.0653 PinBuffer 8.4 runtime: 2m1s,2m,1m59s and profile: 404775 17.9532 CopyReadLine 2084829.2469 DoCopy 1488986.6042 ParseDateTime 1186455.2623 DecodeNumber 80972 3.5914 DecodeDate 79005 3.5042 pg_verify_mbstr_len 73645 3.2664 PageAddItem 72167 3.2009 DecodeDateTime 65264 2.8947 heap_form_tuple 52680 2.3365 timestamp_in 46264 2.0520 pg_next_dst_boundary 45819 2.0322 ExecStoreTuple 45745 2.0290 heap_fill_tuple 43690 1.9378 heap_insert 38453 1.7055 InputFunctionCall 37050 1.6433 LWLockAcquire 36853 1.6346 BufferGetBlockNumber 36428 1.6157 heap_compute_data_size 33818 1.5000 DetermineTimeZoneOffset 33468 1.4844 DecodeTime 30896 1.3703 tm2timestamp 30888 1.3700 GetCurrentTransactionId Stefan -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
[PERFORM] 8.4 COPY performance regression on Solaris
Hi,
It seems that a COPY of 8M rows to a table to 8.4rc1 takes 30% longer than
it does to 8.3.7 on Solaris.
Here are the steps I've taken to reproduce this problem on two different
solaris boxes (Solaris 10 11/06 s10x_u3wos_10 X86 and Solaris 10 8/07
s10x_u4wos_12b X86). I've tried this on a Linux box, and I do not see the
problem there.
1. Run the following in psql client to generate a 8M row data file.
copy (select generate_series(1,800), ('1 second'::interval *
generate_series(1,800) + '2007-01-01'::timestamp)) to
'/export/home/alan/work/pgsql/dump.out' with csv;
2. Build 8.3.7 and 8.4rc1 with the following config.
./configure --prefix=`pwd`/../pgsql CC=/opt/SUNWspro/bin/cc CFLAGS=-xO3
-xarch=native \
-xspace -W0,-Lt -W2,-Rcond_elim -Xa -xildoff -xc99=none -xCC
--without-readline --with-includes=/opt/csw/include
--with-libraries=/opt/csw/lib
3. Run the following on each.
pg_ctl stop -D data -m fast
rm -rf data
initdb -D data
cat postgresql.conf data/postgresql.conf
pg_ctl start -l cq.log -D data -w
psql -f ddl.sql postgres
time psql -c copy t from '/export/home/alan/work/pgsql/dump.out' with csv
postgres
Here are the numbers from several runs I've done.
8.3.7 - Solaris 10 11/06 s10x_u3wos_10 X86
real0m43.971s
user0m0.002s
sys 0m0.003s
real0m44.042s
user0m0.002s
sys 0m0.003s
real0m44.828s
user0m0.002s
sys 0m0.004s
real0m43.921s
user0m0.002s
sys 0m0.003s
8.4rc1 - Solaris 10 11/06 s10x_u3wos_10 X86
real1m0.041s
user0m0.002s
sys 0m0.003s
real1m0.258s
user0m0.002s
sys 0m0.004s
real1m0.173s
user0m0.002s
sys 0m0.003s
real1m0.402s
user0m0.002s
sys 0m0.003s
real1m0.767s
user0m0.002s
sys 0m0.003s
8.3.7 - Solaris 10 8/07 s10x_u4wos_12b X86
real0m36.242s
user0m0.002s
sys 0m0.004s
real0m37.206s
user0m0.002s
sys 0m0.004s
real0m38.431s
user0m0.002s
sys 0m0.004s
real0m38.885s
user0m0.002s
sys 0m0.004s
real0m38.177s
user0m0.002s
sys 0m0.004s
real0m38.332s
user0m0.002s
sys 0m0.004s
real0m38.401s
user0m0.002s
sys 0m0.004s
real0m36.817s
user0m0.002s
sys 0m0.004s
real0m39.505s
user0m0.002s
sys 0m0.004s
real0m38.871s
user0m0.002s
sys 0m0.004s
real0m38.939s
user0m0.002s
sys 0m0.004s
real0m38.823s
user0m0.002s
sys 0m0.004s
real0m37.955s
user0m0.002s
sys 0m0.004s
real0m39.196s
user0m0.002s
sys 0m0.004s
8.4rc1 - Solaris 10 8/07 s10x_u4wos_12b X86
real0m50.603s
user0m0.002s
sys 0m0.004s
real0m49.945s
user0m0.002s
sys 0m0.004s
real0m50.547s
user0m0.002s
sys 0m0.004s
real0m50.061s
user0m0.002s
sys 0m0.004s
real0m48.151s
user0m0.002s
sys 0m0.004s
real0m50.133s
user0m0.002s
sys 0m0.004s
real0m50.583s
user0m0.002s
sys 0m0.004s
Has anyone else seen this problem?
Thanks, Alan
drop table t;
create table t (i int, d timestamp);
postgresql.conf
Description: Binary data
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
