Обсуждение: [BUGS] BUG #14475: buffer overflow and segmentation fault

The following bug has been logged on the website:

Bug reference:      14475
Logged by:          Ivan Fabris
Email address:      fabris@colliniconsulting.it
PostgreSQL version: 9.6.1
Operating system:   Centos 7.2
Description:

Hi, not sure if the root cause is posgres or bulkload. All I have are lines
of log
The failed query runs ( usually ) regularly several time a day


< 2016-12-22 14:45:09.493 CET > LOG:  checkpoints are occurring too
frequently (15 seconds apart)
< 2016-12-22 14:45:09.493 CET > HINT:  Consider increasing the configuration
parameter "max_wal_size".
< 2016-12-22 14:45:32.299 CET > LOG:  checkpoints are occurring too
frequently (23 seconds apart)
< 2016-12-22 14:45:32.299 CET > HINT:  Consider increasing the configuration
parameter "max_wal_size".
*** buffer overflow detected ***: postgres: postgres DBNAME [local] SELECT
terminated
< 2016-12-22 14:46:31.665 CET > LOG:  server process (PID 4880) was
terminated by signal 11: Segmentation fault
< 2016-12-22 14:46:31.665 CET > DETAIL:  Failed process was running: SELECT
* FROM pg_bulkload(ARRAY['TYPE=TUPLE','INPUT=' ||
$1,'WRITER=DIRECT','OUTPUT=' || $2,'ON_DUPLICATE_KEEP=' ||
$3,'DUPLICATE_ERRORS=' || $4,'DUPLICATE_BADFILE=' || $5,'LOGFILE=' ||
$6,'VERBOSE=' || $7,'TRUNCATE=' || $8])
< 2016-12-22 14:46:31.665 CET > LOG:  terminating any other active server
processes
< 2016-12-22 14:46:31.666 CET > WARNING:  terminating connection because of
crash of another server process
< 2016-12-22 14:46:31.666 CET > DETAIL:  The postmaster has commanded this
server process to roll back the current transaction and exit, because
another server proce
ss exited abnormally and possibly corrupted shared memory.
< 2016-12-22 14:46:31.666 CET > HINT:  In a moment you should be able to
reconnect to the database and repeat your command.
< 2016-12-22 14:46:31.666 CET > WARNING:  terminating connection because of
crash of another server process
< 2016-12-22 14:46:31.666 CET > DETAIL:  The postmaster has commanded this
server process to roll back the current transaction and exit, because
another server proce
ss exited abnormally and possibly corrupted shared memory.

......

< 2016-12-22 14:46:31.680 CET > DETAIL:  The postmaster has commanded this
server process to roll back the current transaction and exit, because
another server proce
ss exited abnormally and possibly corrupted shared memory.
< 2016-12-22 14:46:31.680 CET > HINT:  In a moment you should be able to
reconnect to the database and repeat your command.
< 2016-12-22 14:46:31.733 CET > LOG:  all server processes terminated;
reinitializing
< 2016-12-22 14:46:31.819 CET > FATAL:  the database system is in recovery
mode
< 2016-12-22 14:46:31.819 CET > FATAL:  the database system is in recovery
mode
< 2016-12-22 14:46:31.821 CET > LOG:  database system was interrupted; last
known up at 2016-12-22 14:45:16 CET
< 2016-12-22 14:46:31.822 CET > FATAL:  the database system is in recovery
mode

......

