Thread: log sql?
Is there way to track each sql statement and the user for the server? Thanks, -- Laurette Cisneros The Database Group (510) 420-3137 NextBus Information Systems, Inc. www.nextbus.com ---------------------------------- "Intelligence complicates. Wisdom simplifies." -- Mason Cooley
On Fri, Jul 26, 2002 at 03:27:45PM -0700, Laurette Cisneros wrote:
>
> Is there way to track each sql statement and the user for the server?
Sort of. Turn on query logging in the postgresql.conf file, and also
log connections and PID. Then, you can track back by using the PID,
to discovere who logged in (and therefore, who issued that query).
A
--
----
Andrew Sullivan 87 Mowat Avenue
Liberty RMS Toronto, Ontario Canada
<andrew@libertyrms.info> M6K 3E3
+1 416 646 3304 x110
Andrew Sullivan wrote:
> On Fri, Jul 26, 2002 at 03:27:45PM -0700, Laurette Cisneros wrote:
> >
> > Is there way to track each sql statement and the user for the server?
>
> Sort of. Turn on query logging in the postgresql.conf file, and also
> log connections and PID. Then, you can track back by using the PID,
> to discovere who logged in (and therefore, who issued that query).
Andrew, what postgresql.conf parameter is query logging. I don't see
it. I see:
#log_connections = false
#log_timestamp = false
#log_pid = false
--
Bruce Momjian | http://candle.pha.pa.us
pgman@candle.pha.pa.us | (610) 853-3000
+ If your life is a hard drive, | 830 Blythe Avenue
+ Christ can be your backup. | Drexel Hill, Pennsylvania 19026
On Tue, Jul 30, 2002 at 12:14:16AM -0400, Bruce Momjian wrote: > Andrew Sullivan wrote: > > On Fri, Jul 26, 2002 at 03:27:45PM -0700, Laurette Cisneros wrote: > > > > > > Is there way to track each sql statement and the user for the server? > > > > Sort of. Turn on query logging in the postgresql.conf file, and also > > log connections and PID. Then, you can track back by using the PID, > > to discovere who logged in (and therefore, who issued that query). > > Andrew, what postgresql.conf parameter is query logging. debug_print_query Cheers, Neil -- Neil Conway <neilconway@rogers.com> PGP Key ID: DB3C29FC
DEBUG_LEVEL (integer) The higher this value is set, the more "debugging" output of various sorts is generated in the server log during operation. This option is 0 by default, which means no debugging output. Values up to about 4 currently make sense. DEBUG_PRINT_QUERY (boolean) DEBUG_PRINT_PARSE (boolean) DEBUG_PRINT_REWRITTEN (boolean) DEBUG_PRINT_PLAN (boolean) DEBUG_PRETTY_PRINT (boolean) These flags enable various debugging output to be sent to the server log. For each executed query, prints either the query text, the resulting parse tree, the query rewriter output, or the execution plan. DEBUG_PRETTY_PRINT indents these displays to produce a more readable but much longer output format. Setting DEBUG_LEVEL above zero implicitly turns on some of these flags. -- I'd recommend debug level 1 and print query true for starters. Also remember that excessive debug logging can cause performance issues, so keep an eye on things if you crank this up on a production server. Robert Treat On Tue, 2002-07-30 at 00:14, Bruce Momjian wrote: > Andrew Sullivan wrote: > > On Fri, Jul 26, 2002 at 03:27:45PM -0700, Laurette Cisneros wrote: > > > > > > Is there way to track each sql statement and the user for the server? > > > > Sort of. Turn on query logging in the postgresql.conf file, and also > > log connections and PID. Then, you can track back by using the PID, > > to discovere who logged in (and therefore, who issued that query). > > Andrew, what postgresql.conf parameter is query logging. I don't see > it. I see: > > #log_connections = false > #log_timestamp = false > #log_pid = false > > -- > Bruce Momjian | http://candle.pha.pa.us > pgman@candle.pha.pa.us | (610) 853-3000 > + If your life is a hard drive, | 830 Blythe Avenue > + Christ can be your backup. | Drexel Hill, Pennsylvania 19026 > > ---------------------------(end of broadcast)--------------------------- > TIP 4: Don't 'kill -9' the postmaster
On Tue, Jul 30, 2002 at 12:14:16AM -0400, Bruce Momjian wrote:
> Andrew, what postgresql.conf parameter is query logging. I don't see
> it. I see:
>
> #log_connections = false
> #log_timestamp = false
> #log_pid = false
debug_print_query = true
If you really want to see what's going on, you can also turn on any
of these:
#debug_print_parse = false
#debug_print_rewritten = false
#debug_print_plan = false
#debug_pretty_print = false
The _rewritten one is really interesting, and sometimes shows you why
your query runs slowly. Not recommended for production systems,
though!
Note that all of this exacts a cost, so if you need really blazing
performance, it's not a bad idea to turn it off. But for tracking
down problems, nothing beats a good verbose log.
A
--
----
Andrew Sullivan 87 Mowat Avenue
Liberty RMS Toronto, Ontario Canada
<andrew@libertyrms.info> M6K 3E3
+1 416 646 3304 x110
What we really need is something that prints the query, username, and times for admins who want to see which queries are slow. That is on the TODO list. --------------------------------------------------------------------------- Andrew Sullivan wrote: > On Tue, Jul 30, 2002 at 12:14:16AM -0400, Bruce Momjian wrote: > > Andrew, what postgresql.conf parameter is query logging. I don't see > > it. I see: > > > > #log_connections = false > > #log_timestamp = false > > #log_pid = false > > debug_print_query = true > > If you really want to see what's going on, you can also turn on any > of these: > > #debug_print_parse = false > #debug_print_rewritten = false > #debug_print_plan = false > #debug_pretty_print = false > > The _rewritten one is really interesting, and sometimes shows you why > your query runs slowly. Not recommended for production systems, > though! > > Note that all of this exacts a cost, so if you need really blazing > performance, it's not a bad idea to turn it off. But for tracking > down problems, nothing beats a good verbose log. > > A > > -- > ---- > Andrew Sullivan 87 Mowat Avenue > Liberty RMS Toronto, Ontario Canada > <andrew@libertyrms.info> M6K 3E3 > +1 416 646 3304 x110 > > > ---------------------------(end of broadcast)--------------------------- > TIP 6: Have you searched our list archives? > > http://archives.postgresql.org > -- Bruce Momjian | http://candle.pha.pa.us pgman@candle.pha.pa.us | (610) 853-3000 + If your life is a hard drive, | 830 Blythe Avenue + Christ can be your backup. | Drexel Hill, Pennsylvania 19026
I'll try this. The last time I turned the debugging level up, it generated massive amounts of info in the log file so I turned it off. I'll try this... Thanks! L. On 30 Jul 2002, Robert Treat wrote: > DEBUG_LEVEL (integer) > > The higher this value is set, the more "debugging" output of various > sorts is generated in the server log during operation. This option is 0 > by default, which means no debugging output. Values up to about 4 > currently make sense. > DEBUG_PRINT_QUERY (boolean) > DEBUG_PRINT_PARSE (boolean) > DEBUG_PRINT_REWRITTEN (boolean) > DEBUG_PRINT_PLAN (boolean) > DEBUG_PRETTY_PRINT (boolean) > > These flags enable various debugging output to be sent to the server > log. For each executed query, prints either the query text, the > resulting parse tree, the query rewriter output, or the execution plan. > DEBUG_PRETTY_PRINT indents these displays to produce a more readable but > much longer output format. Setting DEBUG_LEVEL above zero implicitly > turns on some of these flags. > -- > I'd recommend debug level 1 and print query true for starters. Also > remember that excessive debug logging can cause performance issues, so > keep an eye on things if you crank this up on a production server. > > Robert Treat > > On Tue, 2002-07-30 at 00:14, Bruce Momjian wrote: > > Andrew Sullivan wrote: > > > On Fri, Jul 26, 2002 at 03:27:45PM -0700, Laurette Cisneros wrote: > > > > > > > > Is there way to track each sql statement and the user for the server? > > > > > > Sort of. Turn on query logging in the postgresql.conf file, and also > > > log connections and PID. Then, you can track back by using the PID, > > > to discovere who logged in (and therefore, who issued that query). > > > > Andrew, what postgresql.conf parameter is query logging. I don't see > > it. I see: > > > > #log_connections = false > > #log_timestamp = false > > #log_pid = false > > > > -- > > Bruce Momjian | http://candle.pha.pa.us > > pgman@candle.pha.pa.us | (610) 853-3000 > > + If your life is a hard drive, | 830 Blythe Avenue > > + Christ can be your backup. | Drexel Hill, Pennsylvania 19026 > > > > ---------------------------(end of broadcast)--------------------------- > > TIP 4: Don't 'kill -9' the postmaster > > > -- Laurette Cisneros The Database Group (510) 420-3137 NextBus Information Systems, Inc. www.nextbus.com ---------------------------------- "Intelligence complicates. Wisdom simplifies." -- Mason Cooley
On Tue, Jul 30, 2002 at 11:06:54AM -0400, Bruce Momjian wrote:
>
> What we really need is something that prints the query, username, and
> times for admins who want to see which queries are slow. That is on the
> TODO list.
That would indeed be cool. In the meantime, here are some strategies
I have used for working around the deficiency. Almost certainly not
news to anyone experienced, but I hope they're useful to someone.
I log the PID, connection, source port, and also the queries. I keep
several hundred megabytes of logs, in order to be able to track
backwards & find trouble spots.
If I get a report of slow performance, it is frequently one of those
annoying "blahblah is slow" type reports. But it usually includes
enough data that I can find the relevant query in my logs. Logged
with the query is the PID. PostgreSQL's one-process-per-connection
is a real advantage here, because I can track everything associated
with the transaction just by looking for the PID. (If you are
inexperienced with grep, trying to whittle down your logs is a good
way to learn to use it. On a busy system, you'll want to start with
something like
grep "\[yourpid\]" yourlogfile
)
Sometimes, the problem is obvious: a query turns out _not_ to be the
action reported or some such (don't laugh. I had someone complain
one time that queries were slow, to discover that the person in
question was actually reqesting a Cartesian product of several
million rows to several other million rows). But usually, the
problem is obscure. I sometimes find that a trigger is performing an
action which is causing the bottleneck -- they're a good thing to
watch for, because it's easy to forget about that extra insert or
update when you think about what the transaction "should" do.
You can turn on any of
#show_parser_stats = false
#show_planner_stats = false
#show_executor_stats = false
#show_query_stats = false
to see what the backend is doing. You can do it in a single psql session,
if you like, by issuing (for example)
set show_query_stats=on;
You can turn on those show_ parameters for the whole database by
editing the config gile and turning on the desired stat, and then
giving the postmaster SIGHUP. If you want to see the stats for your
session on a busy system, use more than one regular expression with
grep (different versions of grep handle that differently, but the -e
option often works). The stats all begin on a line with "!". Just
like the [] characters, you have to escape ! in order to use it, or
your shell will probably grab it. Note that the stats do not get the
PID on every line. (You can write a regexp to catch the stats for
just your PID, but this is not a regexp tutirial, so you're on your
own.)
Sometimes the only answer is to begin a transaction, and then start
stepping through the queries until you run into the problem. It's a
bad idea to do this on a production system (although if you have an
unreproducable problem, you sometimes have to. Don't forget to roll
back your transactions. This is a risky thing to do. It is very
bad. Be careful).
It has almost never happened to me that I had to undertake the
step-through approach, and not had an immediate head-slap moment when
I saw the actually slow query. It's either something plain -- a
recently-analysed table suddenly has had a bunch of updates, for
instance -- or else a query written so badly that I can't believe I
didn't see it first.
Anyway, the one-PID-per connection provides a really nice selection
criterion for reading log files. It would obviously be nice to be
able to turn on a feature and get a nice query-and-statistics line,
but the PostgreSQL logging is pretty flexible, and most of the
information one might want is actually available from the log
facility as it exists.
As I mentioned before, though, all this logging is _not_ free. It
has a measurable effect on the speed of your system.
Hope this is useful to someone.
A
--
----
Andrew Sullivan 87 Mowat Avenue
Liberty RMS Toronto, Ontario Canada
<andrew@libertyrms.info> M6K 3E3
+1 416 646 3304 x110
Hi, once you do that keep an eye over the log file size.. i rember messing up once on this,, postmaster will core dump once size(log_file)> 2.1 GB. regds mallah. > I'll try this. The last time I turned the debugging level up, it > generated massive amounts of info in the log file so I turned it off. > I'll try this... > > Thanks! > > L. > On 30 Jul 2002, Robert Treat wrote: > >> DEBUG_LEVEL (integer) >> >> The higher this value is set, the more "debugging" output of various >> sorts is generated in the server log during operation. This option is >> 0 by default, which means no debugging output. Values up to about 4 >> currently make sense. >> DEBUG_PRINT_QUERY (boolean) >> DEBUG_PRINT_PARSE (boolean) >> DEBUG_PRINT_REWRITTEN (boolean) >> DEBUG_PRINT_PLAN (boolean) >> DEBUG_PRETTY_PRINT (boolean) >> >> These flags enable various debugging output to be sent to the server >> log. For each executed query, prints either the query text, the >> resulting parse tree, the query rewriter output, or the execution >> plan. DEBUG_PRETTY_PRINT indents these displays to produce a more >> readable but much longer output format. Setting DEBUG_LEVEL above zero >> implicitly turns on some of these flags. >> -- >> I'd recommend debug level 1 and print query true for starters. Also >> remember that excessive debug logging can cause performance issues, so >> keep an eye on things if you crank this up on a production server. >> >> Robert Treat >> >> On Tue, 2002-07-30 at 00:14, Bruce Momjian wrote: >> > Andrew Sullivan wrote: >> > > On Fri, Jul 26, 2002 at 03:27:45PM -0700, Laurette Cisneros wrote: >> > > > >> > > > Is there way to track each sql statement and the user for the >> > > > server? >> > > >> > > Sort of. Turn on query logging in the postgresql.conf file, and >> > > also log connections and PID. Then, you can track back by using >> > > the PID, to discovere who logged in (and therefore, who issued >> > > that query). >> > >> > Andrew, what postgresql.conf parameter is query logging. I don't >> > see it. I see: >> > >> > #log_connections = false >> > #log_timestamp = false >> > #log_pid = false >> > >> > -- >> > Bruce Momjian | http://candle.pha.pa.us >> > pgman@candle.pha.pa.us | (610) 853-3000 >> > + If your life is a hard drive, | 830 Blythe Avenue >> > + Christ can be your backup. | Drexel Hill, Pennsylvania >> > 19026 >> > >> > ---------------------------(end of >> > broadcast)--------------------------- TIP 4: Don't 'kill -9' the >> > postmaster >> >> >> > > -- > Laurette Cisneros > The Database Group > (510) 420-3137 > NextBus Information Systems, Inc. > www.nextbus.com > ---------------------------------- > "Intelligence complicates. Wisdom simplifies." > -- Mason Cooley > > > ---------------------------(end of > broadcast)--------------------------- TIP 2: you can get off all lists > at once with the unregister command > (send "unregister YourEmailAddressHere" to majordomo@postgresql.org) ----------------------------------------- Get your free web based email at trade-india.com. "India's Leading B2B eMarketplace.!" http://www.trade-india.com/