BUG #7969: Postgres Recovery Fatal With: "incorrect local pin count: 2"

The following bug has been logged on the website:

Bug reference: 7969
Logged by: Yunong Xiao
Email address: yjxiao(at)gmail(dot)com
PostgreSQL version: 9.2.2
Operating system: SmartOS (Solaris)
Description:

I have an instance of postgresql 9.2.2 running on Solaris. At some point the
zone the postgresql was running on was restarted (effectively a power cycle)
and postgresql consistently crashes on recovery with the following log
snippet: (full log and postgresql.conf attached at the end of this email)

2013-03-15 22:00:49.510 UTCLOG: database system was not properly shut down;
automatic recovery in progress
2013-03-15 22:00:49.510 UTCDEBUG: resetting unlogged relations: cleanup 1
init 0
2013-03-15 22:00:49.511 UTCLOG: redo starts at 0/551EC58
2013-03-15 22:00:49.515 UTCDEBUG: page 10 of relation base/16384/16666 does
not exist
2013-03-15 22:00:49.515 UTCCONTEXT: xlog redo update: rel 1663/16384/16666;
tid 8/4; new 10/5
2013-03-15 22:00:49.515 UTCFATAL: incorrect local pin count: 2

I am running postgres on ZFS with fsync=on, which as far as I can tell,
guarantees that there can be no data corruption. I have included the
postgres data directory as a tarball here:
https://download.joyent.com/pub/postgresql/corrupted-pg.tar and this problem
can be reproduced by untarring the data directory and running as the
postgres user `postgres -D <path_to_data_dir>`

Full postgresql logs:

2013-03-15 22:00:49.509 UTCLOG: database system was interrupted while in
recovery at 2013-03-15 21:55:49 UTC
2013-03-15 22:00:49.509 UTCHINT: This probably means that some data is
corrupted and you will have to use the last backup for recovery.
2013-03-15 22:00:49.510 UTCDEBUG: checkpoint record is at 0/551F6B0
2013-03-15 22:00:49.510 UTCDEBUG: redo record is at 0/551EC58; shutdown
FALSE
2013-03-15 22:00:49.510 UTCDEBUG: next transaction ID: 0/1693; next OID:
24576
2013-03-15 22:00:49.510 UTCDEBUG: next MultiXactId: 1; next
MultiXactOffset: 0
2013-03-15 22:00:49.510 UTCDEBUG: oldest unfrozen transaction ID: 665, in
database 1
2013-03-15 22:00:49.510 UTCDEBUG: transaction ID wrap limit is 2147484312,
limited by database with OID 1
2013-03-15 22:00:49.510 UTCLOG: database system was not properly shut down;
automatic recovery in progress
2013-03-15 22:00:49.510 UTCDEBUG: resetting unlogged relations: cleanup 1
init 0
2013-03-15 22:00:49.511 UTCLOG: redo starts at 0/551EC58
2013-03-15 22:00:49.515 UTCDEBUG: page 10 of relation base/16384/16666 does
not exist
2013-03-15 22:00:49.515 UTCCONTEXT: xlog redo update: rel 1663/16384/16666;
tid 8/4; new 10/5
2013-03-15 22:00:49.515 UTCFATAL: incorrect local pin count: 2
2013-03-15 22:00:49.515 UTCCONTEXT: xlog redo clean: rel 1663/16384/16666;
blk 8 remxid 1729
2013-03-15 22:00:49.515 UTCDEBUG: shmem_exit(1): 4 callbacks to make
2013-03-15 22:00:49.515 UTCDEBUG: proc_exit(1): 2 callbacks to make
2013-03-15 22:00:49.515 UTCDEBUG: exit(1)
2013-03-15 22:00:49.515 UTCDEBUG: shmem_exit(-1): 0 callbacks to make
2013-03-15 22:00:49.515 UTCDEBUG: proc_exit(-1): 0 callbacks to make
2013-03-15 22:00:49.518 UTCDEBUG: reaping dead processes
2013-03-15 22:00:49.518 UTCLOG: startup process (PID 23162) exited with
exit code 1
2013-03-15 22:00:49.518 UTCLOG: aborting startup due to startup process
failure
2013-03-15 22:00:49.518 UTCDEBUG: shmem_exit(1): 3 callbacks to make
2013-03-15 22:00:49.524 UTCDEBUG: proc_exit(1): 3 callbacks to make
2013-03-15 22:00:49.524 UTCDEBUG: exit(1)
2013-03-15 22:00:49.524 UTCDEBUG: shmem_exit(-1): 0 callbacks to make
2013-03-15 22:00:49.524 UTCDEBUG: proc_exit(-1): 0 callbacks to make
2013-03-15 22:00:49.526 UTCDEBUG: logger shutting down
2013-03-15 22:00:49.526 UTCDEBUG: shmem_exit(0): 0 callbacks to make
2013-03-15 22:00:49.526 UTCDEBUG: proc_exit(0): 0 callbacks to make
2013-03-15 22:00:49.527 UTCDEBUG: exit(0)
2013-03-15 22:00:49.527 UTCDEBUG: shmem_exit(-1): 0 callbacks to make
2013-03-15 22:00:49.527 UTCDEBUG: proc_exit(-1): 0 callbacks to make
postgresql-2013-03-15_220049.log (END)

postgresql.conf

listen_addresses = '0.0.0.0' # what IP address(es) to listen on;
port = 5432 # (change requires restart)
max_connections = 100 # (change requires restart)
shared_buffers = 32MB # min 128kB
wal_level = hot_standby # minimal, archive, or hot_standby
fsync = on # turns forced synchronization on or off
synchronous_commit = remote_write
full_page_writes = off # recover from partial page writes
max_wal_senders = 15 # max number of walsender processes
wal_keep_segments = 1000 # in logfile segments, 16MB each; 0 disables
synchronous_standby_names = '' # standby servers that provide sync rep
hot_standby = on # "on" allows queries during recovery
max_standby_archive_delay = 30s # max delay before canceling queries
max_standby_streaming_delay = 30s # max delay before canceling queries
wal_receiver_status_interval = 10s # send replies at least this often
hot_standby_feedback = off # send info from standby to prevent
log_destination = 'stderr' # Valid values are combinations of
logging_collector = on # Enable capturing of stderr and csvlog
log_directory = '/var/pg/' # directory where log files are written,
log_filename = 'postgresql-%Y-%m-%d_%H%M%S.log' # log file name pattern,
log_file_mode = 0600 # creation mode for log files,
log_rotation_age = 0 # Automatic rotation of logfiles will
log_rotation_size = 0 # Automatic rotation of logfiles will
log_min_messages = debug5 # values in order of decreasing detail:
log_line_prefix = '%m' # special values:
log_timezone = 'UTC'
datestyle = 'iso, mdy'
timezone = 'UTC'
lc_messages = 'C' # locale for system error message
lc_monetary = 'C' # locale for monetary formatting
lc_numeric = 'C' # locale for number formatting
lc_time = 'C' # locale for time formatting
default_text_search_config = 'pg_catalog.english'