Обсуждение: RE: [SQL] plpgsql error
What version that has Procedural Language support for Perl?
>X-Authentication-Warning: hub.org: majordom set sender to
owner-pgsql-sql@postgreSQL.org using -f
>From: Michael J Davis <michael.j.davis@tvguide.com>
>To: "'jwieck@debis.com'" <jwieck@debis.com>, alewis@themecca.net
>Cc: apendleton@vgsinc.com, pgsql-sql@hub.org
>Subject: RE: [SQL] plpgsql error
>Date: Tue, 11 May 1999 09:23:32 -0500
>MIME-Version: 1.0
>
>Gets my vote. Should we also consider doing this for Perl too? I turn them
>all on in my installation. I don't use either Perl or TCL yet but want to
>make sure they are available if 1) I ever want to or 2) a need arises that
>is would be better suited to either Perl or TCL.
>
>Thanks, Michael D.
>
> -----Original Message-----
> From: jwieck@debis.com [SMTP:jwieck@debis.com]
> Sent: Tuesday, May 11, 1999 1:35 AM
> To: alewis@themecca.net
> Cc: apendleton@vgsinc.com; pgsql-sql@hub.org
> Subject: Re: [SQL] plpgsql error
>
> >
> > Edit:
>/usr/src/pgsql/postgresql-6.4.2/src/pl/plpgsql/src/mklang.sql
> >
> > Change: as '${exec_prefix}/lib/plpgsql.so'
> > to: as '/usr/local/pgsql/lib/plpgsql.so'
> >
> > Then: psql your_db < mklang.sql
> >
> > This should really be part of the documentation as I wasted two
>days on
> > this same problem a few weeks back.
>
> And this became IMHO an FAQ. Should we avoid it by installing
> PL/pgSQL and PL/Tcl (if built) by default in the template1
> database during intidb? Installing it in template1 would
> have the effect that it will be available after every
> createdb.
>
>
> Jan
>
> --
>
>
>#======================================================================#
> # It's easier to get forgiveness for being wrong than for being
>right. #
> # Let's break this rule - forgive me.
>#
> #======================================== jwieck@debis.com (Jan
>Wieck) #
>
>
>
--
Nisai Wanakule, PH.D., P.E.
Tampa Bay Water
2535 Landmark Dr., Suite 211
Clearwater, FL 33761
Tel 727/791-2373
Fax 727/791-2388
SunCom: 513-7010
Nisai Wanakule wrote:
>
> What version that has Procedural Language support for Perl?
>
None - there is only client access support for Perl so far.
I'm still waiting for a Perl guru who has the knowledge how
to integrate a Perl interpreter into another program.
I've implemented the CREATE LANGUAGE and changed the function
manager to recognize functions in procedural languages. And
I've written PL/Tcl and PL/pgSQL, so I can (and am willing
to) answer all questions about how to interface from a new
language module to fmgr or SPI. But I'm not willing to learn
Perl, Python etc. plus their API just to create all these
PL's.
Jan
--
#======================================================================#
# It's easier to get forgiveness for being wrong than for being right. #
# Let's break this rule - forgive me. #
#======================================== jwieck@debis.com (Jan Wieck) #
Hi,
I'm having a minor problem with one of my queries.
inventorysuppliers.id
av_parts.rawpartnumber
av_parts.vendorid
all have indexes.
Why in the world is postgres selecting seq scan on the inventorysuppliers
table when doing an LIKE? That doesn't make sense to me.
PG version: 6.5 CVS as of monday.
OS: Redhat 6.0, Linux 2.2.6, glibc 2.1
Platform: i386
Running query with explain:
Nested Loop (cost=440.35 rows=1 width=100) -> Seq Scan on inventorysuppliers (cost=11.90 rows=209 width=40) ->
IndexScan using av_parts_vendorid_index on av_parts (cost=2.05
rows=1 width=60)
Running query with last line as: AND (AV_Parts.RawPartNumber = '6890040')
Nested Loop (cost=4.10 rows=1 width=100) -> Index Scan using av_parts_rawpartnumber_index on av_parts
(cost=2.05 rows=1 width=60) -> Index Scan using inventorysuppliers_id_index on inventorysuppliers
(cost=2.05 rows=209 width=40)
Query:
SELECT AV_Parts.PartNumber, AV_Parts.Description, AV_Parts.NSN, AV_Parts.Quantity,
AV_Parts.Condition, inventorysuppliers.companyname, inventorysuppliers.phone, inventorysuppliers.fax,
AV_Parts.ItemID, AV_Parts.VendorID FROM AV_Parts, inventorysuppliers WHERE
(AV_Parts.VendorID= inventorysuppliers.id) AND (AV_Parts.RawPartNumber LIKE '6890040%')
Thanks,
Ole Gjerde
gjerde@icebox.org writes:
> Why in the world is postgres selecting seq scan on the inventorysuppliers
> table when doing an LIKE? That doesn't make sense to me.
I'm guessing you might be compiling with LOCALE support turned on?
The parser's hack to make LIKE comparisons indexable is only half
functional in that case, since you get the >= comparison but not the <=
one. Given the small size of your tables, the optimizer is probably
estimating that an index scan isn't going to be selective enough to
justify its extra cost.
FWIW, I do get an index scan plan on an attempt to duplicate this
case... but I'm not using LOCALE.
We need to figure out a way to make LIKE indexable in non-ASCII locales.
I think the best bet might be to try to generate a string "one greater"
than the given initial string. In other words, givenfield LIKE 'ABC%'
we want to transform tofield LIKE 'ABC%' AND field >= 'ABC' AND field < 'ABD'
so that the optimizer can use the last two clauses to constrain the
index scan.
But it's not real obvious how to generate a "larger" string in the
general case with multibyte characters and non-straightforward collation
order. Anyone have an idea how to do that?
regards, tom lane
On Wed, 12 May 1999, Tom Lane wrote: > I'm guessing you might be compiling with LOCALE support turned on? Unfortunately not. I run ./configure --prefix=/home/postgres so that wouldn't be the case. > The parser's hack to make LIKE comparisons indexable is only half > functional in that case, since you get the >= comparison but not the <= > one. Given the small size of your tables, the optimizer is probably > estimating that an index scan isn't going to be selective enough to > justify its extra cost. Then postgres is not guessing right. Even tho the table only has ~200 rows, the query still takes forever to finish. I have let it go for a few minutes, and it still wasn't done.. I suppose that would be because it's doing a seq scan on the inventorysuppliers table for EACH hit in the av_parts table. That's bound to be slow :) > FWIW, I do get an index scan plan on an attempt to duplicate this > case... but I'm not using LOCALE. Weird. I'll have to look at it more. Thanks, Ole Gjerde
gjerde@icebox.org writes:
> Then postgres is not guessing right. Even tho the table only has
> ~200 rows, the query still takes forever to finish. I have let it go for
> a few minutes, and it still wasn't done..
Something wrong there; even with a nested loop, it shouldn't take more
than a few seconds to process that query. Please dig into it a little
more (do you have gprof?) and find where it's spending the time.
regards, tom lane
On Wed, 12 May 1999, Tom Lane wrote:
> gjerde@icebox.org writes:
> > Then postgres is not guessing right. Even tho the table only has
> > ~200 rows, the query still takes forever to finish. I have let it go for
> > a few minutes, and it still wasn't done..
> Something wrong there; even with a nested loop, it shouldn't take more
> than a few seconds to process that query. Please dig into it a little
> more (do you have gprof?) and find where it's spending the time.
Yes, it definately takes too long. I just let it run its course with
profiling on, and it took a good 25 minutes.
Compiling postgres with -pg created 2 gmon.out files. One in postgres
home dir(/home/postgres/) and one in the database
directory(/home/postgres/data/base/parts). The first one had very little
in it, while the second one is the one below, which seemed to be the right
stuff.
gprof says: % cumulative self self totaltime seconds seconds calls us/call us/call name
100.00 0.01 0.01 3 3333.33 3333.33 ValidatePgVersion 0.00 0.01 0.00 11745603 0.00
0.00 AllocSetAlloc 0.00 0.01 0.00 11745603 0.00 0.00 MemoryContextAlloc 0.00 0.01 0.00
11743401 0.00 0.00 PortalHeapMemoryAlloc 0.00 0.01 0.00 11743016 0.00 0.00 AllocSetFree 0.00
0.01 0.00 11743016 0.00 0.00 MemoryContextFree 0.00 0.01 0.00 11741730 0.00 0.00
AllocSetContains0.00 0.01 0.00 11741730 0.00 0.00 PortalHeapMemoryFree 0.00 0.01 0.00
11741472 0.00 0.00 ExecEvalExpr 0.00 0.01 0.00 7828744 0.00 0.00 LockBuffer 0.00
0.01 0.00 7827998 0.00 0.00 fmgr_c 0.00 0.01 0.00 4145068 0.00 0.00 hash_search 0.00
0.01 0.00 4135600 0.00 0.00 call_hash 0.00 0.01 0.00 4135235 0.00 0.00
tag_hash0.00 0.01 0.00 4110386 0.00 0.00 SpinAcquire 0.00 0.01 0.00 4110386 0.00
0.00 SpinRelease 0.00 0.01 0.00 3925111 0.00 0.00 BufferGetBlockNumber 0.00 0.01 0.00
3923168 0.00 0.00 BufTableLookup 0.00 0.01 0.00 3923168 0.00 0.00 BufferAlloc 0.00 0.01
0.00 3923168 0.00 0.00 ReadBufferWithBufferLock 0.00 0.01 0.00 3923127 0.00 0.00
ReleaseBuffer0.00 0.01 0.00 3922903 0.00 0.00 ReadBuffer 0.00 0.01 0.00 3915548 0.00
0.00 fmgr_info 0.00 0.01 0.00 3915548 0.00 0.00 fmgr_isbuiltin 0.00 0.01 0.00
3915387 0.00 0.00 _bt_checkkeys 0.00 0.01 0.00 3914991 0.00 0.00 _bt_step 0.00 0.01
0.00 3914710 0.00 0.00 nocachegetattr 0.00 0.01 0.00 3914656 0.00 0.00 ExecEvalVar 0.00
0.01 0.00 3914584 0.00 0.00 fmgr 0.00 0.01 0.00 3914247 0.00 0.00 ExecClearTuple
0.00 0.01 0.00 3914143 0.00 0.00 int4eq 0.00 0.01 0.00 3914032 0.00 0.00
ExecStoreTuple0.00 0.01 0.00 3913780 0.00 0.00 btgettuple 0.00 0.01 0.00 3913780 0.00
0.00 index_getnext 0.00 0.01 0.00 3913589 0.00 0.00 HeapTupleSatisfiesSnapshot 0.00 0.01
0.00 3913589 0.00 0.00 IndexNext 0.00 0.01 0.00 3913570 0.00 0.00 FormRetrieveIndexResult
0.00 0.01 0.00 3913570 0.00 0.00 heap_fetch 0.00 0.01 0.00 3913516 0.00 0.00
_bt_next0.00 0.01 0.00 3913414 0.00 0.00 ExecMakeFunctionResult 0.00 0.01 0.00 3913413
0.00 0.00 ExecEvalFuncArgs 0.00 0.01 0.00 3913413 0.00 0.00 ExecEvalOper 0.00 0.01
0.00 3913413 0.00 0.00 ExecQualClause 0.00 0.01 0.00 3913391 0.00 0.00 ExecQual 0.00
0.01 0.00 3913381 0.00 0.00 _bt_restscan 0.00 0.01 0.00 3913380 0.00 0.00 DoMatch
0.00 0.01 0.00 3913380 0.00 0.00 fixedlen_like 0.00 0.01 0.00 3913380 0.00 0.00
like0.00 0.01 0.00 3913380 0.00 0.00 textlike 0.00 0.01 0.00 3840791 0.00
0.00 PinBuffer 0.00 0.01 0.00 85733 0.00 0.00 AddBufferToFreelist
On the other hand, I did have a backend close on me earlier today. I
didn't notice the core file until now however. The query(I think) that
made this was a very simple SELECT. However, I was doing some other
queries at about the same time(the query with problems above)
Here's what gdb had to say:
(gdb) bt
#0 0x40101111 in __kill ()
#1 0x40100d66 in raise (sig=6) at ../sysdeps/posix/raise.c:27
#2 0x40102447 in abort () at ../sysdeps/generic/abort.c:88
#3 0x80d734d in s_lock_stuck ()
#4 0x80d73c1 in s_lock ()
#5 0x80d6049 in WaitIO ()
#6 0x80d58a8 in BufferAlloc ()
#7 0x80d56ed in ReadBufferWithBufferLock ()
#8 0x80d5688 in ReadBuffer ()
#9 0x806c2f7 in heap_fetch ()
#10 0x80982f3 in IndexNext ()
#11 0x80946c9 in ExecScan ()
#12 0x8098410 in ExecIndexScan ()
#13 0x809313e in ExecProcNode ()
#14 0x8099694 in ExecNestLoop ()
#15 0x8093147 in ExecProcNode ()
#16 0x8092529 in ExecutePlan ()
#17 0x8091c2e in ExecutorRun ()
Thanks,
Ole Gjerde
> On Wed, 12 May 1999, Tom Lane wrote: > > gjerde@icebox.org writes: > > > Then postgres is not guessing right. Even tho the table only has > > > ~200 rows, the query still takes forever to finish. I have let it go for > > > a few minutes, and it still wasn't done.. > > Something wrong there; even with a nested loop, it shouldn't take more > > than a few seconds to process that query. Please dig into it a little > > more (do you have gprof?) and find where it's spending the time. > > Yes, it definately takes too long. I just let it run its course with > profiling on, and it took a good 25 minutes. > > Compiling postgres with -pg created 2 gmon.out files. One in postgres > home dir(/home/postgres/) and one in the database > directory(/home/postgres/data/base/parts). The first one had very little > in it, while the second one is the one below, which seemed to be the right > stuff. > > gprof says: > % cumulative self self total > time seconds seconds calls us/call us/call name > 100.00 0.01 0.01 3 3333.33 3333.33 ValidatePgVersion Yikes. ValidatePGVersion. Seems you are in a loop in there somehow. I bet you have a terrible mismatch somewhere. -- Bruce Momjian | http://www.op.net/~candle maillist@candle.pha.pa.us | (610) 853-3000+ If your life is a hard drive, | 830 Blythe Avenue + Christ can be your backup. | Drexel Hill, Pennsylvania19026
On Thu, 13 May 1999, Bruce Momjian wrote: > > gprof says: > > % cumulative self self total > > time seconds seconds calls us/call us/call name > > 100.00 0.01 0.01 3 3333.33 3333.33 ValidatePgVersion > Yikes. ValidatePGVersion. Seems you are in a loop in there somehow. I > bet you have a terrible mismatch somewhere. I think you can ignore that line. I ran it again and that wasn't there. It looked identical otherwise however. I timed it this time, and it took 13 minutes. For some reason, gprof is somewhat messed up not showing timings. I've tried a few things and done some searching. This seems to be a fairly typical problem, but I haven't found any working solutions yet. Maybe the # of times the functions are being called will tell you guys something. Any ideas on the gprof? Thanks, Ole Gjerde
gjerde@icebox.org writes:
> gprof says:
> % cumulative self self total
> time seconds seconds calls us/call us/call name
> 100.00 0.01 0.01 3 3333.33 3333.33 ValidatePgVersion
I concur with the conclusion that this entry is bogus --- you haven't
got a fully functional installation of gprof, evidently :-(. Assuming
that the call counts are accurate, it's clear that memory allocation
and expression evaluation are the main time sinks. It surprises me
that there's so much allocation going on. (Could there be alloc/free
calls inside the regex matcher?)
How big did you say these tables were? The explain outputs you posted
before made them look pretty small ... but if you have not vacuumed the
tables lately, the optimizer might have a bad idea of how big they are.
The number of iterations through the tuple-level routines suggests that
several million tuple combinations are being processed.
> On the other hand, I did have a backend close on me earlier today. I
> didn't notice the core file until now however. The query(I think) that
> made this was a very simple SELECT. However, I was doing some other
> queries at about the same time(the query with problems above)
> Here's what gdb had to say:
> (gdb) bt
> #0 0x40101111 in __kill ()
> #1 0x40100d66 in raise (sig=6) at ../sysdeps/posix/raise.c:27
> #2 0x40102447 in abort () at ../sysdeps/generic/abort.c:88
> #3 0x80d734d in s_lock_stuck ()
> #4 0x80d73c1 in s_lock ()
Several other people have reported s_lock_stuck() aborts recently;
I don't think we quite know the cause yet...
regards, tom lane
On Thu, 13 May 1999, Tom Lane wrote: > I concur with the conclusion that this entry is bogus --- you haven't > got a fully functional installation of gprof, evidently :-(. Assuming Which is weird, since this is a clean install of redhat linux 6.0 :) > How big did you say these tables were? The explain outputs you posted The av_parts table has about 4 million rows, while inventorysuppliers only has ~200 rows. > before made them look pretty small ... but if you have not vacuumed the > tables lately, the optimizer might have a bad idea of how big they are. The table had been vacuumed about a week before, with no updates, inserts or deletes in the mean time. I ran vacuum again, and the query is done instantly, however the cost seem a bit high, no? Hash Join (cost=31373.53 rows=7218 width=100) -> Index Scan using av_parts_rawpartnumber_index on av_parts (cost=31313.53rows=1186 width=60) -> Hash (cost=11.93 rows=210 width=40) -> Seq Scan on inventorysuppliers (cost=11.93rows=210 width=40) > Several other people have reported s_lock_stuck() aborts recently; > I don't think we quite know the cause yet... Bummer, I haven't found a way to reproduce it yet. I have had some other misc weird problems. One of them was with vacuum. I was running 'vacuumdb -z -v procurement' on one of my databases (~3GB) and it kept crashing the backend. (gdb) bt #0 0x810a28f in hash_search () #1 0x80d53e5 in BufTableLookup () #2 0x80d59c1 in BufferAlloc () #3 0x80d583d in ReadBufferWithBufferLock () #4 0x80d57d8 in ReadBuffer () #5 0x80886b2 in vc_scanheap () #6 0x808840c in vc_vacone () #7 0x8087dc1 in vc_vacuum () #8 0x8087cb3 in vacuum () Unfortunately I haven't compiled with -g.. The weird thing is that once I did a 'vacuumdb -v procurement', then I could do a -z vacuum again and it worked... Thanks, Ole Gjerde
Ole Gjerde <gjerde@icebox.org> writes:
>> How big did you say these tables were?
> The av_parts table has about 4 million rows, while inventorysuppliers only
> has ~200 rows.
Ah! That's a critical bit of information! It sure looks to me like the
optimizer did not know that when it was producing the plan you showed
earlier; so it used a plan that looked OK but actually was pretty awful.
> I ran vacuum again, and the query is done instantly, however the cost seem
> a bit high, no?
> Hash Join (cost=31373.53 rows=7218 width=100)
> -> Index Scan using av_parts_rawpartnumber_index on av_parts (cost=31313.53 rows=1186 width=60)
> -> Hash (cost=11.93 rows=210 width=40)
> -> Seq Scan on inventorysuppliers (cost=11.93 rows=210 width=40)
No, that's probably about right --- bear in mind that the optimizer is
only making guesses about how many hits there will be for an index
restriction. Here, we can see that it's guessing 1186 hits in the
av_parts table, which is pretty darn selective for a 4-million-row
table (about 0.03%), even though really there might be only a few
matches.
Note that this doesn't have anything to do with how many rows will
actually match your given restrictionAV_Parts.RawPartNumber LIKE '6890040%'
Instead, it's an estimate based on looking at the additional
index-compatible restrictions that the parser manufactured from that
clause, namelyAV_Parts.RawPartNumber >= '6890040'ANDAV_Parts.RawPartNumber <= '6890040\377'
and trying to guess how many rows will be scanned between those lower
and upper index limits. There's going to be an awful lot of fuzz in any
such estimate.
However, the optimizer drew the right conclusion, namely that this way
is probably cheaper than any other way. You'll recall that before, it
was estimating only two cost units for an index scan on av_parts, which
is obviously silly for a 4-million-row table. (The cost units are
intended to be roughly 1 unit = 1 disk block access.) So it thought it
could get away with doing that as the inner loop of a nested-loop join.
Now that it knows scanning av_parts is *not* cheap compared to scanning
inventorysuppliers, it's making better decisions.
You are probably used to looking at small cost estimates from your
experience with small or unvacuumed tables. Now that the optimizer knows
how big av_parts really is, all its estimates for queries involving that
table will be large --- but they're all relative anyway.
regards, tom lane