Обсуждение: Cannot import logs from csv

Hello.

I've got a table set up on server B to store the logs from server A, as
outlined in
http://www.postgresql.org/docs/8.4/static/runtime-config-logging.html#RUNTIME-CONFIG-LOGGING-CSVLOG

The table is defined as follows:
postgres=# \d maincluster_log
                     Table "public.maincluster_log"
          Column         |            Type             | Modifiers
------------------------+-----------------------------+-----------
  log_time               | timestamp(3) with time zone |
  user_name              | text                        |
  database_name          | text                        |
  process_id             | integer                     |
  connection_from        | text                        |
  session_id             | text                        | not null
  session_line_num       | bigint                      | not null
  command_tag            | text                        |
  session_start_time     | timestamp with time zone    |
  virtual_transaction_id | text                        |
  transaction_id         | bigint                      |
  error_severity         | text                        |
  sql_state_code         | text                        |
  message                | text                        |
  detail                 | text                        |
  hint                   | text                        |
  internal_query         | text                        |
  internal_query_pos     | integer                     |
  context                | text                        |
  query                  | text                        |
  query_pos              | integer                     |
  location               | text                        |
Indexes:
     "pk_maincluster_log" PRIMARY KEY, btree (session_id, session_line_num)
     "ix_maincluster_log_databasename" btree (database_name)
     "ix_maincluster_log_logtime" btree (log_time) CLUSTER
     "ix_maincluster_log_sessionstarttime" btree (session_start_time)
     "ix_maincluster_log_username" btree (user_name)

Every day, I set \encoding SQL_ASCII on server B (server A is
SQL_ASCII) and use \copy with the csv flag to upload yesterday's log
file to the table.  For months, this has worked flawlessly until 12th
October.  The import failed with a message:
postgres=# \copy maincluster_log FROM maincluster-20131011.csv CSV
ERROR:  extra data after last expected column
CONTEXT:  COPY maincluster_log, line 424855: "2013-10-11 15:58:59.463
BST,"apachemitre","course_records",30875,"[local]",52581233.789b,3,"idle",20..."

The failing line, I will give at the end because it is long.

PostgreSQL version on both servers is 8.4, running on CentOS 6.3.

Please, does anyone have some insight into why this fails?

Helen Griffiths


