Streaming Replication Log is puzzling me

Question

I have a streaming replication hot-standby setup, which seems to be running all good. I can login, execute selects and the result seems to be up-to-date with the master. However in the log of the standby, I see a lot of these:

cp: cannot stat `/mnt/wal_drive/wals/0000000100004BA800000070': No such file or directory
2014-02-28 16:00:37 CET LOG:  record with zero length at 4BA8/70DD79D0
2014-02-28 16:00:37 CET LOG:  started streaming WAL from primary at 4BA8/70000000 on timeline 1
2014-02-28 16:02:59 CET FATAL:  could not receive data from WAL stream: SSL error: sslv3 alert unexpected message

What does each of these mean, and should I worry about any of them?

PS. In the master I see some of these, which I expect to be related to the SSL thing:

2014-02-28 16:10:33 CET LOG:  SSL renegotiation failure
2014-02-28 16:10:33 CET LOG:  SSL error: unexpected record

I'm running postgresql 9.3 on ubuntu 12.04

EDIT

Regarding the WAL logs I have the following setup:

On both my master and my slave I have mounted a network storage in fstab using a cifs command. The directory is chowned to be owned by the postgres user.

On my master I have the following settings in postgresql.conf:

archive_mode = on
archive_command = 'rsync -a %p /mnt/wal_drive/wals/%f </dev/null'

On the slave I have hot_standby = on and the following recovery.conf:

standby_mode = 'on'
primary_conninfo = 'host=localhost port=5433 user=replicator password=some_pass'
trigger_file = '/tmp/pgsql.trigger'
restore_command = 'cp -f /mnt/wal_drive/wals/%f %p </dev/null'
archive_cleanup_command = '/usr/lib/postgresql/9.3/bin/pg_archivecleanup /mnt/wal_drive/wals/ %r'

I have an ssh-tunnel forwarding port 5433 of the slave to port 5432 on the master, so connecting on localhost:5433 is actually the master db.

Answer 1

You appear to have two separate problems an issue with OpenSSL renegotiation.

First - nope, I was wrong, see Daniel's answer.

Second, you're being bitten by an OpenSSL issue with renegotiations. Searching for the error message would've told you this. As noted in that bug report:

Workaround is to set 'ssl_renegotiation_limit=0' in postgresql.conf

which asks PostgreSQL to tell OpenSSL to stop attempting renegotiations, since that version of OpenSSL has broken renegotiation support.

Answer 2

This message:

cp: cannot stat `/mnt/wal_drive/wals/0000000100004BA800000070': No such file or directory

is just the output or the restore_command when a not-yet-existing file is requested. This is normal and documented in Archive Recovery Settings:

restore_command (string)
...

It is important for the command to return a zero exit status only if it succeeds. The command will be asked for file names that are not present in the archive; it must return nonzero when so asked.

To avoid this message, you may combine cp with test -e /path/to/file && ... to silently check for file existence in the restore_command or come up with a more elaborate script.

As for this other message:

LOG: record with zero length at 4BA8/70DD79D0

it's harmless at server start. It probably means that you copied pg_xlog from a live master, so that the newest WAL file from there is unfinished. If the WAL was in unrepairable condition, the server wouldn't start at all.

The only real problem is the SSL renegociation issue but it's answered already.