Thread: [GENERAL] Postgres csv logging
I am trying to log executed queries into a csv file.
My main objective is to log the command tag and query. For that I enabled
logging in the postgresql.conf, my configs are the following:
#------------------------------------------------------------------------------
# ERROR REPORTING AND LOGGING
#------------------------------------------------------------------------------
# - Where to Log -
log_destination = 'stderr,csvlog' # Valid values are
combinations of
# stderr, csvlog, syslog, and
eventlog,
# depending on platform. csvlog
# requires logging_collector to be
on.
# This is used when logging to stderr:
logging_collector = on # Enable capturing of stderr and
csvlog
# into log files. Required to be on
for
# csvlogs.
# (change requires restart)
# These are only used if logging_collector is on:
log_directory = 'pg_log' # directory where log files are
written,
# can be absolute or relative to
PGDATA
log_filename = 'postgresql-%a-%H-%M.log' # log file name pattern,
# can include strftime() escapes
#log_file_mode = 0600 # creation mode for log files,
# begin with 0 to use octal notation
log_truncate_on_rotation = on # If on, an existing log file with
the
# same name as the new log file will
be
# truncated rather than appended to.
# But such truncation only occurs on
# time-driven rotation, not on
restarts
# or size-driven rotation. Default
is
# off, meaning append to existing
files
# in all cases.
log_rotation_age = 10 # Automatic rotation of logfiles
will
# happen after that time. 0
disables.
log_rotation_size = 10240 # Automatic rotation of
logfiles will
# happen after that much log output.
# 0 disables.
# These are relevant when logging to syslog:
#syslog_facility = 'LOCAL0'
#syslog_ident = 'postgres'
# This is only relevant when logging to eventlog (win32):
#event_source = 'PostgreSQL'
# - When to Log -
#client_min_messages = log # values in order of decreasing
detail:
# debug5
# debug4
# debug3
# debug2
# debug1
# log
# notice
# warning
# error
#log_min_messages = info # values in order of decreasing
detail:
# debug5
# debug4
# debug3
# debug2
# debug1
# info
# notice
# warning
# error
# log
# fatal
# panic
#log_min_error_statement = info # values in order of decreasing
detail:
# debug5
# debug4
# debug3
# debug2
# debug1
# info
# notice
# warning
# error
# log
# fatal
# panic (effectively off)
log_min_duration_statement = 0 # -1 is disabled, 0 logs all
statements
# and their durations, > 0 logs only
# statements running at least this
number
# of milliseconds
# - What to Log -
#debug_print_parse = off
#debug_print_rewritten = off
#debug_print_plan = off
#debug_pretty_print = on
#log_checkpoints = off
log_connections = on
log_disconnections = on
#log_duration = off
log_error_verbosity = verbose # terse, default, or verbose messages
#log_hostname = off
log_line_prefix = 'ts="%t"/>' # special values:
# %a = application name
# %u = user name
# %d = database name
# %r = remote host and port
# %h = remote host
# %p = process ID
# %t = timestamp without
milliseconds
# %m = timestamp with milliseconds
# %i = command tag
# %e = SQL state
# %c = session ID
# %l = session line number
# %s = session start timestamp
# %v = virtual transaction ID
# %x = transaction ID (0 if none)
# %q = stop here in non-session
# processes
# %% = '%'
# e.g. '<%u%%%d> '
#log_lock_waits = off # log lock waits >= deadlock_timeout
log_statement = 'all' # none, ddl, mod, all
#log_temp_files = -1 # log temporary files equal or
larger
# than the specified size in
kilobytes;
# -1 disables, 0 logs all temp files
log_timezone = 'UTC'
So, the main things I did:
add csvlog to log_destination;
enable logging_collector;
set log_min_duration_statement to 0 (to log all executed queries);
enable log_connections and log_disconnections;
set log_error_verbosity to verbose (to get the max fields in the csv logs)
set log_statement to all
Yet, when I run a simple query, like:
SELECT * FROM tests WHERE id='70';
I get:
2017-07-19 16:42:09.369
UTC,"postgres","postgres",11956,"::1:22927",596f89e1.2eb4,37,"idle",2017-07-19
16:33:37 UTC,2/20,0,LOG,00000,"statement: SELECT * FROM tests WHERE
id='70';",,,,,,,,"exec_simple_query,
src\backend\tcop\postgres.c:914","pgAdmin III - Query Tool"
2017-07-19 16:42:09.369
UTC,"postgres","postgres",11956,"::1:22927",596f89e1.2eb4,38,"SELECT",2017-07-19
16:33:37 UTC,2/0,0,LOG,00000,"duration: 0.000 ms",,,,,,,,"exec_simple_query,
src\backend\tcop\postgres.c:1142","pgAdmin III - Query Tool"
2017-07-19 16:42:09.416
UTC,"postgres","postgres",11956,"::1:22927",596f89e1.2eb4,39,"idle",2017-07-19
16:33:37 UTC,2/21,0,LOG,00000,"statement: SELECT format_type(oid,-1) as
typname FROM pg_type WHERE oid = 23",,,,,,,,"exec_simple_query,
src\backend\tcop\postgres.c:914","pgAdmin III - Query Tool"
2017-07-19 16:42:09.416
UTC,"postgres","postgres",11956,"::1:22927",596f89e1.2eb4,40,"SELECT",2017-07-19
16:33:37 UTC,2/0,0,LOG,00000,"duration: 0.000 ms",,,,,,,,"exec_simple_query,
src\backend\tcop\postgres.c:1142","pgAdmin III - Query Tool"
2017-07-19 16:42:09.416
UTC,"postgres","postgres",11956,"::1:22927",596f89e1.2eb4,41,"idle",2017-07-19
16:33:37 UTC,2/22,0,LOG,00000,"statement: SELECT CASE WHEN typbasetype=0
THEN oid else typbasetype END AS basetype
FROM pg_type WHERE oid=23",,,,,,,,"exec_simple_query,
src\backend\tcop\postgres.c:914","pgAdmin III - Query Tool"
2017-07-19 16:42:09.416
UTC,"postgres","postgres",11956,"::1:22927",596f89e1.2eb4,42,"SELECT",2017-07-19
16:33:37 UTC,2/0,0,LOG,00000,"duration: 0.000 ms",,,,,,,,"exec_simple_query,
src\backend\tcop\postgres.c:1142","pgAdmin III - Query Tool"
2017-07-19 16:42:09.416
UTC,"postgres","postgres",11956,"::1:22927",596f89e1.2eb4,43,"idle",2017-07-19
16:33:37 UTC,2/23,0,LOG,00000,"statement: SELECT format_type(oid,44) as
typname FROM pg_type WHERE oid = 1043",,,,,,,,"exec_simple_query,
src\backend\tcop\postgres.c:914","pgAdmin III - Query Tool"
2017-07-19 16:42:09.416
UTC,"postgres","postgres",11956,"::1:22927",596f89e1.2eb4,44,"SELECT",2017-07-19
16:33:37 UTC,2/0,0,LOG,00000,"duration: 0.000 ms",,,,,,,,"exec_simple_query,
src\backend\tcop\postgres.c:1142","pgAdmin III - Query Tool"
2017-07-19 16:42:09.416
UTC,"postgres","postgres",11956,"::1:22927",596f89e1.2eb4,45,"idle",2017-07-19
16:33:37 UTC,2/24,0,LOG,00000,"statement: SELECT CASE WHEN typbasetype=0
THEN oid else typbasetype END AS basetype
FROM pg_type WHERE oid=1043",,,,,,,,"exec_simple_query,
src\backend\tcop\postgres.c:914","pgAdmin III - Query Tool"
2017-07-19 16:42:09.416
UTC,"postgres","postgres",11956,"::1:22927",596f89e1.2eb4,46,"SELECT",2017-07-19
16:33:37 UTC,2/0,0,LOG,00000,"duration: 0.000 ms",,,,,,,,"exec_simple_query,
src\backend\tcop\postgres.c:1142","pgAdmin III - Query Tool"
Why is the first line, that has the query executed, saying that the command
tag is "idle", shouldn't it say "SELECT"? Is there any way to have a logged
line indicating the correct command tag and query in the proper columns? I
set the log_error_verbosity to verbose in order to get that information. Is
there any way to achieve what I want?
My postgres version is 9.4.
Thank you.
--
View this message in context: http://www.postgresql-archive.org/Postgres-csv-logging-tp5972017.html
Sent from the PostgreSQL - general mailing list archive at Nabble.com.
It is customary to indicate when you've posted the same question to other forums - in this case SO.
As the comment there says your config and your output seem at odds. Though I think your confusion is still adequately represented.
Why is the first line, that has the query executed, saying that the command
tag is "idle", shouldn't it say "SELECT"?
"Command tag: type of session's current command" - given your example I suppose this means "initial state of the session" as opposed to being a category tag of what the current line is doing. What you are seeing is "start at idle and parse" the incoming statement text. That is one action - parse. The subsequent action is "execute" the contents of the SELECT that is now in the active state of the session.
If the above is correct the docs could be more clear since I'd agree that your interpretation of the field seems more logical - though knowing initial state is quite useful in its own right.
David J.
Hi David, thank you for your reply.
David G Johnston wrote
> As the comment there says your config and your output seem at odds.
What I showed was the output present in the csv log, the output in the text
file log has the prefix that I indicated in the configration file.
Either way, I managed to "solve" my problem, I started playing with the
logging configurations and managed to get it working. I still have no clue
why a thing so basic isn't correctly implemented.
In a simple way, what I wanted to do was to configure postgres so it would
log all the queries and respective types in a file, like this
"SELECT * FROM test","SELECT"
"INSERT INTO test (id, time) VALUES ('123','1-1-2010')","INSERT"
...
Now, when checking the official documentation regarding postgres logging, I
noticed that the csv format had all the information I needed
(https://www.postgresql.org/docs/9.4/static/runtime-config-logging.html#RUNTIME-CONFIG-LOGGING-CSVLOG)
In theory, logging to a csv file would give a lot of information that would
be usefull to me, return code, query, command tag, etc... In practice, most
of the columns are missing... Not very usefull at all. I started playing
with the logging configuration and managed to have an output that I can use.
By setting the next variables:
log_min_duration_statement = 0
log_statement = 'none'
I managed to create an output with the actual command tag of the query
instead of the word "idle". Funny part, if I change the setting
log_statement to anything else than none, all the command tags are set to
"idle"... As I already said, fields are missing, for instance, I have no
query... I had to use some regex to get it from the message field, but it
should be present in the respective column, but it isn't.
Again, this is something that seems very simple to do... and I thinks its
also very usefull. Worst part is that it is documented, so why is not
possible to do such a trivial task??
--
View this message in context: http://www.postgresql-archive.org/Postgres-csv-logging-tp5972017p5972482.html
Sent from the PostgreSQL - general mailing list archive at Nabble.com.