Failing log line below this line:
2013-10-11 16:11:32.223
BST,"apachemitre","course_records",2335,"::1:33971",52581524.91f,3,"idle",2013-10-11
16:11:32 BST,1/57,0,LOG,00000,"statement: SELECT DISTINCT
tutbases.term_code AS term_code,
tb_groupmembers.student_id AS student_id,
length(tb_groupmembers.groupname) AS grouplen,
tb_groupmembers.groupname AS groupname,
tb_students.surname AS surname,
tb_students.initials AS initials,
tutbases.block AS block,
tt_sub_types.subtype AS subtype,
tt_sub_types.module_no AS modulecode,
tt_sub_types.type AS type,
tt_events.group_type AS grouptype,
tt_sub_types.long_name AS course
FROM
(tutbases INNER JOIN (((tb_options INNER JOIN tb_students
ON (tb_options.tutbase_id = tb_students.tutbase_id)
AND (tb_options.student_id = tb_students.student_id))
INNER JOIN tt_sub_types ON tb_options.module_no = tt_sub_types.module_no)
INNER JOIN tt_events ON (tt_sub_types.type = tt_events.type)
AND (tt_sub_types.subtype = tt_events.subtype))
ON (tutbases.term_code = tt_events.term_code)
AND (tutbases.block = tt_events.block)
AND (tutbases.id = tb_options.tutbase_id))
INNER JOIN tb_groupmembers
ON (tt_events.group_type = tb_groupmembers.grouptype)
AND (tb_options.student_id = tb_groupmembers.student_id)
AND (tb_options.tutbase_id = tb_groupmembers.tutbase_id)
AND (tutbases.id = tb_groupmembers.tutbase_id)
WHERE
(((tutbases.term_code)='201300')
AND ((tt_sub_types.subtype)='singa')
AND ((tt_sub_types.type)='T')

AND ((length(tb_groupmembers.subtype))=0)
AND ((tb_options.taken)='1')
AND ((tb_students.active)='1'))
UNION
SELECT DISTINCT
tutbases.term_code AS term_code,
tb_groupmembers.student_id AS student_id,
length(tb_groupmembers.groupname) AS grouplen,
tb_groupmembers.groupname AS groupname,
tb_students.surname AS surname,
tb_students.initials AS initials,
tutbases.block AS block,
tt_events.subtype AS subtype,
tt_sub_types.module_no AS modulecode,
tt_events.type AS type,
tb_groupmembers.grouptype AS grouptype,
tt_sub_types.long_name AS course
FROM
((((tutbases INNER JOIN tb_groupmembers
ON tutbases.id = tb_groupmembers.tutbase_id)
INNER JOIN tt_events ON (tb_groupmembers.grouptype = tt_events.group_type)
AND (tb_groupmembers.subtype = tt_events.subtype)
AND (tutbases.term_code = tt_events.term_code)
AND (tutbases.block = tt_events.block))
INNER JOIN tb_options ON (tb_groupmembers.student_id =
tb_options.student_id)
AND (tb_groupmembers.tutbase_id = tb_options.tutbase_id))
INNER JOIN tb_students ON (tb_options.student_id = tb_students.student_id)
AND (tb_options.tutbase_id = tb_students.tutbase_id))
INNER JOIN tt_sub_types ON (tt_events.type = tt_sub_types.type)
AND (tt_events.subtype = tt_sub_types.subtype)
AND (tb_options.module_no = tt_sub_types.module_no)
WHERE
(((tutbases.term_code)='201300')
AND ((tt_events.subtype)='singa')
AND ((tt_events.type)='T')
AND ((length(tb_groupmembers.groupname))>0)
AND ((tb_options.taken)='1')
AND ((tb_students.active)='1'))
UNION
SELECT DISTINCT
tutbases.term_code AS term_code,
tb_groupmembers.student_id AS student_id,
length(tb_groupmembers.groupname) AS grouplen,
tb_groupmembers.groupname AS groupname,
tb_students.surname AS surname,
tb_students.initials AS initials,
tutbases.block AS block,
tt_sub_types.subtype AS subtype,
tt_sub_types.module_no AS modulecode,
tt_sub_types.type AS type,
tb_groupmembers.grouptype AS grouptype,
tt_sub_types.long_name AS course
FROM
((((tutbases INNER JOIN tb_groupmembers
ON tutbases.id = tb_groupmembers.tutbase_id)
INNER JOIN tb_options ON (tb_groupmembers.student_id =
tb_options.student_id)
AND (tb_groupmembers.tutbase_id = tb_options.tutbase_id))
INNER JOIN tb_students ON (tb_options.student_id = tb_students.student_id)
AND (tb_options.tutbase_id = tb_students.tutbase_id))
INNER JOIN tt_sub_types ON tb_options.module_no = tt_sub_types.module_no)
INNER JOIN tt_events ON (tt_sub_types.subtype = tt_events.subtype)
AND (tt_sub_types.type = tt_events.type)
AND (tutbases.block = tt_events.block)
AND (tutbases.term_code = tt_events.term_code)
AND (tb_groupmembers.grouptype = tt_events.group_type)
WHERE
(((tutbases.term_code)='201300')
AND ((length(tb_groupmembers.groupname))>0)
AND ((tt_sub_types.subtype)='singa')
AND ((tt_sub_types.type)='T')
AND ((tb_groupmembers.grouptype)='TM')
AND ((tb_options.taken)='1')
AND ((tb_students.active)='1')
AND ((length(tb_groupmembers.subtype))=0))
ORDER BY
surname,
initials,
grouplen,
groupname",,,,,,,,

On 10/18/2013 08:07 AM, Helen Griffiths wrote:
> Hello.
>
> I've got a table set up on server B to store the logs from server A, as
> outlined in
> http://www.postgresql.org/docs/8.4/static/runtime-config-logging.html#RUNTIME-CONFIG-LOGGING-CSVLOG
>

