Re: your mail - Mailing list pgsql-hackers

From Bruce Momjian
Subject Re: your mail
Date
Msg-id 199803100254.VAA12164@candle.pha.pa.us
Whole thread Raw
List pgsql-hackers
> trashing postgresql doing a 'select count(*) from artist_fti'
> "select count(*) from artist_fti where string ~ '^lling';"
> "select count(*) from artist_fti where string ~ '^tones';"
> and the join-statement.
>
> I don't have much knowledge of profiling, but it seems to me that in the
> end this is really related to I/O. Dirty disk caches forces postgresql to
> read everything from disk again, and this disk is not the fastest in the
> world. Still it takes much more time than I would expect. I mean, btree
> is designed to have few disk accesses, and then accessing the tables
> shouldn't take too long also.

[Marteen is finding word searches on a big table to take a long time.
This is the word slice code we talked about recently as a group.  It
rapid searches for words inside of strings.  Very useful.]

OK, I meant to reply to this, but forgot to.  Let's take the second query:

    select count(*) from artist_fti where string ~ '^lling';

Here is the top of the profile output:

---------------------------------------------------------------------------

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total
 time   seconds   seconds    calls  us/call  us/call  name
 10.20      0.05     0.05    18434     2.71     2.71  sstep
  8.16      0.09     0.04     3225    12.40    12.41  RelationGetLRelId
  6.12      0.12     0.03     5862     5.12     5.12  SpinAcquire
  6.12      0.15     0.03     2750    10.91    10.91  ExecEvalVar
  6.12      0.18     0.03      105   285.71   411.52  heapgettup
  6.12      0.21     0.03        2 15000.00 54472.81  ExecAgg
  4.08      0.23     0.02    12711     1.57     1.57  OrderedSetContains
  4.08      0.25     0.02     5501     3.64     9.09  ExecEvalExpr
  2.04      0.26     0.01    12711     0.79     2.36  AllocSetContains
  2.04      0.27     0.01     7722     1.30     1.30  OrderedElemPushHead
  2.04      0.28     0.01     7608     1.31     2.63  hash_search
  2.04      0.29     0.01     6395     1.56     1.56  tag_hash
  2.04      0.30     0.01     5610     1.78     6.50  PortalHeapMemoryFree
  2.04      0.31     0.01     2293     4.36     4.36  fmgr_isbuiltin
  2.04      0.32     0.01     1919     5.21     5.21  BufferGetBlockNumber
  2.04      0.33     0.01     1912     5.23     9.55  ReleaseBuffer
  2.04      0.34     0.01     1572     6.36     6.36  TransactionIdEquals
  2.04      0.35     0.01     1571     6.37    12.73  HeapTupleSatisfiesVisibili


---------------------------------------------------------------------------

First 'sstep' is taking a lot of time, and that, I think, is the regex
stuff.  Author says the regex is slow and can be speeded up, so we may
get a new release from him soon.

Also strange is the time for ExecAgg, which seems fairly high for a
single function, but only 0.015 seconds.  Certainly not significant in
the wallclock time.

Now, seeing as everything else adds up to perhaps 1-2 seconds, why 30
seconds for the query.  Certainly looks like I/O is the problem.

Have you tried adding -B buffers.  This, I think, would help.  If you
don't flush the cache, how long does a second identical query take?
Also, Vadim, when the backend is accessing a btree index, does it walk
down to the page it needs and read all rows off of that, or does it
drill down the btree to get each row.  Third, remember that these are
made indexable by adding

        string >= 'ling' and
        string <= 'ling\377'

Now, if each is taken to evaluate litarally, I am guessing the backend
is getting all >= 'ling' and then all <= 'ling\377' and then finding the
ones that match.  This is terrible for performance.  I believe this is
the crux of the problem, and why so much I/O is going on.

Vadim, any way to make the optimizer realize that we are looking for a
range of values, and preventing it from pulling all those rows from the
index?  Almost some index scheme that would get all >= 'ling' but stop
when they get > 'ling\377'?

With this going on, the system is spinning through the entire btree
index each time to get the data, even though it is a small subset.

As part of a test, would you please run:

    select count(*) from artist_fti where string >= 'lling'

and

    select count(*) from artist_fti where string <= 'lling\377'


and then try:

    select count(*) from artist_fti where string >= 'lling' and
                        string <= 'lling\377'

Also try:

    select count(*) from artist_fti where string ~ '^lling' and
                    string >= 'lling and
                    string <= 'lling\377';

Try these with the cache trashing code to get good numbers on the
performance.  My guess is that the sum of the first and second execution
times will equal the time for the third, and the third and fourth will
take the same amount of time.

--
Bruce Momjian                          |  830 Blythe Avenue
maillist@candle.pha.pa.us              |  Drexel Hill, Pennsylvania 19026
  +  If your life is a hard drive,     |  (610) 353-9879(w)
  +  Christ can be your backup.        |  (610) 853-3000(h)

pgsql-hackers by date:

Previous
From: Karl Denninger
Date:
Subject: Re: [HACKERS] Heh, the disappearing problem!
Next
From: "Thomas G. Lockhart"
Date:
Subject: Re: [HACKERS] Re: your mail