I took several snapshots. In all cases the FS was fine. In one case
the db looked like on recovery it thought there were outstanding
pages to be written to disk as seen below and the db wouldn't start.
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [9-1] 2007-06-21
00:39:43 PDTLOG: redo done at 71/99870670
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [10-1] 2007-06-21
00:39:43 PDTWARNING: page 28905 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [11-1] 2007-06-21
00:39:43 PDTWARNING: page 13626 of relation 1663/16384/76716 did not
exist
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [12-1] 2007-06-21
00:39:43 PDTWARNING: page 28904 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [13-1] 2007-06-21
00:39:43 PDTWARNING: page 26711 of relation 1663/16384/76719 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [14-1] 2007-06-21
00:39:43 PDTWARNING: page 28900 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [15-1] 2007-06-21
00:39:43 PDTWARNING: page 3535208 of relation 1663/16384/33190 did
not exist
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [16-1] 2007-06-21
00:39:43 PDTWARNING: page 28917 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [17-1] 2007-06-21
00:39:43 PDTWARNING: page 3535207 of relation 1663/16384/33190 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [18-1] 2007-06-21
00:39:43 PDTWARNING: page 28916 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [19-1] 2007-06-21
00:39:43 PDTWARNING: page 28911 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [20-1] 2007-06-21
00:39:43 PDTWARNING: page 26708 of relation 1663/16384/76719 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [21-1] 2007-06-21
00:39:43 PDTWARNING: page 28914 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [22-1] 2007-06-21
00:39:43 PDTWARNING: page 28909 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [23-1] 2007-06-21
00:39:43 PDTWARNING: page 28908 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [24-1] 2007-06-21
00:39:43 PDTWARNING: page 28913 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [25-1] 2007-06-21
00:39:43 PDTWARNING: page 26712 of relation 1663/16384/76719 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [26-1] 2007-06-21
00:39:43 PDTWARNING: page 28918 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [27-1] 2007-06-21
00:39:43 PDTWARNING: page 28912 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [28-1] 2007-06-21
00:39:43 PDTWARNING: page 3535209 of relation 1663/16384/33190 did
not exist
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [29-1] 2007-06-21
00:39:43 PDTWARNING: page 28907 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [30-1] 2007-06-21
00:39:43 PDTWARNING: page 28906 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [31-1] 2007-06-21
00:39:43 PDTWARNING: page 26713 of relation 1663/16384/76719 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [32-1] 2007-06-21
00:39:43 PDTWARNING: page 17306 of relation 1663/16384/76710 did not
exist
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [33-1] 2007-06-21
00:39:43 PDTWARNING: page 26706 of relation 1663/16384/76719 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [34-1] 2007-06-21
00:39:43 PDTWARNING: page 800226 of relation 1663/16384/33204 did
not exist
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [35-1] 2007-06-21
00:39:43 PDTWARNING: page 28915 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [36-1] 2007-06-21
00:39:43 PDTWARNING: page 26710 of relation 1663/16384/76719 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [37-1] 2007-06-21
00:39:43 PDTWARNING: page 28903 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [38-1] 2007-06-21
00:39:43 PDTWARNING: page 28902 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [39-1] 2007-06-21
00:39:43 PDTWARNING: page 28910 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:39:43 sfmedstorageha001 postgres[3506]: [40-1] 2007-06-21
00:39:43 PDTPANIC: WAL contains references to invalid pages
Jun 21 00:39:43 sfmedstorageha001 postgres[3503]: [1-1] 2007-06-21
00:39:43 PDTLOG: startup process (PID 3506) was terminated by signal 6
Jun 21 00:39:43 sfmedstorageha001 postgres[3503]: [2-1] 2007-06-21
00:39:43 PDTLOG: aborting startup due to startup process failure
Jun 21 00:39:43 sfmedstorageha001 postgres[3505]: [1-1] 2007-06-21
00:39:43 PDTLOG: logger shutting down
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [1-1] 2007-06-21
00:40:39 PDTLOG: database system was interrupted while in recovery
at 2007-06-21 00:36:40 PDT
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [1-2] 2007-06-21
00:40:39 PDTHINT: This probably means that some data is corrupted
and you will have to use the last backup for
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [1-3] recovery.
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [2-1] 2007-06-21
00:40:39 PDTLOG: checkpoint record is at 71/9881E928
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [3-1] 2007-06-21
00:40:39 PDTLOG: redo record is at 71/986BF148; undo record is at
0/0; shutdown FALSE
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [4-1] 2007-06-21
00:40:39 PDTLOG: next transaction ID: 0/2871389429; next OID: 83795
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [5-1] 2007-06-21
00:40:39 PDTLOG: next MultiXactId: 1; next MultiXactOffset: 0
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [6-1] 2007-06-21
00:40:39 PDTLOG: database system was not properly shut down;
automatic recovery in progress
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [7-1] 2007-06-21
00:40:39 PDTLOG: redo starts at 71/986BF148
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [8-1] 2007-06-21
00:40:39 PDTLOG: record with zero length at 71/998706A8
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [9-1] 2007-06-21
00:40:39 PDTLOG: redo done at 71/99870670
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [10-1] 2007-06-21
00:40:39 PDTWARNING: page 28905 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [11-1] 2007-06-21
00:40:39 PDTWARNING: page 13626 of relation 1663/16384/76716 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [12-1] 2007-06-21
00:40:39 PDTWARNING: page 28904 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [13-1] 2007-06-21
00:40:39 PDTWARNING: page 26711 of relation 1663/16384/76719 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [14-1] 2007-06-21
00:40:39 PDTWARNING: page 28900 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [15-1] 2007-06-21
00:40:39 PDTWARNING: page 3535208 of relation 1663/16384/33190 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [16-1] 2007-06-21
00:40:39 PDTWARNING: page 28917 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [17-1] 2007-06-21
00:40:39 PDTWARNING: page 3535207 of relation 1663/16384/33190 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [18-1] 2007-06-21
00:40:39 PDTWARNING: page 28916 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [19-1] 2007-06-21
00:40:39 PDTWARNING: page 28911 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [20-1] 2007-06-21
00:40:39 PDTWARNING: page 26708 of relation 1663/16384/76719 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [21-1] 2007-06-21
00:40:39 PDTWARNING: page 28914 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [22-1] 2007-06-21
00:40:39 PDTWARNING: page 28909 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [23-1] 2007-06-21
00:40:39 PDTWARNING: page 28908 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [24-1] 2007-06-21
00:40:39 PDTWARNING: page 28913 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [25-1] 2007-06-21
00:40:39 PDTWARNING: page 26712 of relation 1663/16384/76719 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [26-1] 2007-06-21
00:40:39 PDTWARNING: page 28918 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [27-1] 2007-06-21
00:40:39 PDTWARNING: page 28912 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [28-1] 2007-06-21
00:40:39 PDTWARNING: page 3535209 of relation 1663/16384/33190 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [29-1] 2007-06-21
00:40:39 PDTWARNING: page 28907 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [30-1] 2007-06-21
00:40:39 PDTWARNING: page 28906 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [31-1] 2007-06-21
00:40:39 PDTWARNING: page 26713 of relation 1663/16384/76719 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [32-1] 2007-06-21
00:40:39 PDTWARNING: page 17306 of relation 1663/16384/76710 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [33-1] 2007-06-21
00:40:39 PDTWARNING: page 26706 of relation 1663/16384/76719 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [34-1] 2007-06-21
00:40:39 PDTWARNING: page 800226 of relation 1663/16384/33204 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [35-1] 2007-06-21
00:40:39 PDTWARNING: page 28915 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [36-1] 2007-06-21
00:40:39 PDTWARNING: page 26710 of relation 1663/16384/76719 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [37-1] 2007-06-21
00:40:39 PDTWARNING: page 28903 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [38-1] 2007-06-21
00:40:39 PDTWARNING: page 28902 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [39-1] 2007-06-21
00:40:39 PDTWARNING: page 28910 of relation 1663/16384/76718 was
uninitialized
Jun 21 00:40:39 sfmedstorageha001 postgres[3757]: [40-1] 2007-06-21
00:40:39 PDTPANIC: WAL contains references to invalid pages
Jun 21 00:40:39 sfmedstorageha001 postgres[3755]: [1-1] 2007-06-21
00:40:39 PDTLOG: startup process (PID 3757) was terminated by signal 6
Jun 21 00:40:39 sfmedstorageha001 postgres[3755]: [2-1] 2007-06-21
00:40:39 PDTLOG: aborting startup due to startup process failure
Jun 21 00:40:39 sfmedstorageha001 postgres[3756]: [1-1] 2007-06-21
00:40:39 PDTLOG: logger shutting down
On Jun 25, 2007, at 6:26 AM, Simon Riggs wrote:
On Mon, 2007-06-25 at 19:06 +0900, Koichi Suzuki wrote:
Year, I agree we should carefully follow how Done really did a
backup.
My point is PostgreSQL may have to extend the file during the hot
backup
to write to the new block.
If the snapshot is a consistent, point-in-time copy then I don't
see how
any I/O at all makes a difference. To my knowledge, both EMC and
NetApp
produce snapshots like this. IIRC, EMC calls these instant snapshots,
NetApp calls them frozen snapshots.
It is slightly different from Oracle's case.
Oracle allocates all the database space in advance so that there
could
be no risk to modify the metadata on the fly.
Not really sure its different.
Oracle allows dynamic file extensions and I've got no evidence that
file
extension is prevented from occurring during backup simply as a result
of issuing the start hot backup command.
Oracle and DB2 both support a stop-I/O-to-the-database mode. My
understanding is that isn't required any more if you do an instant
snapshot, so if people are using instant snapshots it should certainly
be the case that they are safe to do this with PostgreSQL also.
Oracle is certainly more picky about snapshotted files than PostgreSQL
is. In Oracle, each file has a header with the LSN of the last
checkpoint in it. This is used at recovery time to ensure the
backup is
consistent by having exactly equal LSNs across all files. PostgreSQL
doesn't use file headers and we don't store the LSN on a per-file
basis,
though we do store the LSN in the control file for the whole server.
In our case, because SAN
based storage snapshot is device level, not file system level, even a
file system does not know that the snapshot is being taken and we
might
encounter the case where metadata and/or user data are not
consistent.
Such snapshot (whole filesystem) might be corrupted and cause file
system level error.
I'm interested in this. Any further comment/openion is welcome.
If you can show me either
i) an error that occurs after the full and correct PostgreSQL hot
backup
procedures have been executed, or
ii) present a conjecture that explains in detail how a device level
error might occur
then I will look into this further.
--
Simon Riggs
EnterpriseDB http://www.enterprisedb.com