>
> Every day, I set \encoding SQL_ASCII on server B (server A is SQL_ASCII)
> and use \copy with the csv flag to upload yesterday's log file to the
> table.  For months, this has worked flawlessly until 12th October.  The
> import failed with a message:
> postgres=# \copy maincluster_log FROM maincluster-20131011.csv CSV
> ERROR:  extra data after last expected column
> CONTEXT:  COPY maincluster_log, line 424855: "2013-10-11 15:58:59.463
> BST,"apachemitre","course_records",30875,"[local]",52581233.789b,3,"idle",20..."
>
>
> The failing line, I will give at the end because it is long.
>
> PostgreSQL version on both servers is 8.4, running on CentOS 6.3.
>
> Please, does anyone have some insight into why this fails?

This came up before recently in this thread:

http://www.postgresql.org/message-id/CADK3HHJNEWKD9gNyXmjv9ABbn+37rY3Mvp9=1j7msg9YpoBBBw@mail.gmail.com

To cut to the chase, in that case the OP found:

"Ok, I found the offending line. It was not the pgadmin line. There was
a line with a large binary insert."

Not sure if that helps.

>
> Helen Griffiths
>

--
Adrian Klaver
adrian.klaver@gmail.com

On Fri, 18 Oct 2013, Adrian Klaver wrote:

> This came up before recently in this thread:
>
> http://www.postgresql.org/message-id/CADK3HHJNEWKD9gNyXmjv9ABbn+37rY3Mvp9=1j7msg9YpoBBBw@mail.gmail.com
>
> To cut to the chase, in that case the OP found:
>
> "Ok, I found the offending line. It was not the pgadmin line. There was a
> line with a large binary insert."
>
> Not sure if that helps.

It might: there are then some lines like:
2013-10-11 02:44:26.164
BST,"postgres","course_records",19216,"[local]",525740b3.4b10,124887,"idle
in transaction",2013-10-11 01:05:07 BST,7/16388,0,LOG,00000,"fastpath
function call: ""loread"" (OID 954)",,,,,,,,

I suspect the ""loread"" is the offender.

Thanks to all for the help.  I would never have thought to suspect the
lines after the one given in the error message.

--
Helen Griffiths

Something else that causes a similar error is if the PostgreSQL daemon is restarted in the middle of logging a query.
Thelog line is truncated and the next log line starts straight after the truncated line without even a newline in
between. The problematic line can be many lines before where the import process shows an error. 

The last problem I found that shows this error is when control characters end up in your queries, usually because
someoneisn't validating their input >:-(  Putting the logfiles through "iconv -c -f UTF8 -t ASCII" seems to fix this. 

--
Helen Griffiths


> -----Original Message-----
> From: pgsql-general-owner@postgresql.org [mailto:pgsql-general-
> owner@postgresql.org] On Behalf Of Helen Griffiths
> Sent: 18 October 2013 18:27
> To: pgsql-general@postgresql.org
> Subject: Re: [GENERAL] Cannot import logs from csv
>
> On Fri, 18 Oct 2013, Adrian Klaver wrote:
>
> > This came up before recently in this thread:
> >
> > http://www.postgresql.org/message-
> id/CADK3HHJNEWKD9gNyXmjv9ABbn+37rY3M
> > vp9=1j7msg9YpoBBBw@mail.gmail.com
> >
> > To cut to the chase, in that case the OP found:
> >
> > "Ok, I found the offending line. It was not the pgadmin line. There
> > was a line with a large binary insert."
> >
> > Not sure if that helps.
>
> It might: there are then some lines like:
> 2013-10-11 02:44:26.164
> BST,"postgres","course_records",19216,"[local]",525740b3.4b10,124887,"idle
> in transaction",2013-10-11 01:05:07 BST,7/16388,0,LOG,00000,"fastpath
> function call: ""loread"" (OID 954)",,,,,,,,
>
> I suspect the ""loread"" is the offender.
>
> Thanks to all for the help.  I would never have thought to suspect the lines after
> the one given in the error message.
>
> --
> Helen Griffiths
>
>
> --
> Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
> To make changes to your subscription:
> http://www.postgresql.org/mailpref/pgsql-general