How to verify that a PostgreSQL base + WAL backup has been restored correctly
The answer will contain two sections - first, what's acceptable to see in the logs after the restore, and second a few examples of what is not. The first section should be fairly deterministic, while the second one is basically a random assortment of whatever happened to us that indicated we had a problem.

Acceptable log output

at the start:

2015-07-23 06:51:24 UTC LOG: database system was interrupted; last known up at 2015-07-23 02:10:42 UTC


It's important to see that the restoring PostgreSQL knows when it was last up. I think that's so because that means it's starting from a checkpoint.

xlog min recovery request ... is past current point

Right at the beginning, a few of these can happen:

2015-07-23 06:51:30 UTC WARNING:  xlog min recovery request 1027/B0A28D98 is past current point 1027/2BE36DA8
2015-07-23 06:51:30 UTC CONTEXT:  writing block 0 of relation base/117264/9551898_vm
       xlog redo insert: rel 1663/117264/8310261; tid 68622/40


But according to http://www.postgresql.org/message-id/CAB7nPqTd43hqpuC+M8fo+xkqHv1WtFe_16NUttu1pHcBtZhZmw@mail.gmail.com that is harmless

FATAL: the database system is starting up

Any number of these can happen:

2015-07-23 06:51:24 UTC FATAL:  the database system is starting up


This should actually be harmless because they were in our case the result of automated SELECT 1 ping-like queries that scripts run to check that PostgreSQL is ready.

unexpected pageaddr ... in log file ..., segment ..., offset ...

At the end, there's this:

2015-07-23 06:52:21 UTC LOG:  restored log file "0000000100001027000000B2" from archive
2015-07-23 06:52:21 UTC LOG:  consistent recovery state reached at 1027/B2F8F2F8
sh: 1: cannot open ../../../wal_backup/0000000100001027000000B3: No such file
2015-07-23 06:52:21 UTC LOG:  unexpected pageaddr 1027/AA000000 in log file 4135, segment 179, offset 0
2015-07-23 06:52:21 UTC LOG:  redo done at 1027/B2F8F2F8
2015-07-23 06:52:21 UTC LOG:  last completed transaction was at log time 2015-07-23 02:17:33.842307+00


But according to http://www.postgresql.org/message-id/CAGrpgQ-BbXUNErrAtToYhRyUef9_GdUQz1T3CXbpTMLTnuKANQ@mail.gmail.com that's also harmless

Note that there may be more of the WAL restorations after that point:

2015-07-23 06:52:21 UTC LOG:  restored log file "0000000100001027000000B2" from archive


That would merely mean that you supplied more WAL files via recovery.conf than strictly necessary.

00000002.history: No such file

At the very end of the WAL unroll process there's this:

sh: 1: cannot open ../../../wal_backup/00000002.history: No such file
2015-07-23 06:52:21 UTC LOG:  selected new timeline ID: 2
sh: 1: cannot open ../../../wal_backup/00000001.history: No such file
2015-07-23 06:52:21 UTC LOG:  archive recovery complete


This is apparently/hopefully irrelevant, because that's where the restored database (clone) starts a new life (timeline).

Unacceptable log output

at the start:

2015-07-20 12:38:31 UTC LOG: database system was interrupted while in recovery at log time 2015-07-20 01:41:22 UTC


This is critical - it means that the backup process did not start at the right time - after a pg_start_backup(...) checkpoint - rather that the database was working normally and was at some random point, which means that this restore is more akin to restoring a crashed database.

missing chunk in pg_toast...

This indicates that the restore wasn't right. As a quick fix, we tried the recipe from http://postgresql.nabble.com/select-table-indicate-missing-chunk-number-0-for-toast-value-96635-in-pg-toast-2619-td5682176.html

mydb=# vacuum analyze mytable; -- trigger the error to see the problem toast
ERROR:  missing chunk number 0 for toast value 13044178 in pg_toast_2619
mydb=# reindex table pg_toast.pg_toast_2619;
REINDEX


This could sometimes get the table back in a working state, but it would also sometimes not have that effect. After that we poked at it some more, and thought we found it's just pg_statistic which is disposable:

mydb=# reindex table pg_statistic;
ERROR:  could not create unique index "pg_statistic_relid_att_inh_index"
DETAIL:  Key (starelid, staattnum, stainherit)=(884792, 34, f) is duplicated.
mydb=# delete from pg_statistic;
DELETE 188540
mydb=# reindex table pg_statistic;
REINDEX
mydb=# vacuum analyze mytable;
VACUUM


right sibling's left-link doesn't match

CREATE TABLE "myschema"."mytable" ( ... )
ERROR: right sibling's left-link doesn't match: block 27 links to 21379 instead of expected 21393 in index "pg_depend_reference_index"


We tried to quickly bypass this by doing:

mydb=# set zero_damaged_pages=on;
SET
mydb=# reindex table pg_depend;
REINDEX
mydb=# set zero_damaged_pages=off;
SET


could not read block in file ...

2015-05-12 13:32:53 UTC ERROR:  could not read block 76408 in file "pg_tblspc/4606764/PG_9.1_201105231/117264/4614269": read only 0 of 8192 bytes


This was obviously a bummer. We couldn't quickly hack our way around this:

mydb=# select cl.relfilenode, nsp.nspname as schema_name, cl.relname, cl.relkind from pg_class cl join pg_namespace nsp on cl.relnamespace = nsp.oid where relfilenode = 4614269;
 relfilenode | schema_name | relname | relkind
-------------+-------------+---------+---------
     4614269 | myschema    | mytable | r
(1 row)

mydb=# select pg_relation_filepath('myschema.mytable');
               pg_relation_filepath
---------------------------------------------------
 pg_tblspc/4606764/PG_9.1_201105231/117264/4614269
(1 row)

% sudo ls -lah /var/lib/postgresql/9.1/main/pg_tblspc/4606764/PG_9.1_201105231/117264/4614269
-rw------- 1 postgres postgres 597M May 11 19:22 /var/lib/postgresql/9.1/main/pg_tblspc/4606764/PG_9.1_201105231/117264/4614269


That was a good indicator that too much data was getting "lost".

duplicate key value violates unique constraint "pg_type_typname_nsp_index"

This was another indicator that the restore was broken:

CREATE TABLE "myschema"."mytable" ( ... )
ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index" DETAIL: Key (typname, typnamespace)=(mytable_mycolumn_seq, 3780903) already exists.


The quick hack for this was to move the sequence position:

SELECT setval('mytable_id_seq', (SELECT MAX(id) FROM mytable));