< 2016-12-22 14:46:32.104 CET > FATAL:  the database system is in recovery
mode
< 2016-12-22 14:46:32.108 CET > FATAL:  the database system is in recovery
mode
< 2016-12-22 14:46:32.115 CET > FATAL:  the database system is in recovery
mode
< 2016-12-22 14:46:32.116 CET > FATAL:  the database system is in recovery
mode
< 2016-12-22 14:46:32.595 CET > LOG:  database system was not properly shut
down; automatic recovery in progress
< 2016-12-22 14:46:32.628 CET > LOG:  redo starts at 95/6411A058
< 2016-12-22 14:46:33.046 CET > FATAL:  the database system is in recovery
mode
< 2016-12-22 14:46:33.058 CET > FATAL:  the database system is in recovery
mode
< 2016-12-22 14:46:33.952 CET > FATAL:  the database system is in recovery
mode

         
< 2016-12-22 14:46:33.993 CET > FATAL:  the database system is in recovery
mode

         
< 2016-12-22 14:46:34.038 CET > FATAL:  the database system is in recovery
mode

         
< 2016-12-22 14:46:38.171 CET > FATAL:  the database system is in recovery
mode

         
< 2016-12-22 14:46:38.980 CET > FATAL:  the database system is in recovery
mode

         
< 2016-12-22 14:46:39.115 CET > FATAL:  the database system is in recovery
mode

         
< 2016-12-22 14:46:39.238 CET > FATAL:  the database system is in recovery
mode

         
< 2016-12-22 14:46:39.321 CET > FATAL:  the database system is in recovery
mode

         
< 2016-12-22 14:46:39.414 CET > FATAL:  the database system is in recovery
mode

         
< 2016-12-22 14:46:42.345 CET > FATAL:  the database system is in recovery
mode

         
< 2016-12-22 14:46:46.472 CET > FATAL:  the database system is in recovery
mode

         
< 2016-12-22 14:46:50.615 CET > FATAL:  the database system is in recovery
mode

         
< 2016-12-22 14:46:51.314 CET > LOG:  unexpected pageaddr 95/3CC86000 in log
segment 000000010000009500000085, offset 13131776

       
< 2016-12-22 14:46:51.314 CET > LOG:  redo done at 95/85C84BF0


       
< 2016-12-22 14:46:51.314 CET > LOG:  last completed transaction was at log
time 2016-12-22 14:46:27.036071+01

        
< 2016-12-22 14:46:52.816 CET > LOG:  MultiXact member wraparound
protections are now enabled

                  
< 2016-12-22 14:46:52.834 CET > LOG:  autovacuum launcher started


       
< 2016-12-22 14:46:52.834 CET > LOG:  database system is ready to accept
connections

           
*** buffer overflow detected ***: postgres: postgres DBNAME [local] SELECT
terminated

         
======= Backtrace: =========


       
/lib64/libc.so.6(__fortify_fail+0x37)[0x7feb01837597]


       
/lib64/libc.so.6(+0x10c750)[0x7feb01835750]
/lib64/libc.so.6(+0x10e507)[0x7feb01837507]
/usr/pgsql-9.6/lib/pg_bulkload.so(+0x15ef6)[0x7feaedc86ef6]
/usr/pgsql-9.6/lib/pg_bulkload.so(+0x12b8b)[0x7feaedc83b8b]
/usr/pgsql-9.6/lib/pg_bulkload.so(pg_bulkload+0x615)[0x7feaedc7f1a5]
< 2016-12-22 14:48:22.035 CET > LOG:  server process (PID 6849) was
terminated by signal 11: Segmentation fault
< 2016-12-22 14:48:22.035 CET > DETAIL:  Failed process was running: SELECT
* FROM pg_bulkload(ARRAY['TYPE=TUPLE','INPUT=' ||
$1,'WRITER=DIRECT','OUTPUT=' || $2,'ON_DUPLICATE_KEEP=' ||
$3,'DUPLICATE_ERRORS=' || $4,'DUPLICATE_BADFILE=' || $5,'LOGFILE=' ||
$6,'VERBOSE=' || $7,'TRUNCATE=' || $8])
< 2016-12-22 14:48:22.035 CET > LOG:  terminating any other active server
processes
< 2016-12-22 14:48:22.035 CET > WARNING:  terminating connection because of
crash of another server process
< 2016-12-22 14:48:22.035 CET > DETAIL:  The postmaster has commanded this
server process to roll back the current transaction and exit, because
another server process exited abnormally and possibly corrupted shared
memory.






--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

fabris@colliniconsulting.it writes:
> Hi, not sure if the root cause is posgres or bulkload. All I have are lines
> of log
> The failed query runs ( usually ) regularly several time a day

Can't do anything about this with this level of detail, although I'd
suggest that the backtrace tends to point the finger at pg_bulkload:

> /lib64/libc.so.6(__fortify_fail+0x37)[0x7feb01837597]
> /lib64/libc.so.6(+0x10c750)[0x7feb01835750]
> /lib64/libc.so.6(+0x10e507)[0x7feb01837507]
> /usr/pgsql-9.6/lib/pg_bulkload.so(+0x15ef6)[0x7feaedc86ef6]
> /usr/pgsql-9.6/lib/pg_bulkload.so(+0x12b8b)[0x7feaedc83b8b]
> /usr/pgsql-9.6/lib/pg_bulkload.so(pg_bulkload+0x615)[0x7feaedc7f1a5]

If you can get a more symbolic trace it would doubtless help the
pg_bulkload crew analyze this.  See advice about adding symbols at
https://wiki.postgresql.org/wiki/Getting_a_stack_trace_of_a_running_PostgreSQL_backend_on_Linux/BSD

            regards, tom lane


--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

On Sat, Dec 24, 2016 at 9:19 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> fabris@colliniconsulting.it writes:
>> Hi, not sure if the root cause is posgres or bulkload. All I have are lines
>> of log
>> The failed query runs ( usually ) regularly several time a day
>
> Can't do anything about this with this level of detail, although I'd
> suggest that the backtrace tends to point the finger at pg_bulkload:

Yes, it's possible that pg_bulkload may be the culprit.

Ivan, could you share the details by creating a GitHub issue:
https://github.com/ossc-db/pg_bulkload/issues

Thanks,
Amit


-- 
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

On Sat, Dec 24, 2016 at 7:54 AM,  <fabris@colliniconsulting.it> wrote:
> Hi, not sure if the root cause is posgres or bulkload. All I have are lines
> of log. The failed query runs ( usually ) regularly several time a day
>
> /lib64/libc.so.6(+0x10c750)[0x7feb01835750]
> /lib64/libc.so.6(+0x10e507)[0x7feb01837507]
> /usr/pgsql-9.6/lib/pg_bulkload.so(+0x15ef6)[0x7feaedc86ef6]
> /usr/pgsql-9.6/lib/pg_bulkload.so(+0x12b8b)[0x7feaedc83b8b]
> /usr/pgsql-9.6/lib/pg_bulkload.so(pg_bulkload+0x615)[0x7feaedc7f1a5]
> < 2016-12-22 14:48:22.035 CET > LOG:  server process (PID 6849) was
> terminated by signal 11: Segmentation fault

It seems to me that this is pointing to pg_bulkload code. You may want
to inform the maintainers here:
https://github.com/ossc-db/pg_bulkload/issues
-- 
Michael


-- 
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs