Re: logical replication snapshots

On 2018-07-25 12:31:01 -0700, Adrian Klaver wrote:
> On 07/25/2018 11:10 AM, Dimitri Maziuk wrote:
> > On 07/25/2018 11:16 AM, Adrian Klaver wrote:
> > 
> > > Where you using pg_export_snapshot() by any chance?:
> > 
> > If it's not in chapter 31 of TFM then I have not touched it. The only
> > notable thing I changed from 31.9 quickstart is that replica identity is
> > full on all tables (the data's a mess).
> 
> So no.
> 
> > 
> > > Where there any relevant error messages in the log before the database
> > > hung?
> > 
> > Do you seriously expect me to know what "relevant" is? ;) -- It's 7
> > days' worth of
> 
> Generally speaking relevancy increases the closer you get to the fall over
> event. So we are most interested in entries close to the point where the
> database stopped/failed.
> 
> > 
> > > 2018-07-23 09:43:12.851 CDT [7975] STATEMENT:  COPY macromolecules."Entity_common_name" TO STDOUT
> > > 2018-07-23 09:43:12.925 CDT [7982] LOG:  logical decoding found consistent point at 19/E6942408
> > > 2018-07-23 09:43:12.925 CDT [7982] DETAIL:  There are no running transactions.
> > > 2018-07-23 09:43:12.935 CDT [7982] ERROR:  permission denied for schema macromolecules
> > > 2018-07-23 09:43:12.935 CDT [7982] STATEMENT:  COPY macromolecules."Assembly" TO STDOUT
> > > 2018-07-23 09:43:13.034 CDT [7987] LOG:  logical decoding found consistent point at 19/E6942440
> > > 2018-07-23 09:43:13.034 CDT [7987] DETAIL:  There are no running transactions.
> > > 2018-07-23 09:43:13.044 CDT [7987] ERROR:  permission denied for schema macromolecules
> > > 2018-07-23 09:43:13.044 CDT [7987] STATEMENT:  COPY macromolecules."Spectral_transition" TO STDOUT
> > > 2018-07-23 09:43:13.135 CDT [7990] LOG:  logical decoding found consistent point at 19/E6942478
> > > 2018-07-23 09:43:13.135 CDT [7990] DETAIL:  There are no running transactions.
> > > 2018-07-23 09:43:13.145 CDT [7990] ERROR:  permission denied for schema macromolecules
> > > 2018-07-23 09:43:13.145 CDT [7990] STATEMENT:  COPY macromolecules."Assembly_db_link" TO STDOUT
> > 
> > that ends with
> > 
> > > 2018-07-23 09:45:40.280 CDT [6032] LOG:  database system was interrupted; last known up at 2018-07-06 17:04:28
CDT
> > > 2018-07-23 09:45:40.281 CDT [6033] FATAL:  the database system is starting up
> > > 2018-07-23 09:45:40.282 CDT [6034] FATAL:  the database system is starting up
> > ... ad infinitum ...
> > 
> > Would "permission denied" be relevant?
> 
> Logical decoding is something I am still learning. The "permission denied"
> would to me be relevant only to the extent that it seems to be provoking:

Yes, it looks related. Looks like logical rep was trying to perform the
intiial sync of those tables, and couldn't due to permission errors.


> "LOG:  logical decoding found consistent point at 19/E6942440"
> DETAIL:  There are no running transactions."
> 
> Others with more experience in this area would need to fill whether that
> might account for the 13 million files in the ~snapshot/ directory.

That indicates there's some error handling issues to be resolved. Petr?

Greetings,

Andres Freund