<div class="im" style="color:rgb(80,0,80);font-family:arial,sans-serif;font-size:13px;background-color:rgb(255,255,255)"><blockquote style="margin:0px 0px 0px 40px;border:none;padding:0px"><div>> For this to happen, am I right to say that I need to rsync the files in</div>
<div>> pg_xlog (node 0) to my archive folder ( /thumbnails/postgres_archives/ ) on</div><div>> node 1 ? My stage 2 script does not do that right now.</div><div><br></div><span style="color:rgb(34,34,34)">No at all. Copying pg_xlog to archive folder should be done by<br>
</span><span style="color:rgb(34,34,34)">archive_command by PostgreSQL.<br><br><br></span></blockquote><div><br></div></div><div style="color:rgb(34,34,34);font-family:arial,sans-serif;font-size:13px;background-color:rgb(255,255,255)">
<font color="#222222" face="arial, sans-serif">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</font></div>
<div style="color:rgb(34,34,34);font-family:arial,sans-serif;font-size:13px;background-color:rgb(255,255,255)"><font color="#222222" face="arial, sans-serif"><br></font></div><div style="color:rgb(34,34,34);font-family:arial,sans-serif;font-size:13px;background-color:rgb(255,255,255)">
<font color="#222222" face="arial, sans-serif">Thanks for your help!</font></div><br><div class="gmail_quote">On Thu, Jan 17, 2013 at 6:14 PM, Tatsuo Ishii <span dir="ltr"><<a href="mailto:ishii@postgresql.org" target="_blank">ishii@postgresql.org</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div class="im">> Thank you for the reply.<br>
><br>
> In the node 1 log, I dont find a "last completed transaction" line as you<br>
> have in your example.<br>
<br>
</div>That's the cause of the problem. For your convenience, I attached my<br>
PostgreSQL log with "log_min_messages = debug5".<br>
<br>
I guess you don't have desired archive files in<br>
/thumbnails/postgres_archives/pg_log.  Are you sure that you have<br>
/thumbnails/postgres_archives/pg_log/00000002000000040000008D on node 1?<br>
<br>
I suggest double check your postgresql.conf setting on node 0. Here is<br>
mine(different from the default):<br>
<br>
listen_addresses = '*'<br>
port = 11000<br>
logging_collector = on<br>
log_filename = '%A.log'<br>
log_line_prefix = '%p %t '<br>
log_truncate_on_rotation = on<br>
log_statement = 'all'<br>
max_prepared_transactions = 10<br>
hot_standby = on<br>
wal_level = hot_standby<br>
max_wal_senders = 2<br>
log_connections = on<br>
log_disconnections = on<br>
archive_mode = on<br>
archive_command = 'test ! -f /home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/%f" target="_blank">git.postgresql.org/test.repli/archivedir/%f</a> && cp %p /home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/%f" target="_blank">git.postgresql.org/test.repli/archivedir/%f</a>'<br>

log_min_messages = debug5<br>
<br>
And also you should see log on node 0 something like this:<br>
<br>
16362 2013-01-18 07:48:11 JST LOG:  pgpool_switch_xlog: waiting for "/home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/000000030000000100000025" target="_blank">git.postgresql.org/test.repli/archivedir/000000030000000100000025</a>"<br>

16362 2013-01-18 07:48:11 JST STATEMENT:  SELECT pgpool_switch_xlog('/home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir" target="_blank">git.postgresql.org/test.repli/archivedir</a>')<br>

16168 2013-01-18 07:48:11 JST DEBUG:  executing archive command "test ! -f /home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/000000030000000100000025" target="_blank">git.postgresql.org/test.repli/archivedir/000000030000000100000025</a> && cp pg_xlog/000000030000000100000025 /home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/000000030000000100000025" target="_blank">git.postgresql.org/test.repli/archivedir/000000030000000100000025</a>"<br>

16168 2013-01-18 07:48:12 JST DEBUG:  archived transaction log file "000000030000000100000025"<br>
16362 2013-01-18 07:48:12 JST DEBUG:  CommitTransactionCommand<br>
16362 2013-01-18 07:48:12 JST DEBUG:  CommitTransaction<br>
16362 2013-01-18 07:48:12 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
                                  pgpool_switch_xlog<br>
--------------------------------------------------------------------------------------<br>
 /home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/000000030000000100000025" target="_blank">git.postgresql.org/test.repli/archivedir/000000030000000100000025</a><br>
