Failover is not successful in Postgresql 9.0

Question

I am using PostgreSQL9.0 with Linux. I am trying to do faiover using java. So, I am able to create the trigger file. But after creating trigger file Postgres server is stopping. I think someone is killing server process. In pg_log it is writing:--

2011-11-16 15:25:18 ETC/GMT LOG:  startup process (PID 32542) was terminated by signal 6: Aborted
2011-11-16 15:25:18 ETC/GMT LOG:  terminating any other active server processes
2011-11-16 15:25:18 ETC/GMT DEBUG:  sending SIGQUIT to process 32546
2011-11-16 15:25:18 ETC/GMT DEBUG:  sending SIGQUIT to process 32547
2011-11-16 15:25:18 ETC/GMT DEBUG:  shmem_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  proc_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  reaping dead processes
2011-11-16 15:25:18 ETC/GMT DEBUG:  shmem_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  proc_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  reaping dead processes
2011-11-16 15:25:18 ETC/GMT DEBUG:  shmem_exit(1): 3 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  proc_exit(1): 3 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  exit(1)
2011-11-16 15:25:18 ETC/GMT DEBUG:  shmem_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  proc_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  logger shutting down
2011-11-16 15:25:18 ETC/GMT DEBUG:  shmem_exit(0): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  proc_exit(0): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  exit(0)
2011-11-16 15:25:18 ETC/GMT DEBUG:  shmem_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  proc_exit(-1): 0 callbacks to make

and because of shutting down the server it is not able to come up as Primary, still in recovery mode.

when i start postgres server using pg_ctl manually then standby come up in production mode.

please tell me what should i do to solve this. who is sending SIGHQUIT signal to postmaster?

---

here is the Log:

2011-11-16 15:25:12 ETC/GMT DEBUG:  executing restore command "cp /data/PostgreSQL/testdata/archive/000000030000000000000008 "pg_xlog/RECOVERYXLOG""
cp: cannot stat `/data/PostgreSQL/testdata/archive/000000030000000000000008': No such file or directory
2011-11-16 15:25:12 ETC/GMT DEBUG:  could not restore file "000000030000000000000008" from archive: return code 256
2011-11-16 15:25:12 ETC/GMT DEBUG:  could not open file "pg_xlog/000000030000000000000008" (log file 0, segment 8): No such file or directory
2011-11-16 15:25:14 ETC/GMT DEBUG:  skipping restartpoint, already performed at 0/8000020
2011-11-16 15:25:18 ETC/GMT DEBUG:  find_in_dynamic_libpath: trying "/data/PostgreSQL/lib/postgresql/libpqwalreceiver"
2011-11-16 15:25:18 ETC/GMT DEBUG:  find_in_dynamic_libpath: trying "/data/PostgreSQL/lib/postgresql/libpqwalreceiver.so"
2011-11-16 15:25:18 ETC/GMT FATAL:  could not connect to the primary server: could not connect to server: Connection refused
                Is the server running on host "172.168.1.28" and accepting
                TCP/IP connections on port 5433?

2011-11-16 15:25:18 ETC/GMT DEBUG:  shmem_exit(1): 5 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  proc_exit(1): 2 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  exit(1)
2011-11-16 15:25:18 ETC/GMT DEBUG:  shmem_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  proc_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  reaping dead processes
2011-11-16 15:25:18 ETC/GMT DEBUG:  executing restore command "cp /data/PostgreSQL/testdata/archive/000000030000000000000008 "pg_xlog/RECOVERYXLOG""
cp: cannot stat `/data/PostgreSQL/testdata/archive/000000030000000000000008': No such file or directory
2011-11-16 15:25:18 ETC/GMT DEBUG:  could not restore file "000000030000000000000008" from archive: return code 256
2011-11-16 15:25:18 ETC/GMT PANIC:  could not open file "pg_xlog/000000030000000000000008" (log file 0, segment 8): Permission denied
2011-11-16 15:25:18 ETC/GMT DEBUG:  reaping dead processes
2011-11-16 15:25:18 ETC/GMT LOG:  startup process (PID 32542) was terminated by signal 6: Aborted
2011-11-16 15:25:18 ETC/GMT LOG:  terminating any other active server processes
2011-11-16 15:25:18 ETC/GMT DEBUG:  sending SIGQUIT to process 32546
2011-11-16 15:25:18 ETC/GMT DEBUG:  sending SIGQUIT to process 32547
2011-11-16 15:25:18 ETC/GMT DEBUG:  shmem_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  proc_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  reaping dead processes
2011-11-16 15:25:18 ETC/GMT DEBUG:  shmem_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  proc_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  reaping dead processes
2011-11-16 15:25:18 ETC/GMT DEBUG:  shmem_exit(1): 3 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  proc_exit(1): 3 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  exit(1)
2011-11-16 15:25:18 ETC/GMT DEBUG:  shmem_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  proc_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  logger shutting down
2011-11-16 15:25:18 ETC/GMT DEBUG:  shmem_exit(0): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  proc_exit(0): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  exit(0)
2011-11-16 15:25:18 ETC/GMT DEBUG:  shmem_exit(-1): 0 callbacks to make
2011-11-16 15:25:18 ETC/GMT DEBUG:  proc_exit(-1): 0 callbacks to make

Answer 1

So looking at your log, there seems to be issues with log shipping coming from the primary server:

2011-11-16 15:25:12 ETC/GMT DEBUG: executing restore command "cp /data/PostgreSQL/testdata/archive/000000030000000000000008 "pg_xlog/RECOVERYXLOG"" cp: cannot stat `/data/PostgreSQL/testdata/archive/000000030000000000000008': No such file or directory 
2011-11-16 15:25:18 ETC/GMT DEBUG: could not restore file "000000030000000000000008" from archive: return code 256 
2011-11-16 15:25:18 ETC/GMT PANIC: could not open file "pg_xlog/000000030000000000000008" (log file 0, segment 8): Permission denied 2011-11-16 

Are you sure that log files are being copied correctly from the server and are read/writeable by the local postgres process? I would verify that.

The other error I see (which I'm not familiar with, it seems something that they added since the last time I set a standby server) is this:

15:25:18 ETC/GMT FATAL: could not connect to the primary server: could not connect to server: Connection refused Is the server running on host "172.168.1.28" and accepting TCP/IP connections on port 5433?

Are you sure the connection info is correct? Can you see the incoming connection in the primary server?

Looking at this log, it seems that server is not in consistent state when you hit the trigger file, which causes the server to shutdown when you try to finish the startup sequence. If you make sure the log shipping works correctly, you should be able to get it to start up. Hope this helps.