[pgpool-general: 1329] Re: hot recovery of a node

Gilbert Soucy gsoucy at 36pix.com
Fri Jan 18 21:27:32 JST 2013


> For this to happen, am I right to say that I need to rsync the files in
> pg_xlog (node 0) to my archive folder ( /thumbnails/postgres_archives/ )
on
> node 1 ? My stage 2 script does not do that right now.

No at all. Copying pg_xlog to archive folder should be done by
archive_command by PostgreSQL.



I do have an archive_command that will copy pg_xlog to my archive dir.
However, I have two different archive folders, one on each of the DB
servers. As a test, I ran an rsync from the archive folder on node0 to the
archive folder on node1 (at the end of pgpool_recovery_pitr) and my
recovery works fine now, including the transactions done during the
recovery. Now, I suppose I could/should have the archive folder on a
different server and have both node servers point to it to access that
common archive folder

Thanks for your help!

On Thu, Jan 17, 2013 at 6:14 PM, Tatsuo Ishii <ishii at postgresql.org> wrote:

> > Thank you for the reply.
> >
> > In the node 1 log, I dont find a "last completed transaction" line as you
> > have in your example.
>
> That's the cause of the problem. For your convenience, I attached my
> PostgreSQL log with "log_min_messages = debug5".
>
> I guess you don't have desired archive files in
> /thumbnails/postgres_archives/pg_log.  Are you sure that you have
> /thumbnails/postgres_archives/pg_log/00000002000000040000008D on node 1?
>
> I suggest double check your postgresql.conf setting on node 0. Here is
> mine(different from the default):
>
> listen_addresses = '*'
> port = 11000
> logging_collector = on
> log_filename = '%A.log'
> log_line_prefix = '%p %t '
> log_truncate_on_rotation = on
> log_statement = 'all'
> max_prepared_transactions = 10
> hot_standby = on
> wal_level = hot_standby
> max_wal_senders = 2
> log_connections = on
> log_disconnections = on
> archive_mode = on
> archive_command = 'test ! -f /home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/%f && cp %p /home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/%f'
> log_min_messages = debug5
>
> And also you should see log on node 0 something like this:
>
> 16362 2013-01-18 07:48:11 JST LOG:  pgpool_switch_xlog: waiting for
> "/home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/000000030000000100000025"
> 16362 2013-01-18 07:48:11 JST STATEMENT:  SELECT
> pgpool_switch_xlog('/home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir')
> 16168 2013-01-18 07:48:11 JST DEBUG:  executing archive command "test ! -f
> /home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/000000030000000100000025 && cp
> pg_xlog/000000030000000100000025 /home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/000000030000000100000025"
> 16168 2013-01-18 07:48:12 JST DEBUG:  archived transaction log file
> "000000030000000100000025"
> 16362 2013-01-18 07:48:12 JST DEBUG:  CommitTransactionCommand
> 16362 2013-01-18 07:48:12 JST DEBUG:  CommitTransaction
> 16362 2013-01-18 07:48:12 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
>                                   pgpool_switch_xlog
>
> --------------------------------------------------------------------------------------
>  /home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/000000030000000100000025
> (1 row)
>
> > For this to happen, am I right to say that I need to rsync the files in
> > pg_xlog (node 0) to my archive folder ( /thumbnails/postgres_archives/ )
> on
> > node 1 ? My stage 2 script does not do that right now.
>
> No at all. Copying pg_xlog to archive folder should be done by
> archive_command by PostgreSQL.
>
> > I am not completely comfortable with what the files in pg_xlog contain
> > exactly, at the various stages. Also, I find it strange that the log show
> > many "No such file or directory", even in your example.
>
> That's normal. PostgreSQL continues recoverying until requested file
> does not exist.
> --
> Tatsuo Ishii
> SRA OSS, Inc. Japan
> English: http://www.sraoss.co.jp/index_en.php
> Japanese: http://www.sraoss.co.jp
>
> > Thanks
> >
> > Gilbert
> >
> > ~~~~
> > LOg file for postgres on node 1 during recovery:
> >
> > 2013-01-16 19:50:20 EST : LOG:  database system was interrupted; last
> known
> > up at 2013-01-16 19:50:16 EST
> > 2013-01-16 19:50:20 EST : LOG:  starting archive recovery
> > 2013-01-16 19:50:20 EST : LOG:  restore_command = 'cp
> >  /thumbnails/postgres_archives/pg_log/%f %p'
> > 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp
> >  /thumbnails/postgres_archives/pg_log/00000002.history
> > pg_xlog/RECOVERYHISTORY"
> > cp: cannot stat `/thumbnails/postgres_archives/pg_log/00000002.history':
> No
> > such file or directory
> > 2013-01-16 19:50:20 EST : DEBUG:  could not restore file
> "00000002.history"
> > from archive: return code 256
> > 2013-01-16 19:50:20 EST : DEBUG:  history of timeline 2 is (i 2 1)
> > 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp
> >
>  /thumbnails/postgres_archives/pg_log/00000002000000040000008D.00000020.backup
> > pg_xlog/RECOVERY
> > HISTORY"
> > cp: cannot stat
> >
> `/thumbnails/postgres_archives/pg_log/00000002000000040000008D.00000020.backup':
> > No such file or directory
> > 2013-01-16 19:50:20 EST : DEBUG:  could not restore file
> > "00000002000000040000008D.00000020.backup" from archive: return code 256
> > 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp
> >  /thumbnails/postgres_archives/pg_log/00000002000000040000008D
> > pg_xlog/RECOVERYXLOG"
> > cp: cannot stat
> > `/thumbnails/postgres_archives/pg_log/00000002000000040000008D': No such
> > file or directory
> > 2013-01-16 19:50:20 EST : DEBUG:  could not restore file
> > "00000002000000040000008D" from archive: return code 256
> > 2013-01-16 19:50:20 EST : DEBUG:  checkpoint record is at 4/8D000020
> > 2013-01-16 19:50:20 EST : DEBUG:  redo record is at 4/8D000020; shutdown
> > FALSE
> > 2013-01-16 19:50:20 EST : DEBUG:  next transaction ID: 0/1625; next OID:
> > 17797
> > 2013-01-16 19:50:20 EST : DEBUG:  next MultiXactId: 1; next
> > MultiXactOffset: 0
> > 2013-01-16 19:50:20 EST : LOG:  automatic recovery in progress
> > 2013-01-16 19:50:20 EST : LOG:  record with zero length at 4/8D000068
> > 2013-01-16 19:50:20 EST : LOG:  redo is not required
> > 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp
> >  /thumbnails/postgres_archives/pg_log/00000002000000040000008D
> > pg_xlog/RECOVERYXLOG"
> > cp: cannot stat
> > `/thumbnails/postgres_archives/pg_log/00000002000000040000008D': No such
> > file or directory
> > 2013-01-16 19:50:20 EST : DEBUG:  could not restore file
> > "00000002000000040000008D" from archive: return code 256
> > 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp
> >  /thumbnails/postgres_archives/pg_log/00000003.history
> > pg_xlog/RECOVERYHISTORY"
> > 2013-01-16 19:50:20 EST : LOG:  restored log file "00000003.history" from
> > archive
> > 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp
> >  /thumbnails/postgres_archives/pg_log/00000004.history
> > pg_xlog/RECOVERYHISTORY"
> > 2013-01-16 19:50:20 EST : LOG:  restored log file "00000004.history" from
> > archive
> > 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp
> >  /thumbnails/postgres_archives/pg_log/00000005.history
> > pg_xlog/RECOVERYHISTORY"
> > 2013-01-16 19:50:20 EST : LOG:  restored log file "00000005.history" from
> > archive
> > 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp
> >  /thumbnails/postgres_archives/pg_log/00000006.history
> > pg_xlog/RECOVERYHISTORY"
> > cp: cannot stat `/thumbnails/postgres_archives/pg_log/00000006.history':
> No
> > such file or directory
> > 2013-01-16 19:50:20 EST : DEBUG:  could not restore file
> "00000006.history"
> > from archive: return code 256
> > 2013-01-16 19:50:20 EST : LOG:  selected new timeline ID: 6
> > 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp
> >  /thumbnails/postgres_archives/pg_log/00000002.history
> > pg_xlog/RECOVERYHISTORY"
> > cp: cannot stat `/thumbnails/postgres_archives/pg_log/00000002.history':
> No
> > such file or directory
> > 2013-01-16 19:50:20 EST : DEBUG:  could not restore file
> "00000002.history"
> > from archive: return code 256
> > 2013-01-16 19:50:20 EST : LOG:  archive recovery complete
> > 2013-01-16 19:50:20 EST : DEBUG:  recycled transaction log file
> > "00000002000000040000008C"
> > 2013-01-16 19:50:20 EST : DEBUG:  transaction ID wrap limit is
> 2147484295,
> > limited by database "template1"
> > 2013-01-16 19:50:20 EST : DEBUG:  shmem_exit(0): 3 callbacks to make
> > 2013-01-16 19:50:20 EST : DEBUG:  proc_exit(0): 2 callbacks to make
> > 2013-01-16 19:50:20 EST : DEBUG:  exit(0)
> > 2013-01-16 19:50:20 EST : DEBUG:  shmem_exit(-1): 0 callbacks to make
> > 2013-01-16 19:50:20 EST : DEBUG:  proc_exit(-1): 0 callbacks to make
> > 2013-01-16 19:50:20 EST : DEBUG:  reaping dead processes
> > 2013-01-16 19:50:20 EST : LOG:  autovacuum launcher started
> > 2013-01-16 19:50:20 EST : LOG:  database system is ready to accept
> > connections
> >
> >
> > On Wed, Jan 16, 2013 at 10:06 PM, Tatsuo Ishii <ishii at postgresql.org>
> wrote:
> >
> >> > Hello
> >> >
> >> > I hope this is the place whee I can ask general questions about
> pgpool. I
> >> > could not find a forum. Otheriwse, please let me know where I should
> go
> >> to
> >> > get help
> >>
> >> Yes, this is the perfect place to ask general questions about
> >> pgpool(there's no forum).
> >>
> >> > Here is my question:
> >> >
> >> > I am trying to setup pgpool II with 2 postgres nodes using replication
> >> and
> >> > load balancing. I have setup the watch dog to switch the virtual IP
> >> > automatically in case of failure. The 2 postgres nodes run on 2
> identical
> >> > computers.
> >> >
> >> > Everything works fine except for the recovery which I dont quite
> >> undestand.
> >> > I have installed and configured the scripts:
> >> >
> >> > basebackup.sh
> >> > pgpool_remote_start
> >> > pgpool_recovery_pitr
> >> >
> >> >
> >> > Then I simulate a failure : I shutdown one of the postgres nodes. This
> >> gets
> >> > detected fine and pgpool is still functional with the remaining node
> >> (which
> >> > can still accept connections).
> >> >
> >> > When I try to recover, it does not work as I expected. I thought that
> we
> >> > could recover *while pgpool keeps accepting requests*. (at least for
> >> stage
> >> > 1 of the recover). So, I simulated this by inserting a new line in a
> >> table
> >> > of my database just before the end of the basebackup.sh script  (just
> >> *after
> >> > * the rsync and *before* the pg_stop_backup() ).
> >> >
> >> > So, my basebackup.sh script looks like:
> >> > ~~~~~~~~~~
> >> >
> >> > ....
> >> >
> >> > *psql -U postgres -p 5432 -c "insert into users values (3000,
> 'def1');"
> >> > myDB      # this line was added to basebackup.sh to simulate a
> >> transaction
> >> > during a recover, stage 1      *
> >> >
> >> > psql -U postgres -p 5432 -c "SELECT pg_stop_backup()" postgres
> >> > ~~~~~~~~~~~~
> >> >
> >> > I then try to recover my failed node with:
> >> >
> >> > /usr/local/bin/pcp_recovery_node -d 15 192.168.0.110 9898 pgpool
> pgpool 1
> >> >
> >> > Which succeeds. However, when I look at the content of the databases,
> >> only
> >> > the master database has the new line  "3000  test" (purposely added
> in my
> >> > basebackup.sh script). The recovered database has all other lines but
> not
> >> > this one. So the recovery is not complete in my opinion (or I dont
> >> > understand what it is supposed to do).
> >> >
> >> > Am I wrong in expecting that this should work (i.e. after the recover,
> >> the
> >> > 2 database should be completely in sync) ?
> >>
> >> Works fine for me. I guess you have problem with archive recovery
> >> setting of PostgreSQL.
> >>
> >> Below is my recovered PostgreSQL log.  Do you find something like
> >> "restored log file "000000030000000100000021" from archive" in your
> >> PostgreSQL log(in your case DB node 1)?
> >>
> >> 31055 2013-01-17 11:38:14 JST LOG:  database system was interrupted;
> last
> >> known up at 2013-01-17 11:38:11 JST
> >> 31055 2013-01-17 11:38:14 JST LOG:  creating missing WAL directory
> >> "pg_xlog/archive_status"
> >> cp: cannot stat `/home/t-ishii/work/
> >> git.postgresql.org/test.repli/archivedir/00000003.history': No such
> file
> >> or directory
> >> 31055 2013-01-17 11:38:14 JST LOG:  starting archive recovery
> >> 31055 2013-01-17 11:38:14 JST LOG:  restored log file
> >> "000000030000000100000020" from archive
> >> 31055 2013-01-17 11:38:14 JST LOG:  redo starts at 1/20000020
> >> 31055 2013-01-17 11:38:14 JST LOG:  consistent recovery state reached at
> >> 1/21000000
> >> 31053 2013-01-17 11:38:14 JST LOG:  database system is ready to accept
> >> read only connections
> >> 31055 2013-01-17 11:38:14 JST LOG:  restored log file
> >> "000000030000000100000021" from archive
> >> cp: cannot stat `/home/t-ishii/work/
> >> git.postgresql.org/test.repli/archivedir/000000030000000100000022': No
> >> such file or directory
> >> 31055 2013-01-17 11:38:14 JST LOG:  could not open file
> >> "pg_xlog/000000030000000100000022" (log file 1, segment 34): No such
> file
> >> or directory
> >> 31055 2013-01-17 11:38:14 JST LOG:  redo done at 1/21000E48
> >> 31055 2013-01-17 11:38:14 JST LOG:  last completed transaction was at
> log
> >> time 2013-01-17 11:38:12.376859+09
> >> 31055 2013-01-17 11:38:14 JST LOG:  restored log file
> >> "000000030000000100000021" from archive
> >> cp: cannot stat `/home/t-ishii/work/
> >> git.postgresql.org/test.repli/archivedir/00000004.history': No such
> file
> >> or directory
> >> 31055 2013-01-17 11:38:14 JST LOG:  selected new timeline ID: 4
> >> cp: cannot stat `/home/t-ishii/work/
> >> git.postgresql.org/test.repli/archivedir/00000003.history': No such
> file
> >> or directory
> >> 31055 2013-01-17 11:38:15 JST LOG:  archive recovery complete
> >> 31053 2013-01-17 11:38:15 JST LOG:  database system is ready to accept
> >> connections
> >> 31067 2013-01-17 11:38:15 JST LOG:  autovacuum launcher started
> >> --
> >> Tatsuo Ishii
> >> SRA OSS, Inc. Japan
> >> English: http://www.sraoss.co.jp/index_en.php
> >> Japanese: http://www.sraoss.co.jp
> >>
>
> 15875 2013-01-18 07:44:08 JST LOG:  connection authorized: user=t-ishii
> database=test
> 15875 2013-01-18 07:44:11 JST LOG:  statement: SELECT n.nspname as
> "Schema",
>           c.relname as "Name",
>           CASE c.relkind WHEN 'r' THEN 'table' WHEN 'v' THEN 'view' WHEN
> 'i' THEN 'index' WHEN 'S' THEN 'sequence' WHEN 's' THEN 'special' WHEN 'f'
> THEN 'foreign table' END as "Type",
>           pg_catalog.pg_get_userbyid(c.relowner) as "Owner"
>         FROM pg_catalog.pg_class c
>              LEFT JOIN pg_catalog.pg_namespace n ON n.oid = c.relnamespace
>         WHERE c.relkind IN ('r','')
>               AND n.nspname <> 'pg_catalog'
>               AND n.nspname <> 'information_schema'
>               AND n.nspname !~ '^pg_toast'
>           AND pg_catalog.pg_table_is_visible(c.oid)
>         ORDER BY 1,2;
> 15875 2013-01-18 07:44:19 JST LOG:  statement: select * from t1;
> 15875 2013-01-18 07:44:21 JST LOG:  statement:  DISCARD ALL
> 15875 2013-01-18 07:44:24 JST LOG:  disconnection: session time:
> 0:00:16.148 user=t-ishii database=test host=[local]
> 31053 2013-01-18 07:44:27 JST LOG:  received fast shutdown request
> 31053 2013-01-18 07:44:27 JST LOG:  aborting any active transactions
> 31067 2013-01-18 07:44:27 JST LOG:  autovacuum launcher shutting down
> 31058 2013-01-18 07:44:27 JST LOG:  shutting down
> 31058 2013-01-18 07:44:27 JST LOG:  database system is shut down
> 16189 2013-01-18 07:47:26 JST LOG:  database system was shut down at
> 2013-01-18 07:44:27 JST
> 16189 2013-01-18 07:47:26 JST DEBUG:  history of timeline 4 is (i 4 3)
> 16189 2013-01-18 07:47:26 JST DEBUG:  checkpoint record is at 1/22000080
> 16189 2013-01-18 07:47:26 JST DEBUG:  redo record is at 1/22000080;
> shutdown TRUE
> 16189 2013-01-18 07:47:26 JST DEBUG:  next transaction ID: 0/438215; next
> OID: 305262
> 16189 2013-01-18 07:47:26 JST DEBUG:  next MultiXactId: 1; next
> MultiXactOffset: 0
> 16189 2013-01-18 07:47:26 JST DEBUG:  oldest unfrozen transaction ID: 686,
> in database 1
> 16189 2013-01-18 07:47:26 JST DEBUG:  transaction ID wrap limit is
> 2147484333, limited by database with OID 1
> 16189 2013-01-18 07:47:26 JST DEBUG:  shmem_exit(0): 4 callbacks to make
> 16189 2013-01-18 07:47:26 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 16189 2013-01-18 07:47:26 JST DEBUG:  exit(0)
> 16189 2013-01-18 07:47:26 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16189 2013-01-18 07:47:26 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16187 2013-01-18 07:47:26 JST DEBUG:  reaping dead processes
> 16190 2013-01-18 07:47:26 JST DEBUG:  checkpointer updated shared memory
> configuration values
> 16187 2013-01-18 07:47:26 JST LOG:  database system is ready to accept
> connections
> 16193 2013-01-18 07:47:26 JST LOG:  autovacuum launcher started
> 16193 2013-01-18 07:47:26 JST DEBUG:  InitPostgres
> 16193 2013-01-18 07:47:26 JST DEBUG:  my backend ID is 1
> 16193 2013-01-18 07:47:26 JST DEBUG:  StartTransaction
> 16193 2013-01-18 07:47:26 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16193 2013-01-18 07:47:26 JST DEBUG:  CommitTransaction
> 16193 2013-01-18 07:47:26 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16187 2013-01-18 07:47:27 JST DEBUG:  forked new backend, pid=16196
> socket=12
> 16196 2013-01-18 07:47:27 JST LOG:  connection received: host=[local]
> 16196 2013-01-18 07:47:27 JST DEBUG:  postgres child[16196]: starting with
> (
> 16196 2013-01-18 07:47:27 JST DEBUG:    postgres
> 16196 2013-01-18 07:47:27 JST DEBUG:    postgres
> 16196 2013-01-18 07:47:27 JST DEBUG:  )
> 16196 2013-01-18 07:47:27 JST DEBUG:  InitPostgres
> 16196 2013-01-18 07:47:27 JST DEBUG:  my backend ID is 2
> 16196 2013-01-18 07:47:27 JST DEBUG:  StartTransaction
> 16196 2013-01-18 07:47:27 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16196 2013-01-18 07:47:27 JST LOG:  connection authorized: user=t-ishii
> database=postgres
> 16196 2013-01-18 07:47:27 JST DEBUG:  CommitTransaction
> 16196 2013-01-18 07:47:27 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16196 2013-01-18 07:47:27 JST DEBUG:  shmem_exit(0): 7 callbacks to make
> 16196 2013-01-18 07:47:27 JST DEBUG:  proc_exit(0): 4 callbacks to make
> 16196 2013-01-18 07:47:27 JST LOG:  disconnection: session time:
> 0:00:00.005 user=t-ishii database=postgres host=[local]
> 16196 2013-01-18 07:47:27 JST DEBUG:  exit(0)
> 16196 2013-01-18 07:47:27 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16196 2013-01-18 07:47:27 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16187 2013-01-18 07:47:27 JST DEBUG:  reaping dead processes
> 16187 2013-01-18 07:47:27 JST DEBUG:  server process (PID 16196) exited
> with exit code 0
> 16187 2013-01-18 07:47:49 JST DEBUG:  postmaster received signal 2
> 16187 2013-01-18 07:47:49 JST LOG:  received fast shutdown request
> 16187 2013-01-18 07:47:49 JST LOG:  aborting any active transactions
> 16193 2013-01-18 07:47:49 JST LOG:  autovacuum launcher shutting down
> 16193 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(0): 7 callbacks to make
> 16193 2013-01-18 07:47:49 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 16193 2013-01-18 07:47:49 JST DEBUG:  exit(0)
> 16192 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(0): 4 callbacks to make
> 16191 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(0): 4 callbacks to make
> 16192 2013-01-18 07:47:49 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 16191 2013-01-18 07:47:49 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 16193 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16192 2013-01-18 07:47:49 JST DEBUG:  exit(0)
> 16193 2013-01-18 07:47:49 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16191 2013-01-18 07:47:49 JST DEBUG:  exit(0)
> 16192 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16192 2013-01-18 07:47:49 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16191 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16191 2013-01-18 07:47:49 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16187 2013-01-18 07:47:49 JST DEBUG:  reaping dead processes
> 16187 2013-01-18 07:47:49 JST DEBUG:  reaping dead processes
> 16190 2013-01-18 07:47:49 JST LOG:  shutting down
> 16190 2013-01-18 07:47:49 JST DEBUG:  SlruScanDirectory invoking callback
> on pg_multixact/offsets/0000
> 16190 2013-01-18 07:47:49 JST DEBUG:  SlruScanDirectory invoking callback
> on pg_multixact/members/0000
> 16190 2013-01-18 07:47:49 JST DEBUG:  attempting to remove WAL segments
> older than log file 000000040000000100000021
> 16190 2013-01-18 07:47:49 JST DEBUG:  SlruScanDirectory invoking callback
> on pg_subtrans/0006
> 16190 2013-01-18 07:47:49 JST LOG:  database system is shut down
> 16190 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(0): 4 callbacks to make
> 16190 2013-01-18 07:47:49 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 16190 2013-01-18 07:47:49 JST DEBUG:  exit(0)
> 16190 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16190 2013-01-18 07:47:49 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16187 2013-01-18 07:47:49 JST DEBUG:  reaping dead processes
> 16194 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16194 2013-01-18 07:47:49 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16187 2013-01-18 07:47:49 JST DEBUG:  reaping dead processes
> 16187 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(0): 3 callbacks to make
> 16187 2013-01-18 07:47:49 JST DEBUG:  proc_exit(0): 3 callbacks to make
> 16187 2013-01-18 07:47:49 JST DEBUG:  exit(0)
> 16187 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16187 2013-01-18 07:47:49 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16188 2013-01-18 07:47:49 JST DEBUG:  logger shutting down
> 16188 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(0): 0 callbacks to make
> 16188 2013-01-18 07:47:49 JST DEBUG:  proc_exit(0): 0 callbacks to make
> 16188 2013-01-18 07:47:49 JST DEBUG:  exit(0)
> 16188 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16188 2013-01-18 07:47:49 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16376 2013-01-18 07:48:13 JST LOG:  database system was interrupted; last
> known up at 2013-01-18 07:48:10 JST
> 16376 2013-01-18 07:48:13 JST LOG:  creating missing WAL directory
> "pg_xlog/archive_status"
> 16376 2013-01-18 07:48:13 JST DEBUG:  restore_command = 'cp
> /home/t-ishii/work/git.postgresql.org/test.repli/archivedir/%f %p'
> 16376 2013-01-18 07:48:13 JST DEBUG:  executing restore command "cp
> /home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/00000003.historypg_xlog/RECOVERYHISTORY"
> cp: cannot stat `/home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/00000003.history': No such file
> or directory
> 16376 2013-01-18 07:48:13 JST DEBUG:  could not restore file
> "00000003.history" from archive: return code 256
> 16376 2013-01-18 07:48:13 JST LOG:  starting archive recovery
> 16376 2013-01-18 07:48:13 JST DEBUG:  executing restore command "cp
> /home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/000000030000000100000024pg_xlog/RECOVERYXLOG"
> 16376 2013-01-18 07:48:13 JST LOG:  restored log file
> "000000030000000100000024" from archive
> 16376 2013-01-18 07:48:13 JST DEBUG:  got WAL segment from archive
> 16376 2013-01-18 07:48:13 JST DEBUG:  checkpoint record is at 1/24000058
> 16376 2013-01-18 07:48:13 JST DEBUG:  redo record is at 1/24000020;
> shutdown FALSE
> 16376 2013-01-18 07:48:13 JST DEBUG:  next transaction ID: 0/438215; next
> OID: 305262
> 16376 2013-01-18 07:48:13 JST DEBUG:  next MultiXactId: 1; next
> MultiXactOffset: 0
> 16376 2013-01-18 07:48:13 JST DEBUG:  oldest unfrozen transaction ID: 686,
> in database 1
> 16376 2013-01-18 07:48:13 JST DEBUG:  transaction ID wrap limit is
> 2147484333, limited by database with OID 1
> 16376 2013-01-18 07:48:13 JST DEBUG:  resetting unlogged relations:
> cleanup 1 init 0
> 16376 2013-01-18 07:48:13 JST DEBUG:  initializing for hot standby
> 16376 2013-01-18 07:48:13 JST DEBUG:  my backend ID is 1
> 16376 2013-01-18 07:48:13 JST LOG:  redo starts at 1/24000020
> 16376 2013-01-18 07:48:13 JST DEBUG:  prune KnownAssignedXids to 438215
> 16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo  running xacts: nextXid
> 438215 latestCompletedXid 438214 oldestRunningXid 438215
> 16376 2013-01-18 07:48:13 JST DEBUG:  0 KnownAssignedXids (num=0 tail=0
> head=0)
> 16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo  running xacts: nextXid
> 438215 latestCompletedXid 438214 oldestRunningXid 438215
> 16376 2013-01-18 07:48:13 JST DEBUG:  recovery snapshots are now enabled
> 16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo  running xacts: nextXid
> 438215 latestCompletedXid 438214 oldestRunningXid 438215
> 16376 2013-01-18 07:48:13 JST DEBUG:  record known xact 438215
> latestObservedXid 438214
> 16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo insert: rel
> 1663/16389/305218; tid 0/18
> 16376 2013-01-18 07:48:13 JST DEBUG:  record known xact 438215
> latestObservedXid 438215
> 16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo commit: 2013-01-18
> 07:48:10.799457+09
> 16376 2013-01-18 07:48:13 JST DEBUG:  record known xact 438215
> latestObservedXid 438215
> 16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo commit: 2013-01-18
> 07:48:10.799457+09
> 16376 2013-01-18 07:48:13 JST DEBUG:  remove KnownAssignedXid 438215
> 16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo commit: 2013-01-18
> 07:48:10.799457+09
> 16376 2013-01-18 07:48:13 JST DEBUG:  end of backup reached
> 16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo backup end: 1/24000020
> 16379 2013-01-18 07:48:13 JST DEBUG:  checkpointer updated shared memory
> configuration values
> 16376 2013-01-18 07:48:13 JST LOG:  consistent recovery state reached at
> 1/25000000
> 16376 2013-01-18 07:48:13 JST DEBUG:  executing restore command "cp
> /home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/000000030000000100000025pg_xlog/RECOVERYXLOG"
> 16374 2013-01-18 07:48:13 JST LOG:  database system is ready to accept
> read only connections
> 16376 2013-01-18 07:48:13 JST LOG:  restored log file
> "000000030000000100000025" from archive
> 16376 2013-01-18 07:48:13 JST DEBUG:  got WAL segment from archive
> 16376 2013-01-18 07:48:13 JST DEBUG:  prune KnownAssignedXids to 438216
> 16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo  running xacts: nextXid
> 438216 latestCompletedXid 438215 oldestRunningXid 438216
> 16376 2013-01-18 07:48:13 JST DEBUG:  executing restore command "cp
> /home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/000000030000000100000026pg_xlog/RECOVERYXLOG"
> cp: cannot stat `/home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/000000030000000100000026': No
> such file or directory
> 16376 2013-01-18 07:48:13 JST DEBUG:  could not restore file
> "000000030000000100000026" from archive: return code 256
> 16376 2013-01-18 07:48:13 JST LOG:  could not open file
> "pg_xlog/000000030000000100000026" (log file 1, segment 38): No such file
> or directory
> 16376 2013-01-18 07:48:13 JST LOG:  redo done at 1/25000E48
> 16376 2013-01-18 07:48:13 JST LOG:  last completed transaction was at log
> time 2013-01-18 07:48:10.799457+09
> 16376 2013-01-18 07:48:13 JST DEBUG:  executing restore command "cp
> /home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/000000030000000100000025pg_xlog/RECOVERYXLOG"
> 16376 2013-01-18 07:48:13 JST LOG:  restored log file
> "000000030000000100000025" from archive
> 16376 2013-01-18 07:48:13 JST DEBUG:  got WAL segment from archive
> 16376 2013-01-18 07:48:13 JST DEBUG:  executing restore command "cp
> /home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/00000004.historypg_xlog/RECOVERYHISTORY"
> cp: cannot stat `/home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/00000004.history': No such file
> or directory
> 16376 2013-01-18 07:48:13 JST DEBUG:  could not restore file
> "00000004.history" from archive: return code 256
> 16376 2013-01-18 07:48:13 JST LOG:  selected new timeline ID: 4
> 16376 2013-01-18 07:48:13 JST DEBUG:  executing restore command "cp
> /home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/00000003.historypg_xlog/RECOVERYHISTORY"
> cp: cannot stat `/home/t-ishii/work/
> git.postgresql.org/test.repli/archivedir/00000003.history': No such file
> or directory
> 16376 2013-01-18 07:48:13 JST DEBUG:  could not restore file
> "00000003.history" from archive: return code 256
> 16376 2013-01-18 07:48:13 JST DEBUG:  updated min recovery point to
> 1/26000000
> 16376 2013-01-18 07:48:13 JST LOG:  archive recovery complete
> 16379 2013-01-18 07:48:13 JST DEBUG:  creating and filling new WAL file
> 16379 2013-01-18 07:48:13 JST DEBUG:  done creating and filling new WAL
> file
> 16379 2013-01-18 07:48:13 JST DEBUG:  attempting to remove WAL segments
> older than log file 000000040000000100000023
> 16376 2013-01-18 07:48:13 JST DEBUG:  resetting unlogged relations:
> cleanup 0 init 1
> 16376 2013-01-18 07:48:13 JST DEBUG:  removing all KnownAssignedXids
> 16376 2013-01-18 07:48:13 JST DEBUG:  release all standby locks
> 16376 2013-01-18 07:48:13 JST DEBUG:  shmem_exit(0): 5 callbacks to make
> 16376 2013-01-18 07:48:13 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 16376 2013-01-18 07:48:13 JST DEBUG:  exit(0)
> 16376 2013-01-18 07:48:13 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16376 2013-01-18 07:48:13 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 07:48:13 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 07:48:13 JST LOG:  database system is ready to accept
> connections
> 16388 2013-01-18 07:48:13 JST LOG:  autovacuum launcher started
> 16388 2013-01-18 07:48:13 JST DEBUG:  InitPostgres
> 16388 2013-01-18 07:48:13 JST DEBUG:  my backend ID is 1
> 16388 2013-01-18 07:48:13 JST DEBUG:  StartTransaction
> 16388 2013-01-18 07:48:13 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 07:48:13 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 07:48:13 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16374 2013-01-18 07:48:14 JST DEBUG:  forked new backend, pid=16394
> socket=10
> 16394 2013-01-18 07:48:14 JST LOG:  connection received: host=[local]
> 16394 2013-01-18 07:48:14 JST DEBUG:  postgres child[16394]: starting with
> (
> 16394 2013-01-18 07:48:14 JST DEBUG:    postgres
> 16394 2013-01-18 07:48:14 JST DEBUG:    postgres
> 16394 2013-01-18 07:48:14 JST DEBUG:  )
> 16394 2013-01-18 07:48:14 JST DEBUG:  InitPostgres
> 16394 2013-01-18 07:48:14 JST DEBUG:  my backend ID is 2
> 16394 2013-01-18 07:48:14 JST DEBUG:  StartTransaction
> 16394 2013-01-18 07:48:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16394 2013-01-18 07:48:14 JST LOG:  connection authorized: user=t-ishii
> database=postgres
> 16394 2013-01-18 07:48:14 JST DEBUG:  CommitTransaction
> 16394 2013-01-18 07:48:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16394 2013-01-18 07:48:14 JST DEBUG:  shmem_exit(0): 7 callbacks to make
> 16394 2013-01-18 07:48:14 JST DEBUG:  proc_exit(0): 4 callbacks to make
> 16394 2013-01-18 07:48:14 JST LOG:  disconnection: session time:
> 0:00:00.008 user=t-ishii database=postgres host=[local]
> 16394 2013-01-18 07:48:14 JST DEBUG:  exit(0)
> 16394 2013-01-18 07:48:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16394 2013-01-18 07:48:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 07:48:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 07:48:14 JST DEBUG:  server process (PID 16394) exited
> with exit code 0
> 16374 2013-01-18 07:48:15 JST DEBUG:  forked new backend, pid=16404
> socket=10
> 16404 2013-01-18 07:48:15 JST LOG:  connection received: host=[local]
> 16404 2013-01-18 07:48:15 JST DEBUG:  postgres child[16404]: starting with
> (
> 16404 2013-01-18 07:48:15 JST DEBUG:    postgres
> 16404 2013-01-18 07:48:15 JST DEBUG:    postgres
> 16404 2013-01-18 07:48:15 JST DEBUG:  )
> 16404 2013-01-18 07:48:15 JST DEBUG:  InitPostgres
> 16404 2013-01-18 07:48:15 JST DEBUG:  my backend ID is 2
> 16404 2013-01-18 07:48:15 JST DEBUG:  StartTransaction
> 16404 2013-01-18 07:48:15 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16404 2013-01-18 07:48:15 JST LOG:  connection authorized: user=t-ishii
> database=postgres
> 16404 2013-01-18 07:48:15 JST DEBUG:  CommitTransaction
> 16404 2013-01-18 07:48:15 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16404 2013-01-18 07:48:16 JST DEBUG:  shmem_exit(0): 7 callbacks to make
> 16404 2013-01-18 07:48:16 JST DEBUG:  proc_exit(0): 4 callbacks to make
> 16404 2013-01-18 07:48:16 JST LOG:  disconnection: session time:
> 0:00:00.004 user=t-ishii database=postgres host=[local]
> 16404 2013-01-18 07:48:16 JST DEBUG:  exit(0)
> 16404 2013-01-18 07:48:16 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16404 2013-01-18 07:48:16 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 07:48:16 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 07:48:16 JST DEBUG:  server process (PID 16404) exited
> with exit code 0
> 16388 2013-01-18 07:49:13 JST DEBUG:  StartTransaction
> 16388 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 07:49:13 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 07:49:13 JST DEBUG:  StartTransaction
> 16388 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 07:49:13 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16509 2013-01-18 07:49:13 JST DEBUG:  InitPostgres
> 16509 2013-01-18 07:49:13 JST DEBUG:  my backend ID is 2
> 16509 2013-01-18 07:49:13 JST DEBUG:  StartTransaction
> 16509 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16509 2013-01-18 07:49:13 JST DEBUG:  CommitTransaction
> 16509 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16509 2013-01-18 07:49:13 JST DEBUG:  autovacuum: processing database
> "postgres"
> 16509 2013-01-18 07:49:13 JST DEBUG:  StartTransaction
> 16509 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16509 2013-01-18 07:49:13 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 16509 2013-01-18 07:49:13 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 16509 2013-01-18 07:49:13 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 16509 2013-01-18 07:49:13 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 16509 2013-01-18 07:49:13 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 16509 2013-01-18 07:49:13 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 16509 2013-01-18 07:49:13 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 16509 2013-01-18 07:49:13 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 16509 2013-01-18 07:49:13 JST DEBUG:  CommitTransaction
> 16509 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16509 2013-01-18 07:49:13 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 16509 2013-01-18 07:49:13 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 16509 2013-01-18 07:49:13 JST DEBUG:  exit(0)
> 16509 2013-01-18 07:49:13 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16509 2013-01-18 07:49:13 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 07:49:13 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 07:49:13 JST DEBUG:  server process (PID 16509) exited
> with exit code 0
> 16388 2013-01-18 07:50:13 JST DEBUG:  StartTransaction
> 16388 2013-01-18 07:50:13 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 07:50:13 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 07:50:13 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16596 2013-01-18 07:50:13 JST DEBUG:  InitPostgres
> 16596 2013-01-18 07:50:13 JST DEBUG:  my backend ID is 2
> 16596 2013-01-18 07:50:13 JST DEBUG:  StartTransaction
> 16596 2013-01-18 07:50:13 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16596 2013-01-18 07:50:13 JST DEBUG:  CommitTransaction
> 16596 2013-01-18 07:50:13 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16596 2013-01-18 07:50:13 JST DEBUG:  autovacuum: processing database
> "postgres"
> 16596 2013-01-18 07:50:13 JST DEBUG:  StartTransaction
> 16596 2013-01-18 07:50:13 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16596 2013-01-18 07:50:13 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 16596 2013-01-18 07:50:13 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 16596 2013-01-18 07:50:13 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 16596 2013-01-18 07:50:13 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 16596 2013-01-18 07:50:13 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 16596 2013-01-18 07:50:13 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 16596 2013-01-18 07:50:13 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 16596 2013-01-18 07:50:13 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 16596 2013-01-18 07:50:13 JST DEBUG:  CommitTransaction
> 16596 2013-01-18 07:50:13 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16596 2013-01-18 07:50:13 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 16596 2013-01-18 07:50:13 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 16596 2013-01-18 07:50:13 JST DEBUG:  exit(0)
> 16596 2013-01-18 07:50:13 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16596 2013-01-18 07:50:13 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 07:50:13 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 07:50:13 JST DEBUG:  server process (PID 16596) exited
> with exit code 0
> 16388 2013-01-18 07:51:13 JST DEBUG:  StartTransaction
> 16388 2013-01-18 07:51:13 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 07:51:13 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 07:51:13 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16682 2013-01-18 07:51:13 JST DEBUG:  InitPostgres
> 16682 2013-01-18 07:51:13 JST DEBUG:  my backend ID is 2
> 16682 2013-01-18 07:51:13 JST DEBUG:  StartTransaction
> 16682 2013-01-18 07:51:13 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16682 2013-01-18 07:51:13 JST DEBUG:  CommitTransaction
> 16682 2013-01-18 07:51:13 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16682 2013-01-18 07:51:13 JST DEBUG:  autovacuum: processing database
> "postgres"
> 16682 2013-01-18 07:51:13 JST DEBUG:  StartTransaction
> 16682 2013-01-18 07:51:13 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16682 2013-01-18 07:51:13 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 16682 2013-01-18 07:51:13 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 16682 2013-01-18 07:51:13 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 16682 2013-01-18 07:51:13 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 16682 2013-01-18 07:51:13 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 16682 2013-01-18 07:51:13 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 16682 2013-01-18 07:51:13 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 16682 2013-01-18 07:51:13 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 16682 2013-01-18 07:51:13 JST DEBUG:  CommitTransaction
> 16682 2013-01-18 07:51:13 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16682 2013-01-18 07:51:13 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 16682 2013-01-18 07:51:13 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 16682 2013-01-18 07:51:13 JST DEBUG:  exit(0)
> 16682 2013-01-18 07:51:13 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16682 2013-01-18 07:51:13 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 07:51:13 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 07:51:13 JST DEBUG:  server process (PID 16682) exited
> with exit code 0
> 16388 2013-01-18 07:52:13 JST DEBUG:  StartTransaction
> 16388 2013-01-18 07:52:13 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 07:52:13 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 07:52:13 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16767 2013-01-18 07:52:13 JST DEBUG:  InitPostgres
> 16767 2013-01-18 07:52:13 JST DEBUG:  my backend ID is 2
> 16767 2013-01-18 07:52:13 JST DEBUG:  StartTransaction
> 16767 2013-01-18 07:52:13 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16767 2013-01-18 07:52:13 JST DEBUG:  CommitTransaction
> 16767 2013-01-18 07:52:13 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16767 2013-01-18 07:52:13 JST DEBUG:  autovacuum: processing database
> "postgres"
> 16767 2013-01-18 07:52:14 JST DEBUG:  StartTransaction
> 16767 2013-01-18 07:52:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16767 2013-01-18 07:52:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 16767 2013-01-18 07:52:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 16767 2013-01-18 07:52:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 16767 2013-01-18 07:52:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 16767 2013-01-18 07:52:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 16767 2013-01-18 07:52:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 16767 2013-01-18 07:52:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 16767 2013-01-18 07:52:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 16767 2013-01-18 07:52:14 JST DEBUG:  CommitTransaction
> 16767 2013-01-18 07:52:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16767 2013-01-18 07:52:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 16767 2013-01-18 07:52:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 16767 2013-01-18 07:52:14 JST DEBUG:  exit(0)
> 16767 2013-01-18 07:52:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16767 2013-01-18 07:52:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 07:52:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 07:52:14 JST DEBUG:  server process (PID 16767) exited
> with exit code 0
> 16388 2013-01-18 07:53:14 JST DEBUG:  StartTransaction
> 16388 2013-01-18 07:53:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 07:53:14 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 07:53:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16849 2013-01-18 07:53:14 JST DEBUG:  InitPostgres
> 16849 2013-01-18 07:53:14 JST DEBUG:  my backend ID is 2
> 16849 2013-01-18 07:53:14 JST DEBUG:  StartTransaction
> 16849 2013-01-18 07:53:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16849 2013-01-18 07:53:14 JST DEBUG:  CommitTransaction
> 16849 2013-01-18 07:53:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16849 2013-01-18 07:53:14 JST DEBUG:  autovacuum: processing database
> "postgres"
> 16849 2013-01-18 07:53:14 JST DEBUG:  StartTransaction
> 16849 2013-01-18 07:53:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16849 2013-01-18 07:53:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 16849 2013-01-18 07:53:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 16849 2013-01-18 07:53:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 16849 2013-01-18 07:53:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 16849 2013-01-18 07:53:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 16849 2013-01-18 07:53:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 16849 2013-01-18 07:53:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 16849 2013-01-18 07:53:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 16849 2013-01-18 07:53:14 JST DEBUG:  CommitTransaction
> 16849 2013-01-18 07:53:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16849 2013-01-18 07:53:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 16849 2013-01-18 07:53:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 16849 2013-01-18 07:53:14 JST DEBUG:  exit(0)
> 16849 2013-01-18 07:53:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16849 2013-01-18 07:53:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 07:53:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 07:53:14 JST DEBUG:  server process (PID 16849) exited
> with exit code 0
> 16388 2013-01-18 07:54:14 JST DEBUG:  StartTransaction
> 16388 2013-01-18 07:54:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 07:54:14 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 07:54:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16934 2013-01-18 07:54:14 JST DEBUG:  InitPostgres
> 16934 2013-01-18 07:54:14 JST DEBUG:  my backend ID is 2
> 16934 2013-01-18 07:54:14 JST DEBUG:  StartTransaction
> 16934 2013-01-18 07:54:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16934 2013-01-18 07:54:14 JST DEBUG:  CommitTransaction
> 16934 2013-01-18 07:54:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16934 2013-01-18 07:54:14 JST DEBUG:  autovacuum: processing database
> "postgres"
> 16934 2013-01-18 07:54:14 JST DEBUG:  StartTransaction
> 16934 2013-01-18 07:54:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16934 2013-01-18 07:54:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 16934 2013-01-18 07:54:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 16934 2013-01-18 07:54:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 16934 2013-01-18 07:54:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 16934 2013-01-18 07:54:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 16934 2013-01-18 07:54:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 16934 2013-01-18 07:54:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 16934 2013-01-18 07:54:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 16934 2013-01-18 07:54:14 JST DEBUG:  CommitTransaction
> 16934 2013-01-18 07:54:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16934 2013-01-18 07:54:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 16934 2013-01-18 07:54:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 16934 2013-01-18 07:54:14 JST DEBUG:  exit(0)
> 16934 2013-01-18 07:54:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 16934 2013-01-18 07:54:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 07:54:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 07:54:14 JST DEBUG:  server process (PID 16934) exited
> with exit code 0
> 16388 2013-01-18 07:55:14 JST DEBUG:  StartTransaction
> 16388 2013-01-18 07:55:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 07:55:14 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 07:55:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17019 2013-01-18 07:55:14 JST DEBUG:  InitPostgres
> 17019 2013-01-18 07:55:14 JST DEBUG:  my backend ID is 2
> 17019 2013-01-18 07:55:14 JST DEBUG:  StartTransaction
> 17019 2013-01-18 07:55:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17019 2013-01-18 07:55:14 JST DEBUG:  CommitTransaction
> 17019 2013-01-18 07:55:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17019 2013-01-18 07:55:14 JST DEBUG:  autovacuum: processing database
> "postgres"
> 17019 2013-01-18 07:55:14 JST DEBUG:  StartTransaction
> 17019 2013-01-18 07:55:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17019 2013-01-18 07:55:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17019 2013-01-18 07:55:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 17019 2013-01-18 07:55:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 17019 2013-01-18 07:55:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 17019 2013-01-18 07:55:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 17019 2013-01-18 07:55:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 17019 2013-01-18 07:55:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17019 2013-01-18 07:55:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 17019 2013-01-18 07:55:14 JST DEBUG:  CommitTransaction
> 17019 2013-01-18 07:55:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17019 2013-01-18 07:55:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 17019 2013-01-18 07:55:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 17019 2013-01-18 07:55:14 JST DEBUG:  exit(0)
> 17019 2013-01-18 07:55:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 17019 2013-01-18 07:55:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 07:55:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 07:55:14 JST DEBUG:  server process (PID 17019) exited
> with exit code 0
> 16388 2013-01-18 07:56:14 JST DEBUG:  StartTransaction
> 16388 2013-01-18 07:56:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 07:56:14 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 07:56:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17106 2013-01-18 07:56:14 JST DEBUG:  InitPostgres
> 17106 2013-01-18 07:56:14 JST DEBUG:  my backend ID is 2
> 17106 2013-01-18 07:56:14 JST DEBUG:  StartTransaction
> 17106 2013-01-18 07:56:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17106 2013-01-18 07:56:14 JST DEBUG:  CommitTransaction
> 17106 2013-01-18 07:56:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17106 2013-01-18 07:56:14 JST DEBUG:  autovacuum: processing database
> "postgres"
> 17106 2013-01-18 07:56:14 JST DEBUG:  StartTransaction
> 17106 2013-01-18 07:56:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17106 2013-01-18 07:56:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17106 2013-01-18 07:56:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 17106 2013-01-18 07:56:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 17106 2013-01-18 07:56:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 17106 2013-01-18 07:56:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 17106 2013-01-18 07:56:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 17106 2013-01-18 07:56:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17106 2013-01-18 07:56:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 17106 2013-01-18 07:56:14 JST DEBUG:  CommitTransaction
> 17106 2013-01-18 07:56:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17106 2013-01-18 07:56:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 17106 2013-01-18 07:56:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 17106 2013-01-18 07:56:14 JST DEBUG:  exit(0)
> 17106 2013-01-18 07:56:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 17106 2013-01-18 07:56:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 07:56:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 07:56:14 JST DEBUG:  server process (PID 17106) exited
> with exit code 0
> 16388 2013-01-18 07:57:14 JST DEBUG:  StartTransaction
> 16388 2013-01-18 07:57:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 07:57:14 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 07:57:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17190 2013-01-18 07:57:14 JST DEBUG:  InitPostgres
> 17190 2013-01-18 07:57:14 JST DEBUG:  my backend ID is 2
> 17190 2013-01-18 07:57:14 JST DEBUG:  StartTransaction
> 17190 2013-01-18 07:57:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17190 2013-01-18 07:57:14 JST DEBUG:  CommitTransaction
> 17190 2013-01-18 07:57:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17190 2013-01-18 07:57:14 JST DEBUG:  autovacuum: processing database
> "postgres"
> 17190 2013-01-18 07:57:14 JST DEBUG:  StartTransaction
> 17190 2013-01-18 07:57:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17190 2013-01-18 07:57:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17190 2013-01-18 07:57:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 17190 2013-01-18 07:57:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 17190 2013-01-18 07:57:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 17190 2013-01-18 07:57:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 17190 2013-01-18 07:57:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 17190 2013-01-18 07:57:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17190 2013-01-18 07:57:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 17190 2013-01-18 07:57:14 JST DEBUG:  CommitTransaction
> 17190 2013-01-18 07:57:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17190 2013-01-18 07:57:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 17190 2013-01-18 07:57:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 17190 2013-01-18 07:57:14 JST DEBUG:  exit(0)
> 17190 2013-01-18 07:57:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 17190 2013-01-18 07:57:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 07:57:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 07:57:14 JST DEBUG:  server process (PID 17190) exited
> with exit code 0
> 16388 2013-01-18 07:58:14 JST DEBUG:  StartTransaction
> 16388 2013-01-18 07:58:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 07:58:14 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 07:58:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17271 2013-01-18 07:58:14 JST DEBUG:  InitPostgres
> 17271 2013-01-18 07:58:14 JST DEBUG:  my backend ID is 2
> 17271 2013-01-18 07:58:14 JST DEBUG:  StartTransaction
> 17271 2013-01-18 07:58:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17271 2013-01-18 07:58:14 JST DEBUG:  CommitTransaction
> 17271 2013-01-18 07:58:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17271 2013-01-18 07:58:14 JST DEBUG:  autovacuum: processing database
> "postgres"
> 17271 2013-01-18 07:58:14 JST DEBUG:  StartTransaction
> 17271 2013-01-18 07:58:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17271 2013-01-18 07:58:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17271 2013-01-18 07:58:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 17271 2013-01-18 07:58:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 17271 2013-01-18 07:58:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 17271 2013-01-18 07:58:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 17271 2013-01-18 07:58:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 17271 2013-01-18 07:58:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17271 2013-01-18 07:58:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 17271 2013-01-18 07:58:14 JST DEBUG:  CommitTransaction
> 17271 2013-01-18 07:58:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17271 2013-01-18 07:58:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 17271 2013-01-18 07:58:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 17271 2013-01-18 07:58:14 JST DEBUG:  exit(0)
> 17271 2013-01-18 07:58:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 17271 2013-01-18 07:58:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 07:58:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 07:58:14 JST DEBUG:  server process (PID 17271) exited
> with exit code 0
> 16388 2013-01-18 07:59:14 JST DEBUG:  StartTransaction
> 16388 2013-01-18 07:59:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 07:59:14 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 07:59:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17357 2013-01-18 07:59:14 JST DEBUG:  InitPostgres
> 17357 2013-01-18 07:59:14 JST DEBUG:  my backend ID is 2
> 17357 2013-01-18 07:59:14 JST DEBUG:  StartTransaction
> 17357 2013-01-18 07:59:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17357 2013-01-18 07:59:14 JST DEBUG:  CommitTransaction
> 17357 2013-01-18 07:59:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17357 2013-01-18 07:59:14 JST DEBUG:  autovacuum: processing database
> "postgres"
> 17357 2013-01-18 07:59:14 JST DEBUG:  StartTransaction
> 17357 2013-01-18 07:59:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17357 2013-01-18 07:59:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17357 2013-01-18 07:59:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 17357 2013-01-18 07:59:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 17357 2013-01-18 07:59:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 17357 2013-01-18 07:59:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 17357 2013-01-18 07:59:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 17357 2013-01-18 07:59:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17357 2013-01-18 07:59:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 17357 2013-01-18 07:59:14 JST DEBUG:  CommitTransaction
> 17357 2013-01-18 07:59:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17357 2013-01-18 07:59:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 17357 2013-01-18 07:59:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 17357 2013-01-18 07:59:14 JST DEBUG:  exit(0)
> 17357 2013-01-18 07:59:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 17357 2013-01-18 07:59:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 07:59:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 07:59:14 JST DEBUG:  server process (PID 17357) exited
> with exit code 0
> 16388 2013-01-18 08:00:14 JST DEBUG:  StartTransaction
> 16388 2013-01-18 08:00:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 08:00:14 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 08:00:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17442 2013-01-18 08:00:14 JST DEBUG:  InitPostgres
> 17442 2013-01-18 08:00:14 JST DEBUG:  my backend ID is 2
> 17442 2013-01-18 08:00:14 JST DEBUG:  StartTransaction
> 17442 2013-01-18 08:00:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17442 2013-01-18 08:00:14 JST DEBUG:  CommitTransaction
> 17442 2013-01-18 08:00:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17442 2013-01-18 08:00:14 JST DEBUG:  autovacuum: processing database
> "postgres"
> 17442 2013-01-18 08:00:14 JST DEBUG:  StartTransaction
> 17442 2013-01-18 08:00:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17442 2013-01-18 08:00:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17442 2013-01-18 08:00:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 17442 2013-01-18 08:00:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 17442 2013-01-18 08:00:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 17442 2013-01-18 08:00:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 17442 2013-01-18 08:00:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 17442 2013-01-18 08:00:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17442 2013-01-18 08:00:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 17442 2013-01-18 08:00:14 JST DEBUG:  CommitTransaction
> 17442 2013-01-18 08:00:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17442 2013-01-18 08:00:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 17442 2013-01-18 08:00:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 17442 2013-01-18 08:00:14 JST DEBUG:  exit(0)
> 17442 2013-01-18 08:00:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 17442 2013-01-18 08:00:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 08:00:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 08:00:14 JST DEBUG:  server process (PID 17442) exited
> with exit code 0
> 16388 2013-01-18 08:01:14 JST DEBUG:  StartTransaction
> 16388 2013-01-18 08:01:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 08:01:14 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 08:01:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17529 2013-01-18 08:01:14 JST DEBUG:  InitPostgres
> 17529 2013-01-18 08:01:14 JST DEBUG:  my backend ID is 2
> 17529 2013-01-18 08:01:14 JST DEBUG:  StartTransaction
> 17529 2013-01-18 08:01:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17529 2013-01-18 08:01:14 JST DEBUG:  CommitTransaction
> 17529 2013-01-18 08:01:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17529 2013-01-18 08:01:14 JST DEBUG:  autovacuum: processing database
> "postgres"
> 17529 2013-01-18 08:01:14 JST DEBUG:  StartTransaction
> 17529 2013-01-18 08:01:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17529 2013-01-18 08:01:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17529 2013-01-18 08:01:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 17529 2013-01-18 08:01:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 17529 2013-01-18 08:01:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 17529 2013-01-18 08:01:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 17529 2013-01-18 08:01:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 17529 2013-01-18 08:01:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17529 2013-01-18 08:01:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 17529 2013-01-18 08:01:14 JST DEBUG:  CommitTransaction
> 17529 2013-01-18 08:01:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17529 2013-01-18 08:01:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 17529 2013-01-18 08:01:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 17529 2013-01-18 08:01:14 JST DEBUG:  exit(0)
> 17529 2013-01-18 08:01:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 17529 2013-01-18 08:01:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 08:01:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 08:01:14 JST DEBUG:  server process (PID 17529) exited
> with exit code 0
> 16388 2013-01-18 08:02:14 JST DEBUG:  StartTransaction
> 16388 2013-01-18 08:02:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 08:02:14 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 08:02:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17610 2013-01-18 08:02:14 JST DEBUG:  InitPostgres
> 17610 2013-01-18 08:02:14 JST DEBUG:  my backend ID is 2
> 17610 2013-01-18 08:02:14 JST DEBUG:  StartTransaction
> 17610 2013-01-18 08:02:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17610 2013-01-18 08:02:14 JST DEBUG:  CommitTransaction
> 17610 2013-01-18 08:02:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17610 2013-01-18 08:02:14 JST DEBUG:  autovacuum: processing database
> "postgres"
> 17610 2013-01-18 08:02:14 JST DEBUG:  StartTransaction
> 17610 2013-01-18 08:02:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17610 2013-01-18 08:02:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17610 2013-01-18 08:02:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 17610 2013-01-18 08:02:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 17610 2013-01-18 08:02:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 17610 2013-01-18 08:02:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 17610 2013-01-18 08:02:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 17610 2013-01-18 08:02:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17610 2013-01-18 08:02:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 17610 2013-01-18 08:02:14 JST DEBUG:  CommitTransaction
> 17610 2013-01-18 08:02:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17610 2013-01-18 08:02:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 17610 2013-01-18 08:02:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 17610 2013-01-18 08:02:14 JST DEBUG:  exit(0)
> 17610 2013-01-18 08:02:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 17610 2013-01-18 08:02:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 08:02:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 08:02:14 JST DEBUG:  server process (PID 17610) exited
> with exit code 0
> 16388 2013-01-18 08:03:14 JST DEBUG:  StartTransaction
> 16388 2013-01-18 08:03:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 08:03:14 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 08:03:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17696 2013-01-18 08:03:14 JST DEBUG:  InitPostgres
> 17696 2013-01-18 08:03:14 JST DEBUG:  my backend ID is 2
> 17696 2013-01-18 08:03:14 JST DEBUG:  StartTransaction
> 17696 2013-01-18 08:03:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17696 2013-01-18 08:03:14 JST DEBUG:  CommitTransaction
> 17696 2013-01-18 08:03:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17696 2013-01-18 08:03:14 JST DEBUG:  autovacuum: processing database
> "postgres"
> 17696 2013-01-18 08:03:14 JST DEBUG:  StartTransaction
> 17696 2013-01-18 08:03:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17696 2013-01-18 08:03:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17696 2013-01-18 08:03:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 17696 2013-01-18 08:03:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 17696 2013-01-18 08:03:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 17696 2013-01-18 08:03:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 17696 2013-01-18 08:03:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 17696 2013-01-18 08:03:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17696 2013-01-18 08:03:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 17696 2013-01-18 08:03:14 JST DEBUG:  CommitTransaction
> 17696 2013-01-18 08:03:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17696 2013-01-18 08:03:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 17696 2013-01-18 08:03:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 17696 2013-01-18 08:03:14 JST DEBUG:  exit(0)
> 17696 2013-01-18 08:03:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 17696 2013-01-18 08:03:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 08:03:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 08:03:14 JST DEBUG:  server process (PID 17696) exited
> with exit code 0
> 16388 2013-01-18 08:04:14 JST DEBUG:  StartTransaction
> 16388 2013-01-18 08:04:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 08:04:14 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 08:04:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17781 2013-01-18 08:04:14 JST DEBUG:  InitPostgres
> 17781 2013-01-18 08:04:14 JST DEBUG:  my backend ID is 2
> 17781 2013-01-18 08:04:14 JST DEBUG:  StartTransaction
> 17781 2013-01-18 08:04:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17781 2013-01-18 08:04:14 JST DEBUG:  CommitTransaction
> 17781 2013-01-18 08:04:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17781 2013-01-18 08:04:14 JST DEBUG:  autovacuum: processing database
> "postgres"
> 17781 2013-01-18 08:04:14 JST DEBUG:  StartTransaction
> 17781 2013-01-18 08:04:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17781 2013-01-18 08:04:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17781 2013-01-18 08:04:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 17781 2013-01-18 08:04:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 17781 2013-01-18 08:04:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 17781 2013-01-18 08:04:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 17781 2013-01-18 08:04:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 17781 2013-01-18 08:04:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17781 2013-01-18 08:04:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 17781 2013-01-18 08:04:14 JST DEBUG:  CommitTransaction
> 17781 2013-01-18 08:04:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17781 2013-01-18 08:04:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 17781 2013-01-18 08:04:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 17781 2013-01-18 08:04:14 JST DEBUG:  exit(0)
> 17781 2013-01-18 08:04:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 17781 2013-01-18 08:04:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 08:04:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 08:04:14 JST DEBUG:  server process (PID 17781) exited
> with exit code 0
> 16388 2013-01-18 08:05:14 JST DEBUG:  StartTransaction
> 16388 2013-01-18 08:05:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 08:05:14 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 08:05:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17866 2013-01-18 08:05:14 JST DEBUG:  InitPostgres
> 17866 2013-01-18 08:05:14 JST DEBUG:  my backend ID is 2
> 17866 2013-01-18 08:05:14 JST DEBUG:  StartTransaction
> 17866 2013-01-18 08:05:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17866 2013-01-18 08:05:14 JST DEBUG:  CommitTransaction
> 17866 2013-01-18 08:05:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17866 2013-01-18 08:05:14 JST DEBUG:  autovacuum: processing database
> "postgres"
> 17866 2013-01-18 08:05:14 JST DEBUG:  StartTransaction
> 17866 2013-01-18 08:05:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17866 2013-01-18 08:05:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17866 2013-01-18 08:05:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 17866 2013-01-18 08:05:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 17866 2013-01-18 08:05:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 17866 2013-01-18 08:05:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 17866 2013-01-18 08:05:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 17866 2013-01-18 08:05:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17866 2013-01-18 08:05:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 17866 2013-01-18 08:05:14 JST DEBUG:  CommitTransaction
> 17866 2013-01-18 08:05:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17866 2013-01-18 08:05:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 17866 2013-01-18 08:05:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 17866 2013-01-18 08:05:14 JST DEBUG:  exit(0)
> 17866 2013-01-18 08:05:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 17866 2013-01-18 08:05:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 08:05:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 08:05:14 JST DEBUG:  server process (PID 17866) exited
> with exit code 0
> 16388 2013-01-18 08:06:14 JST DEBUG:  StartTransaction
> 16388 2013-01-18 08:06:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 08:06:14 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 08:06:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17953 2013-01-18 08:06:14 JST DEBUG:  InitPostgres
> 17953 2013-01-18 08:06:14 JST DEBUG:  my backend ID is 2
> 17953 2013-01-18 08:06:14 JST DEBUG:  StartTransaction
> 17953 2013-01-18 08:06:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17953 2013-01-18 08:06:14 JST DEBUG:  CommitTransaction
> 17953 2013-01-18 08:06:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17953 2013-01-18 08:06:14 JST DEBUG:  autovacuum: processing database
> "postgres"
> 17953 2013-01-18 08:06:14 JST DEBUG:  StartTransaction
> 17953 2013-01-18 08:06:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17953 2013-01-18 08:06:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17953 2013-01-18 08:06:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 17953 2013-01-18 08:06:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 17953 2013-01-18 08:06:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 17953 2013-01-18 08:06:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 17953 2013-01-18 08:06:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 17953 2013-01-18 08:06:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 17953 2013-01-18 08:06:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 17953 2013-01-18 08:06:14 JST DEBUG:  CommitTransaction
> 17953 2013-01-18 08:06:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 17953 2013-01-18 08:06:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 17953 2013-01-18 08:06:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 17953 2013-01-18 08:06:14 JST DEBUG:  exit(0)
> 17953 2013-01-18 08:06:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 17953 2013-01-18 08:06:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 08:06:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 08:06:14 JST DEBUG:  server process (PID 17953) exited
> with exit code 0
> 16388 2013-01-18 08:07:14 JST DEBUG:  StartTransaction
> 16388 2013-01-18 08:07:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 16388 2013-01-18 08:07:14 JST DEBUG:  CommitTransaction
> 16388 2013-01-18 08:07:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 18032 2013-01-18 08:07:14 JST DEBUG:  InitPostgres
> 18032 2013-01-18 08:07:14 JST DEBUG:  my backend ID is 2
> 18032 2013-01-18 08:07:14 JST DEBUG:  StartTransaction
> 18032 2013-01-18 08:07:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 18032 2013-01-18 08:07:14 JST DEBUG:  CommitTransaction
> 18032 2013-01-18 08:07:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 18032 2013-01-18 08:07:14 JST DEBUG:  autovacuum: processing database
> "postgres"
> 18032 2013-01-18 08:07:14 JST DEBUG:  StartTransaction
> 18032 2013-01-18 08:07:14 JST DEBUG:  name: unnamed; blockState:
> DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 18032 2013-01-18 08:07:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 18032 2013-01-18 08:07:14 JST DEBUG:  pg_class: vac: 0 (threshold 108),
> anl: 0 (threshold 79)
> 18032 2013-01-18 08:07:14 JST DEBUG:  pg_attribute: vac: 0 (threshold
> 499), anl: 0 (threshold 275)
> 18032 2013-01-18 08:07:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74),
> anl: 0 (threshold 62)
> 18032 2013-01-18 08:07:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
> (threshold 50)
> 18032 2013-01-18 08:07:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107),
> anl: 0 (threshold 79)
> 18032 2013-01-18 08:07:14 JST DEBUG:  pg_database: vac: 0 (threshold 50),
> anl: 0 (threshold 50)
> 18032 2013-01-18 08:07:14 JST DEBUG:  pg_index: vac: 0 (threshold 72),
> anl: 0 (threshold 61)
> 18032 2013-01-18 08:07:14 JST DEBUG:  CommitTransaction
> 18032 2013-01-18 08:07:14 JST DEBUG:  name: unnamed; blockState:
> STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 18032 2013-01-18 08:07:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make
> 18032 2013-01-18 08:07:14 JST DEBUG:  proc_exit(0): 2 callbacks to make
> 18032 2013-01-18 08:07:14 JST DEBUG:  exit(0)
> 18032 2013-01-18 08:07:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make
> 18032 2013-01-18 08:07:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make
> 16374 2013-01-18 08:07:14 JST DEBUG:  reaping dead processes
> 16374 2013-01-18 08:07:14 JST DEBUG:  server process (PID 18032) exited
> with exit code 0
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.sraoss.jp/pipermail/pgpool-general/attachments/20130118/c0c27155/attachment-0001.html>


More information about the pgpool-general mailing list