(1 row)<br>
<div class="im"><br>
> For this to happen, am I right to say that I need to rsync the files in<br>
> pg_xlog (node 0) to my archive folder ( /thumbnails/postgres_archives/ ) on<br>
> node 1 ? My stage 2 script does not do that right now.<br>
<br>
</div>No at all. Copying pg_xlog to archive folder should be done by<br>
archive_command by PostgreSQL.<br>
<div class="im"><br>
> I am not completely comfortable with what the files in pg_xlog contain<br>
> exactly, at the various stages. Also, I find it strange that the log show<br>
> many "No such file or directory", even in your example.<br>
<br>
</div>That's normal. PostgreSQL continues recoverying until requested file<br>
does not exist.<br>
<div class="im HOEnZb">--<br>
Tatsuo Ishii<br>
SRA OSS, Inc. Japan<br>
English: <a href="http://www.sraoss.co.jp/index_en.php" target="_blank">http://www.sraoss.co.jp/index_en.php</a><br>
Japanese: <a href="http://www.sraoss.co.jp" target="_blank">http://www.sraoss.co.jp</a><br>
<br>
</div><div class="HOEnZb"><div class="h5">> Thanks<br>
><br>
> Gilbert<br>
><br>
> ~~~~<br>
> LOg file for postgres on node 1 during recovery:<br>
><br>
> 2013-01-16 19:50:20 EST : LOG:  database system was interrupted; last known<br>
> up at 2013-01-16 19:50:16 EST<br>
> 2013-01-16 19:50:20 EST : LOG:  starting archive recovery<br>
> 2013-01-16 19:50:20 EST : LOG:  restore_command = 'cp<br>
>  /thumbnails/postgres_archives/pg_log/%f %p'<br>
> 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp<br>
>  /thumbnails/postgres_archives/pg_log/00000002.history<br>
> pg_xlog/RECOVERYHISTORY"<br>
> cp: cannot stat `/thumbnails/postgres_archives/pg_log/00000002.history': No<br>
> such file or directory<br>
> 2013-01-16 19:50:20 EST : DEBUG:  could not restore file "00000002.history"<br>
> from archive: return code 256<br>
> 2013-01-16 19:50:20 EST : DEBUG:  history of timeline 2 is (i 2 1)<br>
> 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp<br>
>  /thumbnails/postgres_archives/pg_log/00000002000000040000008D.00000020.backup<br>
> pg_xlog/RECOVERY<br>
> HISTORY"<br>
> cp: cannot stat<br>
> `/thumbnails/postgres_archives/pg_log/00000002000000040000008D.00000020.backup':<br>
> No such file or directory<br>
> 2013-01-16 19:50:20 EST : DEBUG:  could not restore file<br>
> "00000002000000040000008D.00000020.backup" from archive: return code 256<br>
> 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp<br>
>  /thumbnails/postgres_archives/pg_log/00000002000000040000008D<br>
> pg_xlog/RECOVERYXLOG"<br>
> cp: cannot stat<br>
> `/thumbnails/postgres_archives/pg_log/00000002000000040000008D': No such<br>
> file or directory<br>
> 2013-01-16 19:50:20 EST : DEBUG:  could not restore file<br>
> "00000002000000040000008D" from archive: return code 256<br>
> 2013-01-16 19:50:20 EST : DEBUG:  checkpoint record is at 4/8D000020<br>
> 2013-01-16 19:50:20 EST : DEBUG:  redo record is at 4/8D000020; shutdown<br>
> FALSE<br>
> 2013-01-16 19:50:20 EST : DEBUG:  next transaction ID: 0/1625; next OID:<br>
> 17797<br>
> 2013-01-16 19:50:20 EST : DEBUG:  next MultiXactId: 1; next<br>
> MultiXactOffset: 0<br>
> 2013-01-16 19:50:20 EST : LOG:  automatic recovery in progress<br>
> 2013-01-16 19:50:20 EST : LOG:  record with zero length at 4/8D000068<br>
> 2013-01-16 19:50:20 EST : LOG:  redo is not required<br>
> 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp<br>
>  /thumbnails/postgres_archives/pg_log/00000002000000040000008D<br>
> pg_xlog/RECOVERYXLOG"<br>
> cp: cannot stat<br>
> `/thumbnails/postgres_archives/pg_log/00000002000000040000008D': No such<br>
> file or directory<br>
> 2013-01-16 19:50:20 EST : DEBUG:  could not restore file<br>
> "00000002000000040000008D" from archive: return code 256<br>
> 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp<br>
>  /thumbnails/postgres_archives/pg_log/00000003.history<br>
> pg_xlog/RECOVERYHISTORY"<br>
> 2013-01-16 19:50:20 EST : LOG:  restored log file "00000003.history" from<br>
> archive<br>
> 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp<br>
>  /thumbnails/postgres_archives/pg_log/00000004.history<br>
> pg_xlog/RECOVERYHISTORY"<br>
> 2013-01-16 19:50:20 EST : LOG:  restored log file "00000004.history" from<br>
> archive<br>
> 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp<br>
>  /thumbnails/postgres_archives/pg_log/00000005.history<br>
> pg_xlog/RECOVERYHISTORY"<br>
> 2013-01-16 19:50:20 EST : LOG:  restored log file "00000005.history" from<br>
> archive<br>
> 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp<br>
>  /thumbnails/postgres_archives/pg_log/00000006.history<br>
> pg_xlog/RECOVERYHISTORY"<br>
> cp: cannot stat `/thumbnails/postgres_archives/pg_log/00000006.history': No<br>
> such file or directory<br>
> 2013-01-16 19:50:20 EST : DEBUG:  could not restore file "00000006.history"<br>
> from archive: return code 256<br>
> 2013-01-16 19:50:20 EST : LOG:  selected new timeline ID: 6<br>
> 2013-01-16 19:50:20 EST : DEBUG:  executing restore command "cp<br>
>  /thumbnails/postgres_archives/pg_log/00000002.history<br>
> pg_xlog/RECOVERYHISTORY"<br>
> cp: cannot stat `/thumbnails/postgres_archives/pg_log/00000002.history': No<br>
> such file or directory<br>
> 2013-01-16 19:50:20 EST : DEBUG:  could not restore file "00000002.history"<br>
> from archive: return code 256<br>
> 2013-01-16 19:50:20 EST : LOG:  archive recovery complete<br>
> 2013-01-16 19:50:20 EST : DEBUG:  recycled transaction log file<br>
> "00000002000000040000008C"<br>
> 2013-01-16 19:50:20 EST : DEBUG:  transaction ID wrap limit is 2147484295,<br>
> limited by database "template1"<br>
> 2013-01-16 19:50:20 EST : DEBUG:  shmem_exit(0): 3 callbacks to make<br>
> 2013-01-16 19:50:20 EST : DEBUG:  proc_exit(0): 2 callbacks to make<br>
> 2013-01-16 19:50:20 EST : DEBUG:  exit(0)<br>
> 2013-01-16 19:50:20 EST : DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
> 2013-01-16 19:50:20 EST : DEBUG:  proc_exit(-1): 0 callbacks to make<br>
> 2013-01-16 19:50:20 EST : DEBUG:  reaping dead processes<br>
> 2013-01-16 19:50:20 EST : LOG:  autovacuum launcher started<br>
> 2013-01-16 19:50:20 EST : LOG:  database system is ready to accept<br>
> connections<br>
><br>
><br>
> On Wed, Jan 16, 2013 at 10:06 PM, Tatsuo Ishii <<a href="mailto:ishii@postgresql.org">ishii@postgresql.org</a>> wrote:<br>
><br>
>> > Hello<br>
>> ><br>
>> > I hope this is the place whee I can ask general questions about pgpool. I<br>
>> > could not find a forum. Otheriwse, please let me know where I should go<br>
>> to<br>
>> > get help<br>
>><br>
>> Yes, this is the perfect place to ask general questions about<br>
>> pgpool(there's no forum).<br>
>><br>
>> > Here is my question:<br>
>> ><br>
>> > I am trying to setup pgpool II with 2 postgres nodes using replication<br>
>> and<br>
>> > load balancing. I have setup the watch dog to switch the virtual IP<br>
>> > automatically in case of failure. The 2 postgres nodes run on 2 identical<br>
>> > computers.<br>
>> ><br>
>> > Everything works fine except for the recovery which I dont quite<br>
>> undestand.<br>
>> > I have installed and configured the scripts:<br>
>> ><br>
>> > basebackup.sh<br>
>> > pgpool_remote_start<br>
>> > pgpool_recovery_pitr<br>
>> ><br>
>> ><br>
>> > Then I simulate a failure : I shutdown one of the postgres nodes. This<br>
>> gets<br>
>> > detected fine and pgpool is still functional with the remaining node<br>
>> (which<br>
>> > can still accept connections).<br>
>> ><br>
>> > When I try to recover, it does not work as I expected. I thought that we<br>
>> > could recover *while pgpool keeps accepting requests*. (at least for<br>
>> stage<br>
>> > 1 of the recover). So, I simulated this by inserting a new line in a<br>
>> table<br>
>> > of my database just before the end of the basebackup.sh script  (just<br>
>> *after<br>
>> > * the rsync and *before* the pg_stop_backup() ).<br>
>> ><br>
>> > So, my basebackup.sh script looks like:<br>
>> > ~~~~~~~~~~<br>
>> ><br>
>> > ....<br>
>> ><br>
>> > *psql -U postgres -p 5432 -c "insert into users values (3000, 'def1');"<br>
>> > myDB      # this line was added to basebackup.sh to simulate a<br>
>> transaction<br>
>> > during a recover, stage 1      *<br>
>> ><br>
>> > psql -U postgres -p 5432 -c "SELECT pg_stop_backup()" postgres<br>
>> > ~~~~~~~~~~~~<br>
>> ><br>
>> > I then try to recover my failed node with:<br>
>> ><br>
>> > /usr/local/bin/pcp_recovery_node -d 15 192.168.0.110 9898 pgpool pgpool 1<br>
>> ><br>
>> > Which succeeds. However, when I look at the content of the databases,<br>
>> only<br>
>> > the master database has the new line  "3000  test" (purposely added in my<br>
>> > basebackup.sh script). The recovered database has all other lines but not<br>
>> > this one. So the recovery is not complete in my opinion (or I dont<br>
>> > understand what it is supposed to do).<br>
>> ><br>
>> > Am I wrong in expecting that this should work (i.e. after the recover,<br>
>> the<br>
>> > 2 database should be completely in sync) ?<br>
>><br>
>> Works fine for me. I guess you have problem with archive recovery<br>
>> setting of PostgreSQL.<br>
>><br>
>> Below is my recovered PostgreSQL log.  Do you find something like<br>
>> "restored log file "000000030000000100000021" from archive" in your<br>
>> PostgreSQL log(in your case DB node 1)?<br>
>><br>
>> 31055 2013-01-17 11:38:14 JST LOG:  database system was interrupted; last<br>
>> known up at 2013-01-17 11:38:11 JST<br>
>> 31055 2013-01-17 11:38:14 JST LOG:  creating missing WAL directory<br>
>> "pg_xlog/archive_status"<br>
>> cp: cannot stat `/home/t-ishii/work/<br>
>> <a href="http://git.postgresql.org/test.repli/archivedir/00000003.history" target="_blank">git.postgresql.org/test.repli/archivedir/00000003.history</a>': No such file<br>
>> or directory<br>
>> 31055 2013-01-17 11:38:14 JST LOG:  starting archive recovery<br>
>> 31055 2013-01-17 11:38:14 JST LOG:  restored log file<br>
>> "000000030000000100000020" from archive<br>
>> 31055 2013-01-17 11:38:14 JST LOG:  redo starts at 1/20000020<br>
>> 31055 2013-01-17 11:38:14 JST LOG:  consistent recovery state reached at<br>
>> 1/21000000<br>
>> 31053 2013-01-17 11:38:14 JST LOG:  database system is ready to accept<br>
>> read only connections<br>
>> 31055 2013-01-17 11:38:14 JST LOG:  restored log file<br>
>> "000000030000000100000021" from archive<br>
>> cp: cannot stat `/home/t-ishii/work/<br>
>> <a href="http://git.postgresql.org/test.repli/archivedir/000000030000000100000022" target="_blank">git.postgresql.org/test.repli/archivedir/000000030000000100000022</a>': No<br>
>> such file or directory<br>
>> 31055 2013-01-17 11:38:14 JST LOG:  could not open file<br>
>> "pg_xlog/000000030000000100000022" (log file 1, segment 34): No such file<br>
>> or directory<br>
>> 31055 2013-01-17 11:38:14 JST LOG:  redo done at 1/21000E48<br>
>> 31055 2013-01-17 11:38:14 JST LOG:  last completed transaction was at log<br>
>> time 2013-01-17 11:38:12.376859+09<br>
>> 31055 2013-01-17 11:38:14 JST LOG:  restored log file<br>
>> "000000030000000100000021" from archive<br>
>> cp: cannot stat `/home/t-ishii/work/<br>
>> <a href="http://git.postgresql.org/test.repli/archivedir/00000004.history" target="_blank">git.postgresql.org/test.repli/archivedir/00000004.history</a>': No such file<br>
>> or directory<br>
>> 31055 2013-01-17 11:38:14 JST LOG:  selected new timeline ID: 4<br>
>> cp: cannot stat `/home/t-ishii/work/<br>
>> <a href="http://git.postgresql.org/test.repli/archivedir/00000003.history" target="_blank">git.postgresql.org/test.repli/archivedir/00000003.history</a>': No such file<br>
>> or directory<br>
>> 31055 2013-01-17 11:38:15 JST LOG:  archive recovery complete<br>
>> 31053 2013-01-17 11:38:15 JST LOG:  database system is ready to accept<br>
>> connections<br>
>> 31067 2013-01-17 11:38:15 JST LOG:  autovacuum launcher started<br>
>> --<br>
>> Tatsuo Ishii<br>
>> SRA OSS, Inc. Japan<br>
>> English: <a href="http://www.sraoss.co.jp/index_en.php" target="_blank">http://www.sraoss.co.jp/index_en.php</a><br>
>> Japanese: <a href="http://www.sraoss.co.jp" target="_blank">http://www.sraoss.co.jp</a><br>
>><br>
</div></div><br>15875 2013-01-18 07:44:08 JST LOG:  connection authorized: user=t-ishii database=test<br>
15875 2013-01-18 07:44:11 JST LOG:  statement: SELECT n.nspname as "Schema",<br>
          c.relname as "Name",<br>
          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",<br>

          pg_catalog.pg_get_userbyid(c.relowner) as "Owner"<br>
        FROM pg_catalog.pg_class c<br>
             LEFT JOIN pg_catalog.pg_namespace n ON n.oid = c.relnamespace<br>
        WHERE c.relkind IN ('r','')<br>
              AND n.nspname <> 'pg_catalog'<br>
              AND n.nspname <> 'information_schema'<br>
              AND n.nspname !~ '^pg_toast'<br>
          AND pg_catalog.pg_table_is_visible(c.oid)<br>
        ORDER BY 1,2;<br>
15875 2013-01-18 07:44:19 JST LOG:  statement: select * from t1;<br>
15875 2013-01-18 07:44:21 JST LOG:  statement:  DISCARD ALL<br>
15875 2013-01-18 07:44:24 JST LOG:  disconnection: session time: 0:00:16.148 user=t-ishii database=test host=[local]<br>
31053 2013-01-18 07:44:27 JST LOG:  received fast shutdown request<br>
31053 2013-01-18 07:44:27 JST LOG:  aborting any active transactions<br>
31067 2013-01-18 07:44:27 JST LOG:  autovacuum launcher shutting down<br>
31058 2013-01-18 07:44:27 JST LOG:  shutting down<br>
31058 2013-01-18 07:44:27 JST LOG:  database system is shut down<br>
16189 2013-01-18 07:47:26 JST LOG:  database system was shut down at 2013-01-18 07:44:27 JST<br>
16189 2013-01-18 07:47:26 JST DEBUG:  history of timeline 4 is (i 4 3)<br>
16189 2013-01-18 07:47:26 JST DEBUG:  checkpoint record is at 1/22000080<br>
16189 2013-01-18 07:47:26 JST DEBUG:  redo record is at 1/22000080; shutdown TRUE<br>
16189 2013-01-18 07:47:26 JST DEBUG:  next transaction ID: 0/438215; next OID: 305262<br>
16189 2013-01-18 07:47:26 JST DEBUG:  next MultiXactId: 1; next MultiXactOffset: 0<br>
16189 2013-01-18 07:47:26 JST DEBUG:  oldest unfrozen transaction ID: 686, in database 1<br>
16189 2013-01-18 07:47:26 JST DEBUG:  transaction ID wrap limit is 2147484333, limited by database with OID 1<br>
16189 2013-01-18 07:47:26 JST DEBUG:  shmem_exit(0): 4 callbacks to make<br>
16189 2013-01-18 07:47:26 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
16189 2013-01-18 07:47:26 JST DEBUG:  exit(0)<br>
16189 2013-01-18 07:47:26 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16189 2013-01-18 07:47:26 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16187 2013-01-18 07:47:26 JST DEBUG:  reaping dead processes<br>
16190 2013-01-18 07:47:26 JST DEBUG:  checkpointer updated shared memory configuration values<br>
16187 2013-01-18 07:47:26 JST LOG:  database system is ready to accept connections<br>
16193 2013-01-18 07:47:26 JST LOG:  autovacuum launcher started<br>
16193 2013-01-18 07:47:26 JST DEBUG:  InitPostgres<br>
16193 2013-01-18 07:47:26 JST DEBUG:  my backend ID is 1<br>
16193 2013-01-18 07:47:26 JST DEBUG:  StartTransaction<br>
16193 2013-01-18 07:47:26 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16193 2013-01-18 07:47:26 JST DEBUG:  CommitTransaction<br>
16193 2013-01-18 07:47:26 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16187 2013-01-18 07:47:27 JST DEBUG:  forked new backend, pid=16196 socket=12<br>
16196 2013-01-18 07:47:27 JST LOG:  connection received: host=[local]<br>
16196 2013-01-18 07:47:27 JST DEBUG:  postgres child[16196]: starting with (<br>
16196 2013-01-18 07:47:27 JST DEBUG:    postgres<br>
16196 2013-01-18 07:47:27 JST DEBUG:    postgres<br>
16196 2013-01-18 07:47:27 JST DEBUG:  )<br>
16196 2013-01-18 07:47:27 JST DEBUG:  InitPostgres<br>
16196 2013-01-18 07:47:27 JST DEBUG:  my backend ID is 2<br>
16196 2013-01-18 07:47:27 JST DEBUG:  StartTransaction<br>
16196 2013-01-18 07:47:27 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16196 2013-01-18 07:47:27 JST LOG:  connection authorized: user=t-ishii database=postgres<br>
16196 2013-01-18 07:47:27 JST DEBUG:  CommitTransaction<br>
16196 2013-01-18 07:47:27 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16196 2013-01-18 07:47:27 JST DEBUG:  shmem_exit(0): 7 callbacks to make<br>
16196 2013-01-18 07:47:27 JST DEBUG:  proc_exit(0): 4 callbacks to make<br>
16196 2013-01-18 07:47:27 JST LOG:  disconnection: session time: 0:00:00.005 user=t-ishii database=postgres host=[local]<br>
16196 2013-01-18 07:47:27 JST DEBUG:  exit(0)<br>
16196 2013-01-18 07:47:27 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16196 2013-01-18 07:47:27 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16187 2013-01-18 07:47:27 JST DEBUG:  reaping dead processes<br>
16187 2013-01-18 07:47:27 JST DEBUG:  server process (PID 16196) exited with exit code 0<br>
16187 2013-01-18 07:47:49 JST DEBUG:  postmaster received signal 2<br>
16187 2013-01-18 07:47:49 JST LOG:  received fast shutdown request<br>
16187 2013-01-18 07:47:49 JST LOG:  aborting any active transactions<br>
16193 2013-01-18 07:47:49 JST LOG:  autovacuum launcher shutting down<br>
16193 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(0): 7 callbacks to make<br>
16193 2013-01-18 07:47:49 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
16193 2013-01-18 07:47:49 JST DEBUG:  exit(0)<br>
16192 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(0): 4 callbacks to make<br>
16191 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(0): 4 callbacks to make<br>
16192 2013-01-18 07:47:49 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
16191 2013-01-18 07:47:49 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
16193 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16192 2013-01-18 07:47:49 JST DEBUG:  exit(0)<br>
16193 2013-01-18 07:47:49 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16191 2013-01-18 07:47:49 JST DEBUG:  exit(0)<br>
16192 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16192 2013-01-18 07:47:49 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16191 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16191 2013-01-18 07:47:49 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16187 2013-01-18 07:47:49 JST DEBUG:  reaping dead processes<br>
16187 2013-01-18 07:47:49 JST DEBUG:  reaping dead processes<br>
16190 2013-01-18 07:47:49 JST LOG:  shutting down<br>
16190 2013-01-18 07:47:49 JST DEBUG:  SlruScanDirectory invoking callback on pg_multixact/offsets/0000<br>
16190 2013-01-18 07:47:49 JST DEBUG:  SlruScanDirectory invoking callback on pg_multixact/members/0000<br>
16190 2013-01-18 07:47:49 JST DEBUG:  attempting to remove WAL segments older than log file 000000040000000100000021<br>
16190 2013-01-18 07:47:49 JST DEBUG:  SlruScanDirectory invoking callback on pg_subtrans/0006<br>
16190 2013-01-18 07:47:49 JST LOG:  database system is shut down<br>
16190 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(0): 4 callbacks to make<br>
16190 2013-01-18 07:47:49 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
16190 2013-01-18 07:47:49 JST DEBUG:  exit(0)<br>
16190 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16190 2013-01-18 07:47:49 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16187 2013-01-18 07:47:49 JST DEBUG:  reaping dead processes<br>
16194 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16194 2013-01-18 07:47:49 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16187 2013-01-18 07:47:49 JST DEBUG:  reaping dead processes<br>
16187 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(0): 3 callbacks to make<br>
16187 2013-01-18 07:47:49 JST DEBUG:  proc_exit(0): 3 callbacks to make<br>
16187 2013-01-18 07:47:49 JST DEBUG:  exit(0)<br>
16187 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16187 2013-01-18 07:47:49 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16188 2013-01-18 07:47:49 JST DEBUG:  logger shutting down<br>
16188 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(0): 0 callbacks to make<br>
16188 2013-01-18 07:47:49 JST DEBUG:  proc_exit(0): 0 callbacks to make<br>
16188 2013-01-18 07:47:49 JST DEBUG:  exit(0)<br>
16188 2013-01-18 07:47:49 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16188 2013-01-18 07:47:49 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16376 2013-01-18 07:48:13 JST LOG:  database system was interrupted; last known up at 2013-01-18 07:48:10 JST<br>
16376 2013-01-18 07:48:13 JST LOG:  creating missing WAL directory "pg_xlog/archive_status"<br>
16376 2013-01-18 07:48:13 JST DEBUG:  restore_command = 'cp /home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/%f" target="_blank">git.postgresql.org/test.repli/archivedir/%f</a> %p'<br>
16376 2013-01-18 07:48:13 JST DEBUG:  executing restore command "cp /home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/00000003.history" target="_blank">git.postgresql.org/test.repli/archivedir/00000003.history</a> pg_xlog/RECOVERYHISTORY"<br>

cp: cannot stat `/home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/00000003.history" target="_blank">git.postgresql.org/test.repli/archivedir/00000003.history</a>': No such file or directory<br>

16376 2013-01-18 07:48:13 JST DEBUG:  could not restore file "00000003.history" from archive: return code 256<br>
16376 2013-01-18 07:48:13 JST LOG:  starting archive recovery<br>
16376 2013-01-18 07:48:13 JST DEBUG:  executing restore command "cp /home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/000000030000000100000024" target="_blank">git.postgresql.org/test.repli/archivedir/000000030000000100000024</a> pg_xlog/RECOVERYXLOG"<br>

16376 2013-01-18 07:48:13 JST LOG:  restored log file "000000030000000100000024" from archive<br>
16376 2013-01-18 07:48:13 JST DEBUG:  got WAL segment from archive<br>
16376 2013-01-18 07:48:13 JST DEBUG:  checkpoint record is at 1/24000058<br>
16376 2013-01-18 07:48:13 JST DEBUG:  redo record is at 1/24000020; shutdown FALSE<br>
16376 2013-01-18 07:48:13 JST DEBUG:  next transaction ID: 0/438215; next OID: 305262<br>
16376 2013-01-18 07:48:13 JST DEBUG:  next MultiXactId: 1; next MultiXactOffset: 0<br>
16376 2013-01-18 07:48:13 JST DEBUG:  oldest unfrozen transaction ID: 686, in database 1<br>
16376 2013-01-18 07:48:13 JST DEBUG:  transaction ID wrap limit is 2147484333, limited by database with OID 1<br>
16376 2013-01-18 07:48:13 JST DEBUG:  resetting unlogged relations: cleanup 1 init 0<br>
16376 2013-01-18 07:48:13 JST DEBUG:  initializing for hot standby<br>
16376 2013-01-18 07:48:13 JST DEBUG:  my backend ID is 1<br>
16376 2013-01-18 07:48:13 JST LOG:  redo starts at 1/24000020<br>
16376 2013-01-18 07:48:13 JST DEBUG:  prune KnownAssignedXids to 438215<br>
16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo  running xacts: nextXid 438215 latestCompletedXid 438214 oldestRunningXid 438215<br>
16376 2013-01-18 07:48:13 JST DEBUG:  0 KnownAssignedXids (num=0 tail=0 head=0)<br>
16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo  running xacts: nextXid 438215 latestCompletedXid 438214 oldestRunningXid 438215<br>
16376 2013-01-18 07:48:13 JST DEBUG:  recovery snapshots are now enabled<br>
16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo  running xacts: nextXid 438215 latestCompletedXid 438214 oldestRunningXid 438215<br>
16376 2013-01-18 07:48:13 JST DEBUG:  record known xact 438215 latestObservedXid 438214<br>
16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo insert: rel 1663/16389/305218; tid 0/18<br>
16376 2013-01-18 07:48:13 JST DEBUG:  record known xact 438215 latestObservedXid 438215<br>
16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo commit: 2013-01-18 07:48:10.799457+09<br>
16376 2013-01-18 07:48:13 JST DEBUG:  record known xact 438215 latestObservedXid 438215<br>
16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo commit: 2013-01-18 07:48:10.799457+09<br>
16376 2013-01-18 07:48:13 JST DEBUG:  remove KnownAssignedXid 438215<br>
16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo commit: 2013-01-18 07:48:10.799457+09<br>
16376 2013-01-18 07:48:13 JST DEBUG:  end of backup reached<br>
16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo backup end: 1/24000020<br>
16379 2013-01-18 07:48:13 JST DEBUG:  checkpointer updated shared memory configuration values<br>
16376 2013-01-18 07:48:13 JST LOG:  consistent recovery state reached at 1/25000000<br>
16376 2013-01-18 07:48:13 JST DEBUG:  executing restore command "cp /home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/000000030000000100000025" target="_blank">git.postgresql.org/test.repli/archivedir/000000030000000100000025</a> pg_xlog/RECOVERYXLOG"<br>

16374 2013-01-18 07:48:13 JST LOG:  database system is ready to accept read only connections<br>
16376 2013-01-18 07:48:13 JST LOG:  restored log file "000000030000000100000025" from archive<br>
16376 2013-01-18 07:48:13 JST DEBUG:  got WAL segment from archive<br>
16376 2013-01-18 07:48:13 JST DEBUG:  prune KnownAssignedXids to 438216<br>
16376 2013-01-18 07:48:13 JST CONTEXT:  xlog redo  running xacts: nextXid 438216 latestCompletedXid 438215 oldestRunningXid 438216<br>
16376 2013-01-18 07:48:13 JST DEBUG:  executing restore command "cp /home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/000000030000000100000026" target="_blank">git.postgresql.org/test.repli/archivedir/000000030000000100000026</a> pg_xlog/RECOVERYXLOG"<br>

cp: cannot stat `/home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/000000030000000100000026" target="_blank">git.postgresql.org/test.repli/archivedir/000000030000000100000026</a>': No such file or directory<br>

16376 2013-01-18 07:48:13 JST DEBUG:  could not restore file "000000030000000100000026" from archive: return code 256<br>
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<br>
16376 2013-01-18 07:48:13 JST LOG:  redo done at 1/25000E48<br>
16376 2013-01-18 07:48:13 JST LOG:  last completed transaction was at log time 2013-01-18 07:48:10.799457+09<br>
16376 2013-01-18 07:48:13 JST DEBUG:  executing restore command "cp /home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/000000030000000100000025" target="_blank">git.postgresql.org/test.repli/archivedir/000000030000000100000025</a> pg_xlog/RECOVERYXLOG"<br>

16376 2013-01-18 07:48:13 JST LOG:  restored log file "000000030000000100000025" from archive<br>
16376 2013-01-18 07:48:13 JST DEBUG:  got WAL segment from archive<br>
16376 2013-01-18 07:48:13 JST DEBUG:  executing restore command "cp /home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/00000004.history" target="_blank">git.postgresql.org/test.repli/archivedir/00000004.history</a> pg_xlog/RECOVERYHISTORY"<br>

cp: cannot stat `/home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/00000004.history" target="_blank">git.postgresql.org/test.repli/archivedir/00000004.history</a>': No such file or directory<br>

16376 2013-01-18 07:48:13 JST DEBUG:  could not restore file "00000004.history" from archive: return code 256<br>
16376 2013-01-18 07:48:13 JST LOG:  selected new timeline ID: 4<br>
16376 2013-01-18 07:48:13 JST DEBUG:  executing restore command "cp /home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/00000003.history" target="_blank">git.postgresql.org/test.repli/archivedir/00000003.history</a> pg_xlog/RECOVERYHISTORY"<br>

cp: cannot stat `/home/t-ishii/work/<a href="http://git.postgresql.org/test.repli/archivedir/00000003.history" target="_blank">git.postgresql.org/test.repli/archivedir/00000003.history</a>': No such file or directory<br>

16376 2013-01-18 07:48:13 JST DEBUG:  could not restore file "00000003.history" from archive: return code 256<br>
16376 2013-01-18 07:48:13 JST DEBUG:  updated min recovery point to 1/26000000<br>
16376 2013-01-18 07:48:13 JST LOG:  archive recovery complete<br>
16379 2013-01-18 07:48:13 JST DEBUG:  creating and filling new WAL file<br>
16379 2013-01-18 07:48:13 JST DEBUG:  done creating and filling new WAL file<br>
16379 2013-01-18 07:48:13 JST DEBUG:  attempting to remove WAL segments older than log file 000000040000000100000023<br>
16376 2013-01-18 07:48:13 JST DEBUG:  resetting unlogged relations: cleanup 0 init 1<br>
16376 2013-01-18 07:48:13 JST DEBUG:  removing all KnownAssignedXids<br>
16376 2013-01-18 07:48:13 JST DEBUG:  release all standby locks<br>
16376 2013-01-18 07:48:13 JST DEBUG:  shmem_exit(0): 5 callbacks to make<br>
16376 2013-01-18 07:48:13 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
16376 2013-01-18 07:48:13 JST DEBUG:  exit(0)<br>
16376 2013-01-18 07:48:13 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16376 2013-01-18 07:48:13 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 07:48:13 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 07:48:13 JST LOG:  database system is ready to accept connections<br>
16388 2013-01-18 07:48:13 JST LOG:  autovacuum launcher started<br>
16388 2013-01-18 07:48:13 JST DEBUG:  InitPostgres<br>
16388 2013-01-18 07:48:13 JST DEBUG:  my backend ID is 1<br>
16388 2013-01-18 07:48:13 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 07:48:13 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 07:48:13 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 07:48:13 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16374 2013-01-18 07:48:14 JST DEBUG:  forked new backend, pid=16394 socket=10<br>
16394 2013-01-18 07:48:14 JST LOG:  connection received: host=[local]<br>
16394 2013-01-18 07:48:14 JST DEBUG:  postgres child[16394]: starting with (<br>
16394 2013-01-18 07:48:14 JST DEBUG:    postgres<br>
16394 2013-01-18 07:48:14 JST DEBUG:    postgres<br>
16394 2013-01-18 07:48:14 JST DEBUG:  )<br>
16394 2013-01-18 07:48:14 JST DEBUG:  InitPostgres<br>
16394 2013-01-18 07:48:14 JST DEBUG:  my backend ID is 2<br>
16394 2013-01-18 07:48:14 JST DEBUG:  StartTransaction<br>
16394 2013-01-18 07:48:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16394 2013-01-18 07:48:14 JST LOG:  connection authorized: user=t-ishii database=postgres<br>
16394 2013-01-18 07:48:14 JST DEBUG:  CommitTransaction<br>
16394 2013-01-18 07:48:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16394 2013-01-18 07:48:14 JST DEBUG:  shmem_exit(0): 7 callbacks to make<br>
16394 2013-01-18 07:48:14 JST DEBUG:  proc_exit(0): 4 callbacks to make<br>
16394 2013-01-18 07:48:14 JST LOG:  disconnection: session time: 0:00:00.008 user=t-ishii database=postgres host=[local]<br>
16394 2013-01-18 07:48:14 JST DEBUG:  exit(0)<br>
16394 2013-01-18 07:48:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16394 2013-01-18 07:48:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 07:48:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 07:48:14 JST DEBUG:  server process (PID 16394) exited with exit code 0<br>
16374 2013-01-18 07:48:15 JST DEBUG:  forked new backend, pid=16404 socket=10<br>
16404 2013-01-18 07:48:15 JST LOG:  connection received: host=[local]<br>
16404 2013-01-18 07:48:15 JST DEBUG:  postgres child[16404]: starting with (<br>
16404 2013-01-18 07:48:15 JST DEBUG:    postgres<br>
16404 2013-01-18 07:48:15 JST DEBUG:    postgres<br>
16404 2013-01-18 07:48:15 JST DEBUG:  )<br>
16404 2013-01-18 07:48:15 JST DEBUG:  InitPostgres<br>
16404 2013-01-18 07:48:15 JST DEBUG:  my backend ID is 2<br>
16404 2013-01-18 07:48:15 JST DEBUG:  StartTransaction<br>
16404 2013-01-18 07:48:15 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16404 2013-01-18 07:48:15 JST LOG:  connection authorized: user=t-ishii database=postgres<br>
16404 2013-01-18 07:48:15 JST DEBUG:  CommitTransaction<br>
16404 2013-01-18 07:48:15 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16404 2013-01-18 07:48:16 JST DEBUG:  shmem_exit(0): 7 callbacks to make<br>
16404 2013-01-18 07:48:16 JST DEBUG:  proc_exit(0): 4 callbacks to make<br>
16404 2013-01-18 07:48:16 JST LOG:  disconnection: session time: 0:00:00.004 user=t-ishii database=postgres host=[local]<br>
16404 2013-01-18 07:48:16 JST DEBUG:  exit(0)<br>
16404 2013-01-18 07:48:16 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16404 2013-01-18 07:48:16 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 07:48:16 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 07:48:16 JST DEBUG:  server process (PID 16404) exited with exit code 0<br>
16388 2013-01-18 07:49:13 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 07:49:13 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 07:49:13 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 07:49:13 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16509 2013-01-18 07:49:13 JST DEBUG:  InitPostgres<br>
16509 2013-01-18 07:49:13 JST DEBUG:  my backend ID is 2<br>
16509 2013-01-18 07:49:13 JST DEBUG:  StartTransaction<br>
16509 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16509 2013-01-18 07:49:13 JST DEBUG:  CommitTransaction<br>
16509 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16509 2013-01-18 07:49:13 JST DEBUG:  autovacuum: processing database "postgres"<br>
16509 2013-01-18 07:49:13 JST DEBUG:  StartTransaction<br>
16509 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16509 2013-01-18 07:49:13 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
16509 2013-01-18 07:49:13 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
16509 2013-01-18 07:49:13 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
16509 2013-01-18 07:49:13 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
16509 2013-01-18 07:49:13 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
16509 2013-01-18 07:49:13 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
16509 2013-01-18 07:49:13 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
16509 2013-01-18 07:49:13 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
16509 2013-01-18 07:49:13 JST DEBUG:  CommitTransaction<br>
16509 2013-01-18 07:49:13 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16509 2013-01-18 07:49:13 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
16509 2013-01-18 07:49:13 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
16509 2013-01-18 07:49:13 JST DEBUG:  exit(0)<br>
16509 2013-01-18 07:49:13 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16509 2013-01-18 07:49:13 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 07:49:13 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 07:49:13 JST DEBUG:  server process (PID 16509) exited with exit code 0<br>
16388 2013-01-18 07:50:13 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 07:50:13 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 07:50:13 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 07:50:13 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16596 2013-01-18 07:50:13 JST DEBUG:  InitPostgres<br>
16596 2013-01-18 07:50:13 JST DEBUG:  my backend ID is 2<br>
16596 2013-01-18 07:50:13 JST DEBUG:  StartTransaction<br>
16596 2013-01-18 07:50:13 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16596 2013-01-18 07:50:13 JST DEBUG:  CommitTransaction<br>
16596 2013-01-18 07:50:13 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16596 2013-01-18 07:50:13 JST DEBUG:  autovacuum: processing database "postgres"<br>
16596 2013-01-18 07:50:13 JST DEBUG:  StartTransaction<br>
16596 2013-01-18 07:50:13 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16596 2013-01-18 07:50:13 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
16596 2013-01-18 07:50:13 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
16596 2013-01-18 07:50:13 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
16596 2013-01-18 07:50:13 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
16596 2013-01-18 07:50:13 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
16596 2013-01-18 07:50:13 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
16596 2013-01-18 07:50:13 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
16596 2013-01-18 07:50:13 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
16596 2013-01-18 07:50:13 JST DEBUG:  CommitTransaction<br>
16596 2013-01-18 07:50:13 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16596 2013-01-18 07:50:13 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
16596 2013-01-18 07:50:13 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
16596 2013-01-18 07:50:13 JST DEBUG:  exit(0)<br>
16596 2013-01-18 07:50:13 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16596 2013-01-18 07:50:13 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 07:50:13 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 07:50:13 JST DEBUG:  server process (PID 16596) exited with exit code 0<br>
16388 2013-01-18 07:51:13 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 07:51:13 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 07:51:13 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 07:51:13 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16682 2013-01-18 07:51:13 JST DEBUG:  InitPostgres<br>
16682 2013-01-18 07:51:13 JST DEBUG:  my backend ID is 2<br>
16682 2013-01-18 07:51:13 JST DEBUG:  StartTransaction<br>
16682 2013-01-18 07:51:13 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16682 2013-01-18 07:51:13 JST DEBUG:  CommitTransaction<br>
16682 2013-01-18 07:51:13 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16682 2013-01-18 07:51:13 JST DEBUG:  autovacuum: processing database "postgres"<br>
16682 2013-01-18 07:51:13 JST DEBUG:  StartTransaction<br>
16682 2013-01-18 07:51:13 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16682 2013-01-18 07:51:13 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
16682 2013-01-18 07:51:13 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
16682 2013-01-18 07:51:13 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
16682 2013-01-18 07:51:13 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
16682 2013-01-18 07:51:13 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
16682 2013-01-18 07:51:13 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
16682 2013-01-18 07:51:13 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
16682 2013-01-18 07:51:13 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
16682 2013-01-18 07:51:13 JST DEBUG:  CommitTransaction<br>
16682 2013-01-18 07:51:13 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16682 2013-01-18 07:51:13 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
16682 2013-01-18 07:51:13 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
16682 2013-01-18 07:51:13 JST DEBUG:  exit(0)<br>
16682 2013-01-18 07:51:13 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16682 2013-01-18 07:51:13 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 07:51:13 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 07:51:13 JST DEBUG:  server process (PID 16682) exited with exit code 0<br>
16388 2013-01-18 07:52:13 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 07:52:13 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 07:52:13 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 07:52:13 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16767 2013-01-18 07:52:13 JST DEBUG:  InitPostgres<br>
16767 2013-01-18 07:52:13 JST DEBUG:  my backend ID is 2<br>
16767 2013-01-18 07:52:13 JST DEBUG:  StartTransaction<br>
16767 2013-01-18 07:52:13 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16767 2013-01-18 07:52:13 JST DEBUG:  CommitTransaction<br>
16767 2013-01-18 07:52:13 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16767 2013-01-18 07:52:13 JST DEBUG:  autovacuum: processing database "postgres"<br>
16767 2013-01-18 07:52:14 JST DEBUG:  StartTransaction<br>
16767 2013-01-18 07:52:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16767 2013-01-18 07:52:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
16767 2013-01-18 07:52:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
16767 2013-01-18 07:52:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
16767 2013-01-18 07:52:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
16767 2013-01-18 07:52:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
16767 2013-01-18 07:52:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
16767 2013-01-18 07:52:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
16767 2013-01-18 07:52:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
16767 2013-01-18 07:52:14 JST DEBUG:  CommitTransaction<br>
16767 2013-01-18 07:52:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16767 2013-01-18 07:52:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
16767 2013-01-18 07:52:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
16767 2013-01-18 07:52:14 JST DEBUG:  exit(0)<br>
16767 2013-01-18 07:52:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16767 2013-01-18 07:52:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 07:52:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 07:52:14 JST DEBUG:  server process (PID 16767) exited with exit code 0<br>
16388 2013-01-18 07:53:14 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 07:53:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 07:53:14 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 07:53:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16849 2013-01-18 07:53:14 JST DEBUG:  InitPostgres<br>
16849 2013-01-18 07:53:14 JST DEBUG:  my backend ID is 2<br>
16849 2013-01-18 07:53:14 JST DEBUG:  StartTransaction<br>
16849 2013-01-18 07:53:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16849 2013-01-18 07:53:14 JST DEBUG:  CommitTransaction<br>
16849 2013-01-18 07:53:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16849 2013-01-18 07:53:14 JST DEBUG:  autovacuum: processing database "postgres"<br>
16849 2013-01-18 07:53:14 JST DEBUG:  StartTransaction<br>
16849 2013-01-18 07:53:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16849 2013-01-18 07:53:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
16849 2013-01-18 07:53:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
16849 2013-01-18 07:53:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
16849 2013-01-18 07:53:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
16849 2013-01-18 07:53:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
16849 2013-01-18 07:53:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
16849 2013-01-18 07:53:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
16849 2013-01-18 07:53:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
16849 2013-01-18 07:53:14 JST DEBUG:  CommitTransaction<br>
16849 2013-01-18 07:53:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16849 2013-01-18 07:53:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
16849 2013-01-18 07:53:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
16849 2013-01-18 07:53:14 JST DEBUG:  exit(0)<br>
16849 2013-01-18 07:53:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16849 2013-01-18 07:53:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 07:53:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 07:53:14 JST DEBUG:  server process (PID 16849) exited with exit code 0<br>
16388 2013-01-18 07:54:14 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 07:54:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 07:54:14 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 07:54:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16934 2013-01-18 07:54:14 JST DEBUG:  InitPostgres<br>
16934 2013-01-18 07:54:14 JST DEBUG:  my backend ID is 2<br>
16934 2013-01-18 07:54:14 JST DEBUG:  StartTransaction<br>
16934 2013-01-18 07:54:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16934 2013-01-18 07:54:14 JST DEBUG:  CommitTransaction<br>
16934 2013-01-18 07:54:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16934 2013-01-18 07:54:14 JST DEBUG:  autovacuum: processing database "postgres"<br>
16934 2013-01-18 07:54:14 JST DEBUG:  StartTransaction<br>
16934 2013-01-18 07:54:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16934 2013-01-18 07:54:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
16934 2013-01-18 07:54:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
16934 2013-01-18 07:54:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
16934 2013-01-18 07:54:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
16934 2013-01-18 07:54:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
16934 2013-01-18 07:54:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
16934 2013-01-18 07:54:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
16934 2013-01-18 07:54:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
16934 2013-01-18 07:54:14 JST DEBUG:  CommitTransaction<br>
16934 2013-01-18 07:54:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16934 2013-01-18 07:54:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
16934 2013-01-18 07:54:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
16934 2013-01-18 07:54:14 JST DEBUG:  exit(0)<br>
16934 2013-01-18 07:54:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
16934 2013-01-18 07:54:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 07:54:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 07:54:14 JST DEBUG:  server process (PID 16934) exited with exit code 0<br>
16388 2013-01-18 07:55:14 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 07:55:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 07:55:14 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 07:55:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17019 2013-01-18 07:55:14 JST DEBUG:  InitPostgres<br>
17019 2013-01-18 07:55:14 JST DEBUG:  my backend ID is 2<br>
17019 2013-01-18 07:55:14 JST DEBUG:  StartTransaction<br>
17019 2013-01-18 07:55:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17019 2013-01-18 07:55:14 JST DEBUG:  CommitTransaction<br>
17019 2013-01-18 07:55:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17019 2013-01-18 07:55:14 JST DEBUG:  autovacuum: processing database "postgres"<br>
17019 2013-01-18 07:55:14 JST DEBUG:  StartTransaction<br>
17019 2013-01-18 07:55:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17019 2013-01-18 07:55:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17019 2013-01-18 07:55:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
17019 2013-01-18 07:55:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
17019 2013-01-18 07:55:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
17019 2013-01-18 07:55:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
17019 2013-01-18 07:55:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
17019 2013-01-18 07:55:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17019 2013-01-18 07:55:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
17019 2013-01-18 07:55:14 JST DEBUG:  CommitTransaction<br>
17019 2013-01-18 07:55:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17019 2013-01-18 07:55:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
17019 2013-01-18 07:55:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
17019 2013-01-18 07:55:14 JST DEBUG:  exit(0)<br>
17019 2013-01-18 07:55:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
17019 2013-01-18 07:55:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 07:55:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 07:55:14 JST DEBUG:  server process (PID 17019) exited with exit code 0<br>
16388 2013-01-18 07:56:14 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 07:56:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 07:56:14 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 07:56:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17106 2013-01-18 07:56:14 JST DEBUG:  InitPostgres<br>
17106 2013-01-18 07:56:14 JST DEBUG:  my backend ID is 2<br>
17106 2013-01-18 07:56:14 JST DEBUG:  StartTransaction<br>
17106 2013-01-18 07:56:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17106 2013-01-18 07:56:14 JST DEBUG:  CommitTransaction<br>
17106 2013-01-18 07:56:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17106 2013-01-18 07:56:14 JST DEBUG:  autovacuum: processing database "postgres"<br>
17106 2013-01-18 07:56:14 JST DEBUG:  StartTransaction<br>
17106 2013-01-18 07:56:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17106 2013-01-18 07:56:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17106 2013-01-18 07:56:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
17106 2013-01-18 07:56:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
17106 2013-01-18 07:56:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
17106 2013-01-18 07:56:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
17106 2013-01-18 07:56:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
17106 2013-01-18 07:56:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17106 2013-01-18 07:56:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
17106 2013-01-18 07:56:14 JST DEBUG:  CommitTransaction<br>
17106 2013-01-18 07:56:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17106 2013-01-18 07:56:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
17106 2013-01-18 07:56:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
17106 2013-01-18 07:56:14 JST DEBUG:  exit(0)<br>
17106 2013-01-18 07:56:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
17106 2013-01-18 07:56:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 07:56:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 07:56:14 JST DEBUG:  server process (PID 17106) exited with exit code 0<br>
16388 2013-01-18 07:57:14 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 07:57:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 07:57:14 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 07:57:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17190 2013-01-18 07:57:14 JST DEBUG:  InitPostgres<br>
17190 2013-01-18 07:57:14 JST DEBUG:  my backend ID is 2<br>
17190 2013-01-18 07:57:14 JST DEBUG:  StartTransaction<br>
17190 2013-01-18 07:57:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17190 2013-01-18 07:57:14 JST DEBUG:  CommitTransaction<br>
17190 2013-01-18 07:57:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17190 2013-01-18 07:57:14 JST DEBUG:  autovacuum: processing database "postgres"<br>
17190 2013-01-18 07:57:14 JST DEBUG:  StartTransaction<br>
17190 2013-01-18 07:57:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17190 2013-01-18 07:57:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17190 2013-01-18 07:57:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
17190 2013-01-18 07:57:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
17190 2013-01-18 07:57:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
17190 2013-01-18 07:57:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
17190 2013-01-18 07:57:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
17190 2013-01-18 07:57:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17190 2013-01-18 07:57:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
17190 2013-01-18 07:57:14 JST DEBUG:  CommitTransaction<br>
17190 2013-01-18 07:57:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17190 2013-01-18 07:57:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
17190 2013-01-18 07:57:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
17190 2013-01-18 07:57:14 JST DEBUG:  exit(0)<br>
17190 2013-01-18 07:57:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
17190 2013-01-18 07:57:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 07:57:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 07:57:14 JST DEBUG:  server process (PID 17190) exited with exit code 0<br>
16388 2013-01-18 07:58:14 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 07:58:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 07:58:14 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 07:58:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17271 2013-01-18 07:58:14 JST DEBUG:  InitPostgres<br>
17271 2013-01-18 07:58:14 JST DEBUG:  my backend ID is 2<br>
17271 2013-01-18 07:58:14 JST DEBUG:  StartTransaction<br>
17271 2013-01-18 07:58:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17271 2013-01-18 07:58:14 JST DEBUG:  CommitTransaction<br>
17271 2013-01-18 07:58:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17271 2013-01-18 07:58:14 JST DEBUG:  autovacuum: processing database "postgres"<br>
17271 2013-01-18 07:58:14 JST DEBUG:  StartTransaction<br>
17271 2013-01-18 07:58:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17271 2013-01-18 07:58:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17271 2013-01-18 07:58:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
17271 2013-01-18 07:58:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
17271 2013-01-18 07:58:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
17271 2013-01-18 07:58:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
17271 2013-01-18 07:58:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
17271 2013-01-18 07:58:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17271 2013-01-18 07:58:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
17271 2013-01-18 07:58:14 JST DEBUG:  CommitTransaction<br>
17271 2013-01-18 07:58:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17271 2013-01-18 07:58:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
17271 2013-01-18 07:58:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
17271 2013-01-18 07:58:14 JST DEBUG:  exit(0)<br>
17271 2013-01-18 07:58:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
17271 2013-01-18 07:58:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 07:58:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 07:58:14 JST DEBUG:  server process (PID 17271) exited with exit code 0<br>
16388 2013-01-18 07:59:14 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 07:59:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 07:59:14 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 07:59:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17357 2013-01-18 07:59:14 JST DEBUG:  InitPostgres<br>
17357 2013-01-18 07:59:14 JST DEBUG:  my backend ID is 2<br>
17357 2013-01-18 07:59:14 JST DEBUG:  StartTransaction<br>
17357 2013-01-18 07:59:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17357 2013-01-18 07:59:14 JST DEBUG:  CommitTransaction<br>
17357 2013-01-18 07:59:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17357 2013-01-18 07:59:14 JST DEBUG:  autovacuum: processing database "postgres"<br>
17357 2013-01-18 07:59:14 JST DEBUG:  StartTransaction<br>
17357 2013-01-18 07:59:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17357 2013-01-18 07:59:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17357 2013-01-18 07:59:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
17357 2013-01-18 07:59:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
17357 2013-01-18 07:59:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
17357 2013-01-18 07:59:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
17357 2013-01-18 07:59:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
17357 2013-01-18 07:59:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17357 2013-01-18 07:59:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
17357 2013-01-18 07:59:14 JST DEBUG:  CommitTransaction<br>
17357 2013-01-18 07:59:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17357 2013-01-18 07:59:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
17357 2013-01-18 07:59:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
17357 2013-01-18 07:59:14 JST DEBUG:  exit(0)<br>
17357 2013-01-18 07:59:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
17357 2013-01-18 07:59:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 07:59:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 07:59:14 JST DEBUG:  server process (PID 17357) exited with exit code 0<br>
16388 2013-01-18 08:00:14 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 08:00:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 08:00:14 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 08:00:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17442 2013-01-18 08:00:14 JST DEBUG:  InitPostgres<br>
17442 2013-01-18 08:00:14 JST DEBUG:  my backend ID is 2<br>
17442 2013-01-18 08:00:14 JST DEBUG:  StartTransaction<br>
17442 2013-01-18 08:00:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17442 2013-01-18 08:00:14 JST DEBUG:  CommitTransaction<br>
17442 2013-01-18 08:00:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17442 2013-01-18 08:00:14 JST DEBUG:  autovacuum: processing database "postgres"<br>
17442 2013-01-18 08:00:14 JST DEBUG:  StartTransaction<br>
17442 2013-01-18 08:00:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17442 2013-01-18 08:00:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17442 2013-01-18 08:00:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
17442 2013-01-18 08:00:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
17442 2013-01-18 08:00:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
17442 2013-01-18 08:00:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
17442 2013-01-18 08:00:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
17442 2013-01-18 08:00:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17442 2013-01-18 08:00:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
17442 2013-01-18 08:00:14 JST DEBUG:  CommitTransaction<br>
17442 2013-01-18 08:00:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17442 2013-01-18 08:00:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
17442 2013-01-18 08:00:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
17442 2013-01-18 08:00:14 JST DEBUG:  exit(0)<br>
17442 2013-01-18 08:00:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
17442 2013-01-18 08:00:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 08:00:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 08:00:14 JST DEBUG:  server process (PID 17442) exited with exit code 0<br>
16388 2013-01-18 08:01:14 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 08:01:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 08:01:14 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 08:01:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17529 2013-01-18 08:01:14 JST DEBUG:  InitPostgres<br>
17529 2013-01-18 08:01:14 JST DEBUG:  my backend ID is 2<br>
17529 2013-01-18 08:01:14 JST DEBUG:  StartTransaction<br>
17529 2013-01-18 08:01:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17529 2013-01-18 08:01:14 JST DEBUG:  CommitTransaction<br>
17529 2013-01-18 08:01:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17529 2013-01-18 08:01:14 JST DEBUG:  autovacuum: processing database "postgres"<br>
17529 2013-01-18 08:01:14 JST DEBUG:  StartTransaction<br>
17529 2013-01-18 08:01:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17529 2013-01-18 08:01:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17529 2013-01-18 08:01:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
17529 2013-01-18 08:01:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
17529 2013-01-18 08:01:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
17529 2013-01-18 08:01:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
17529 2013-01-18 08:01:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
17529 2013-01-18 08:01:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17529 2013-01-18 08:01:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
17529 2013-01-18 08:01:14 JST DEBUG:  CommitTransaction<br>
17529 2013-01-18 08:01:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17529 2013-01-18 08:01:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
17529 2013-01-18 08:01:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
17529 2013-01-18 08:01:14 JST DEBUG:  exit(0)<br>
17529 2013-01-18 08:01:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
17529 2013-01-18 08:01:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 08:01:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 08:01:14 JST DEBUG:  server process (PID 17529) exited with exit code 0<br>
16388 2013-01-18 08:02:14 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 08:02:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 08:02:14 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 08:02:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17610 2013-01-18 08:02:14 JST DEBUG:  InitPostgres<br>
17610 2013-01-18 08:02:14 JST DEBUG:  my backend ID is 2<br>
17610 2013-01-18 08:02:14 JST DEBUG:  StartTransaction<br>
17610 2013-01-18 08:02:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17610 2013-01-18 08:02:14 JST DEBUG:  CommitTransaction<br>
17610 2013-01-18 08:02:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17610 2013-01-18 08:02:14 JST DEBUG:  autovacuum: processing database "postgres"<br>
17610 2013-01-18 08:02:14 JST DEBUG:  StartTransaction<br>
17610 2013-01-18 08:02:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17610 2013-01-18 08:02:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17610 2013-01-18 08:02:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
17610 2013-01-18 08:02:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
17610 2013-01-18 08:02:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
17610 2013-01-18 08:02:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
17610 2013-01-18 08:02:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
17610 2013-01-18 08:02:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17610 2013-01-18 08:02:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
17610 2013-01-18 08:02:14 JST DEBUG:  CommitTransaction<br>
17610 2013-01-18 08:02:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17610 2013-01-18 08:02:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
17610 2013-01-18 08:02:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
17610 2013-01-18 08:02:14 JST DEBUG:  exit(0)<br>
17610 2013-01-18 08:02:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
17610 2013-01-18 08:02:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 08:02:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 08:02:14 JST DEBUG:  server process (PID 17610) exited with exit code 0<br>
16388 2013-01-18 08:03:14 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 08:03:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 08:03:14 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 08:03:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17696 2013-01-18 08:03:14 JST DEBUG:  InitPostgres<br>
17696 2013-01-18 08:03:14 JST DEBUG:  my backend ID is 2<br>
17696 2013-01-18 08:03:14 JST DEBUG:  StartTransaction<br>
17696 2013-01-18 08:03:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17696 2013-01-18 08:03:14 JST DEBUG:  CommitTransaction<br>
17696 2013-01-18 08:03:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17696 2013-01-18 08:03:14 JST DEBUG:  autovacuum: processing database "postgres"<br>
17696 2013-01-18 08:03:14 JST DEBUG:  StartTransaction<br>
17696 2013-01-18 08:03:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17696 2013-01-18 08:03:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17696 2013-01-18 08:03:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
17696 2013-01-18 08:03:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
17696 2013-01-18 08:03:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
17696 2013-01-18 08:03:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
17696 2013-01-18 08:03:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
17696 2013-01-18 08:03:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17696 2013-01-18 08:03:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
17696 2013-01-18 08:03:14 JST DEBUG:  CommitTransaction<br>
17696 2013-01-18 08:03:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17696 2013-01-18 08:03:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
17696 2013-01-18 08:03:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
17696 2013-01-18 08:03:14 JST DEBUG:  exit(0)<br>
17696 2013-01-18 08:03:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
17696 2013-01-18 08:03:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 08:03:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 08:03:14 JST DEBUG:  server process (PID 17696) exited with exit code 0<br>
16388 2013-01-18 08:04:14 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 08:04:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 08:04:14 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 08:04:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17781 2013-01-18 08:04:14 JST DEBUG:  InitPostgres<br>
17781 2013-01-18 08:04:14 JST DEBUG:  my backend ID is 2<br>
17781 2013-01-18 08:04:14 JST DEBUG:  StartTransaction<br>
17781 2013-01-18 08:04:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17781 2013-01-18 08:04:14 JST DEBUG:  CommitTransaction<br>
17781 2013-01-18 08:04:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17781 2013-01-18 08:04:14 JST DEBUG:  autovacuum: processing database "postgres"<br>
17781 2013-01-18 08:04:14 JST DEBUG:  StartTransaction<br>
17781 2013-01-18 08:04:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17781 2013-01-18 08:04:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17781 2013-01-18 08:04:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
17781 2013-01-18 08:04:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
17781 2013-01-18 08:04:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
17781 2013-01-18 08:04:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
17781 2013-01-18 08:04:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
17781 2013-01-18 08:04:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17781 2013-01-18 08:04:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
17781 2013-01-18 08:04:14 JST DEBUG:  CommitTransaction<br>
17781 2013-01-18 08:04:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17781 2013-01-18 08:04:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
17781 2013-01-18 08:04:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
17781 2013-01-18 08:04:14 JST DEBUG:  exit(0)<br>
17781 2013-01-18 08:04:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
17781 2013-01-18 08:04:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 08:04:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 08:04:14 JST DEBUG:  server process (PID 17781) exited with exit code 0<br>
16388 2013-01-18 08:05:14 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 08:05:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 08:05:14 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 08:05:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17866 2013-01-18 08:05:14 JST DEBUG:  InitPostgres<br>
17866 2013-01-18 08:05:14 JST DEBUG:  my backend ID is 2<br>
17866 2013-01-18 08:05:14 JST DEBUG:  StartTransaction<br>
17866 2013-01-18 08:05:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17866 2013-01-18 08:05:14 JST DEBUG:  CommitTransaction<br>
17866 2013-01-18 08:05:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17866 2013-01-18 08:05:14 JST DEBUG:  autovacuum: processing database "postgres"<br>
17866 2013-01-18 08:05:14 JST DEBUG:  StartTransaction<br>
17866 2013-01-18 08:05:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17866 2013-01-18 08:05:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17866 2013-01-18 08:05:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
17866 2013-01-18 08:05:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
17866 2013-01-18 08:05:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
17866 2013-01-18 08:05:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
17866 2013-01-18 08:05:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
17866 2013-01-18 08:05:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17866 2013-01-18 08:05:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
17866 2013-01-18 08:05:14 JST DEBUG:  CommitTransaction<br>
17866 2013-01-18 08:05:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17866 2013-01-18 08:05:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
17866 2013-01-18 08:05:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
17866 2013-01-18 08:05:14 JST DEBUG:  exit(0)<br>
17866 2013-01-18 08:05:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
17866 2013-01-18 08:05:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 08:05:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 08:05:14 JST DEBUG:  server process (PID 17866) exited with exit code 0<br>
16388 2013-01-18 08:06:14 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 08:06:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 08:06:14 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 08:06:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17953 2013-01-18 08:06:14 JST DEBUG:  InitPostgres<br>
17953 2013-01-18 08:06:14 JST DEBUG:  my backend ID is 2<br>
17953 2013-01-18 08:06:14 JST DEBUG:  StartTransaction<br>
17953 2013-01-18 08:06:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17953 2013-01-18 08:06:14 JST DEBUG:  CommitTransaction<br>
17953 2013-01-18 08:06:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17953 2013-01-18 08:06:14 JST DEBUG:  autovacuum: processing database "postgres"<br>
17953 2013-01-18 08:06:14 JST DEBUG:  StartTransaction<br>
17953 2013-01-18 08:06:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17953 2013-01-18 08:06:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17953 2013-01-18 08:06:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
17953 2013-01-18 08:06:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
17953 2013-01-18 08:06:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
17953 2013-01-18 08:06:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
17953 2013-01-18 08:06:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
17953 2013-01-18 08:06:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
17953 2013-01-18 08:06:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
17953 2013-01-18 08:06:14 JST DEBUG:  CommitTransaction<br>
17953 2013-01-18 08:06:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
17953 2013-01-18 08:06:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
17953 2013-01-18 08:06:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
17953 2013-01-18 08:06:14 JST DEBUG:  exit(0)<br>
17953 2013-01-18 08:06:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
17953 2013-01-18 08:06:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 08:06:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 08:06:14 JST DEBUG:  server process (PID 17953) exited with exit code 0<br>
16388 2013-01-18 08:07:14 JST DEBUG:  StartTransaction<br>
16388 2013-01-18 08:07:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
16388 2013-01-18 08:07:14 JST DEBUG:  CommitTransaction<br>
16388 2013-01-18 08:07:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
18032 2013-01-18 08:07:14 JST DEBUG:  InitPostgres<br>
18032 2013-01-18 08:07:14 JST DEBUG:  my backend ID is 2<br>
18032 2013-01-18 08:07:14 JST DEBUG:  StartTransaction<br>
18032 2013-01-18 08:07:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
18032 2013-01-18 08:07:14 JST DEBUG:  CommitTransaction<br>
18032 2013-01-18 08:07:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
18032 2013-01-18 08:07:14 JST DEBUG:  autovacuum: processing database "postgres"<br>
18032 2013-01-18 08:07:14 JST DEBUG:  StartTransaction<br>
18032 2013-01-18 08:07:14 JST DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
18032 2013-01-18 08:07:14 JST DEBUG:  pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
18032 2013-01-18 08:07:14 JST DEBUG:  pg_class: vac: 0 (threshold 108), anl: 0 (threshold 79)<br>
18032 2013-01-18 08:07:14 JST DEBUG:  pg_attribute: vac: 0 (threshold 499), anl: 0 (threshold 275)<br>
18032 2013-01-18 08:07:14 JST DEBUG:  pg_opclass: vac: 0 (threshold 74), anl: 0 (threshold 62)<br>
18032 2013-01-18 08:07:14 JST DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)<br>
18032 2013-01-18 08:07:14 JST DEBUG:  pg_amproc: vac: 0 (threshold 107), anl: 0 (threshold 79)<br>
18032 2013-01-18 08:07:14 JST DEBUG:  pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)<br>
18032 2013-01-18 08:07:14 JST DEBUG:  pg_index: vac: 0 (threshold 72), anl: 0 (threshold 61)<br>
18032 2013-01-18 08:07:14 JST DEBUG:  CommitTransaction<br>
18032 2013-01-18 08:07:14 JST DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:<br>
18032 2013-01-18 08:07:14 JST DEBUG:  shmem_exit(0): 8 callbacks to make<br>
18032 2013-01-18 08:07:14 JST DEBUG:  proc_exit(0): 2 callbacks to make<br>
18032 2013-01-18 08:07:14 JST DEBUG:  exit(0)<br>
18032 2013-01-18 08:07:14 JST DEBUG:  shmem_exit(-1): 0 callbacks to make<br>
18032 2013-01-18 08:07:14 JST DEBUG:  proc_exit(-1): 0 callbacks to make<br>
16374 2013-01-18 08:07:14 JST DEBUG:  reaping dead processes<br>
16374 2013-01-18 08:07:14 JST DEBUG:  server process (PID 18032) exited with exit code 0<br>
<br></blockquote></div><br>