/usr/share/doc/slony1-2-doc/adminguide/loganalysis.html

<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN""http://www.w3.org/TR/html4/loose.dtd">
<HTML
><HEAD
><TITLE
>Log Analysis</TITLE
><META
NAME="GENERATOR"
CONTENT="Modular DocBook HTML Stylesheet Version 1.79"><LINK
REV="MADE"
HREF="mailto:slony1-general@lists.slony.info"><LINK
REL="HOME"
TITLE="Slony-I 2.1.4 Documentation"
HREF="index.html"><LINK
REL="UP"
TITLE="Deployment Considerations"
HREF="deploymentconcerns.html"><LINK
REL="PREVIOUS"
TITLE=" Slony-I Upgrade "
HREF="slonyupgrade.html"><LINK
REL="NEXT"
TITLE="Performance Considerations"
HREF="performance.html"><LINK
REL="STYLESHEET"
TYPE="text/css"
HREF="stylesheet.css"><META
HTTP-EQUIV="Content-Type"
CONTENT="text/html; charset=ISO-8859-1"><META
NAME="creation"
CONTENT="2014-02-06T00:06:49"></HEAD
><BODY
CLASS="SECT1"
><DIV
CLASS="NAVHEADER"
><TABLE
SUMMARY="Header navigation table"
WIDTH="100%"
BORDER="0"
CELLPADDING="0"
CELLSPACING="0"
><TR
><TH
COLSPAN="5"
ALIGN="center"
VALIGN="bottom"
><SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
> 2.1.4 Documentation</TH
></TR
><TR
><TD
WIDTH="10%"
ALIGN="left"
VALIGN="top"
><A
HREF="slonyupgrade.html"
ACCESSKEY="P"
>Prev</A
></TD
><TD
WIDTH="10%"
ALIGN="left"
VALIGN="top"
><A
HREF="deploymentconcerns.html"
>Fast Backward</A
></TD
><TD
WIDTH="60%"
ALIGN="center"
VALIGN="bottom"
>Chapter 5. Deployment Considerations</TD
><TD
WIDTH="10%"
ALIGN="right"
VALIGN="top"
><A
HREF="deploymentconcerns.html"
>Fast Forward</A
></TD
><TD
WIDTH="10%"
ALIGN="right"
VALIGN="top"
><A
HREF="performance.html"
ACCESSKEY="N"
>Next</A
></TD
></TR
></TABLE
><HR
ALIGN="LEFT"
WIDTH="100%"></DIV
><DIV
CLASS="SECT1"
><H1
CLASS="SECT1"
><A
NAME="LOGANALYSIS"
>5.5. Log Analysis</A
></H1
><A
NAME="AEN2963"
></A
><P
>Here are some of things that you may find in your <SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
> logs,
and explanations of what they mean.</P
><DIV
CLASS="SECT2"
><H2
CLASS="SECT2"
><A
NAME="AEN2967"
>5.5.1. CONFIG notices</A
></H2
><A
NAME="AEN2969"
></A
><P
>These entries are pretty straightforward. They are informative
messages about your configuration.</P
><P
>Here are some typical entries that you will probably run into in
your logs:

</P><PRE
CLASS="SCREEN"
>CONFIG main: local node id = 1
CONFIG main: loading current cluster configuration
CONFIG storeNode: no_id=3 no_comment='Node 3'
CONFIG storePath: pa_server=5 pa_client=1 pa_conninfo="host=127.0.0.1 dbname=foo user=postgres port=6132" pa_connretry=10
CONFIG storeListen: li_origin=3 li_receiver=1 li_provider=3
CONFIG storeSet: set_id=1 set_origin=1 set_comment='Set 1'
CONFIG main: configuration complete - starting threads</PRE
><P></P
></DIV
><DIV
CLASS="SECT2"
><H2
CLASS="SECT2"
><A
NAME="AEN2974"
>5.5.2. INFO notices</A
></H2
><A
NAME="AEN2976"
></A
><P
> Events that take place that seem like they will generally be of
interest are recorded at the INFO level, and, just as with CONFIG
notices, are always listed. </P
></DIV
><DIV
CLASS="SECT2"
><H2
CLASS="SECT2"
><A
NAME="AEN2979"
>5.5.3. DEBUG Notices</A
></H2
><A
NAME="AEN2981"
></A
><P
>Debug notices are of less interest, and will quite likely only
need to be shown if you are running into some problem with <SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
>.</P
></DIV
><DIV
CLASS="SECT2"
><H2
CLASS="SECT2"
><A
NAME="AEN2985"
>5.5.4. Thread name</A
></H2
><A
NAME="AEN2987"
></A
><P
> Notices are always prefaced by the name of the thread from
which the notice originates. You will see messages from the following
threads:

<P
></P
></P><DIV
CLASS="VARIABLELIST"
><DL
><DT
>localListenThread</DT
><DD
><P
> This is the local thread that listens for events on
the local node.</P
></DD
><DT
>remoteWorkerThread-X</DT
><DD
><P
> The thread processing remote events.  You can expect
to see one of these for each node that this node communicates
with.</P
></DD
><DT
>remoteListenThread-X</DT
><DD
><P
>Listens for events on a remote node database.  You may
expect to see one of these for each node in the
cluster.</P
></DD
><DT
>cleanupThread</DT
><DD
><P
> Takes care
of things like vacuuming, cleaning out the confirm and event tables,
and deleting old data.</P
></DD
><DT
>syncThread</DT
><DD
><P
> Generates SYNC
events.</P
></DD
></DL
></DIV
><P></P
><P
> How much information they display is controlled by the
<TT
CLASS="ENVAR"
>log_level</TT
> <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> parameter; ERROR/WARN/CONFIG/INFO
messages will always be displayed, while choosing increasing values
from 1 to 4 will lead to additional DEBUG level messages being
displayed. </P
></DIV
><DIV
CLASS="SECT2"
><H2
CLASS="SECT2"
><A
NAME="AEN3014"
>5.5.5. How to read <SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
> logs</A
></H2
><A
NAME="AEN3017"
></A
><P
> Note that as far as slon is concerned, there is no
<SPAN
CLASS="QUOTE"
>"master"</SPAN
> or <SPAN
CLASS="QUOTE"
>"slave."</SPAN
> They are just
nodes. </P
><P
>What you can expect, initially, is to see, on both nodes, some
events propagating back and forth.  Firstly, there should be some
events published to indicate creation of the nodes and paths.  If you
don't see those, then the nodes aren't properly communicating with one
another, and nothing else will happen... </P
><P
></P
><UL
><LI
><P
>Create the two nodes.</P
><P
> No slons are running yet, so there are no logs to look
at.</P
></LI
><LI
><P
> Start the two slons</P
><P
> The logs for each will start out very quiet, as neither node
has much to say, and neither node knows how to talk to another node.
Each node will periodically generate a <TT
CLASS="COMMAND"
>SYNC</TT
> event,
but recognize <SPAN
CLASS="emphasis"
><I
CLASS="EMPHASIS"
>nothing</I
></SPAN
> about what is going on on
other nodes.</P
></LI
><LI
><P
> Do the <A
HREF="stmtstorepath.html"
>SLONIK STORE
     PATH</A
> to set up
communications paths.  That will allow the nodes to start to become
aware of one another.</P
><P
> The slon logs should now start to receive events from
<SPAN
CLASS="QUOTE"
>"foreign"</SPAN
> nodes.</P
><P
> If you look at the contents of the tables <A
HREF="table.sl-node.html"
>sl_node</A
> and <A
HREF="table.sl-path.html"
>sl_path</A
> and <A
HREF="table.sl-listen.html"
>sl_listen</A
>, on each node, that should give a good idea
as to where things stand.  Until the <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> starts,
each node may only be partly configured.  If there are two nodes,
there should be two entries in all three of these tables once the
communications configuration is set up properly.  If there are fewer
entries than that, well, that should give you some idea of what is
missing.</P
></LI
><LI
><P
> You'll set up the set
(<A
HREF="stmtcreateset.html"
>SLONIK CREATE SET</A
>), add tables
(<A
HREF="stmtsetaddtable.html"
>SLONIK SET ADD TABLE</A
>), and sequences
(<A
HREF="stmtsetaddsequence.html"
>SLONIK SET ADD SEQUENCE</A
>), and will see relevant
events <A
HREF="loganalysis.html#LOGADDOBJECTS"
>Section 5.5.6.7</A
> only in the logs for the origin
node for the set. </P
></LI
><LI
><P
> Then, when you submit the <A
HREF="stmtsubscribeset.html"
>SLONIK SUBSCRIBE SET</A
> request, the event should go to both
nodes. </P
><P
> The origin node has little more to do, after that...  The
subscriber will then have a <TT
CLASS="COMMAND"
>COPY_SET</TT
> event, which
will lead to logging information about adding each table and copying
its data.  See <A
HREF="loganalysis.html#LOGSUBTIME"
>Section 5.5.6.4</A
> for more
details.</P
></LI
></UL
><P
>After that, you'll mainly see two sorts of behaviour:</P
><P
></P
><UL
><LI
><P
> On the origin, there won't be too terribly much
logged, just indication that some <TT
CLASS="COMMAND"
>SYNC</TT
> events are
being generated and confirmed by other nodes.
See <A
HREF="loganalysis.html#LOGNORMALSYNC"
>Section 5.5.6.6</A
> to see the sorts of log entries to
expect.</P
></LI
><LI
><P
> On the subscriber, there will be reports of
<TT
CLASS="COMMAND"
>SYNC</TT
> events, and that the subscriber pulls data
from the provider for the relevant set(s).  This will happen
infrequently if there are no updates going to the origin node; it will
happen frequently when the origin sees heavy updates. </P
></LI
></UL
></DIV
><DIV
CLASS="SECT2"
><H2
CLASS="SECT2"
><A
NAME="AEN3064"
>5.5.6. Log Messages and Implications</A
></H2
><P
> This section lists numerous of the error messages found in
<SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
>, along with a brief explanation of implications.  It is a
fairly comprehensive list, only leaving out some of the
<TT
CLASS="COMMAND"
>DEBUG4</TT
> messages that are almost always
uninteresting.</P
><DIV
CLASS="SECT3"
><H3
CLASS="SECT3"
><A
NAME="LOGSHIPLOG"
>5.5.6.1. Log Messages Associated with Log
Shipping</A
></H3
><A
NAME="AEN3071"
></A
><P
> Most of these represent errors that come up if
the <A
HREF="logshipping.html"
>Section 4.5</A
> functionality breaks.  You may expect
things to break if the filesystem being used for log shipping fills,
or if permissions on that directory are wrongly set. </P
><P
></P
><UL
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: log archive failed %s - %s\n</TT
> </P
><P
> This indicates that an error was encountered trying to write a
log shipping file.  Normally the <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> will retry, and hopefully
succeed. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: writing archive log...</TT
></P
><P
> This indicates that a log shipping archive log is being written for a particular <TT
CLASS="COMMAND"
>SYNC</TT
> set. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>INFO: remoteWorkerThread_%d: Run Archive Command %s</TT
></P
><P
> If <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> has been configured (<TT
CLASS="OPTION"
>-x</TT
>
aka <TT
CLASS="ENVAR"
>command_on_logarchive</TT
>) to run a command after
generating each log shipping archive log, this reports when that
process is spawned using <CODE
CLASS="FUNCTION"
>system()</CODE
>. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: Could not open
COPY SET archive file %s - %s</TT
></P
><P
> Seems pretty self-explanatory... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: Could not generate COPY SET archive header %s - %s</TT
></P
><P
> Probably means that we just filled up a filesystem... </P
></LI
><LI
><P
> <TT
CLASS="COMMAND"
>ERROR  remoteWorkerThread_%d: "update "_slony_regress1".sl_archive_counter     set ac_num = ac_num + 1,         ac_timestamp = CURRENT_TIMESTAMP; select ac_num, ac_timestamp from "_slony_regress1".sl_archive_counter; " PGRES_FATAL_ERROR ERROR:  could not serialize access due to concurrent update</TT
> </P
><P
> This may occasionally occur when using logshipping; this will
typically happen if there are 3 or more nodes, and there is an attempt
to concurrently process events sourced from different nodes.  This
does not represent any serious problem; <SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
> will retry the event
which failed without the need for administrative intervention. </P
></LI
></UL
></DIV
><DIV
CLASS="SECT3"
><H3
CLASS="SECT3"
><A
NAME="DDLLOGS"
>5.5.6.2. Log Messages -  DDL scripts</A
></H3
><A
NAME="AEN3109"
></A
><P
> The handling of DDL is somewhat fragile, as described
in <A
HREF="ddlchanges.html"
>Section 3.3</A
>; here are both informational and error
messages that may occur in the progress of
an <A
HREF="stmtddlscript.html"
>SLONIK EXECUTE SCRIPT</A
> request.</P
><P
></P
><UL
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: DDL preparation
failed - set %d - only on node %</TT
></P
><P
> Something broke when applying a DDL script on one of the nodes.
This is quite likely indicates that the node's schema differed from
that on the origin; you may need to apply a change manually to the
node to allow the event to proceed.  The scary, scary alternative
might be to delete the offending event, assuming it can't possibly
work...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>SLON_CONFIG: remoteWorkerThread_%d: DDL request with %d statements</TT
></P
><P
> This is informational, indicating how many SQL statements were processed. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>SLON_ERROR: remoteWorkerThread_%d: DDL had invalid number of statements - %d</TT
></P
><P
> Occurs if there were &#60; 0 statements (which should be impossible) or &#62; MAXSTATEMENTS statements.  Probably the script was bad...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: malloc()
failure in DDL_SCRIPT - could not allocate %d bytes of
memory</TT
></P
><P
> This should only occur if you submit some extraordinarily large
DDL script that makes a <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> run out of memory </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>CONFIG: remoteWorkerThread_%d: DDL Statement %d: [%s]</TT
></P
><P
> This lists each DDL statement as it is submitted. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: DDL Statement failed - %s</TT
></P
><P
> Oh, dear, one of the DDL statements that worked on the origin
failed on this remote node... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>CONFIG: DDL Statement success - %s</TT
></P
><P
> All's well...  </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: Could not generate DDL archive tracker %s - %s</TT
></P
><P
> Apparently the DDL script couldn't be written to a log shipping file... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: Could not submit DDL script %s - %s</TT
></P
><P
>Couldn't write the script to a log shipping file.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: Could not close DDL script %s - %s</TT
></P
><P
>Couldn't close a log shipping file for a DDL script.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I ddlScript_prepare(): set % not found</TT
></P
><P
> Set wasn't found on this node; you probably gave the wrong ID number... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I ddlScript_prepare_int(): set % not found</TT
></P
><P
> Set wasn't found on this node; you probably gave the wrong ID number... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: alterTableForReplication(): Table with id % not found</TT
></P
><P
> Apparently the table wasn't found; could the schema be messed up? </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: alterTableForReplication(): Table % is already in altered state</TT
></P
><P
> Curious...  We're trying to set a table up for replication
a <SPAN
CLASS="emphasis"
><I
CLASS="EMPHASIS"
>second</I
></SPAN
> time?  </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: alterTableRestore(): Table with id % not found</TT
></P
><P
> This runs when a table is being restored to <SPAN
CLASS="QUOTE"
>"non-replicated"</SPAN
> state; apparently the replicated table wasn't found.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: alterTableRestore(): Table % is not in altered state</TT
></P
><P
> Hmm.  The table isn't in altered replicated state.  That shouldn't be, if replication had been working properly...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>NOTICE: Slony-I: alterTableForReplication(): multiple instances of trigger % on table %'',</TT
></P
><P
> This normally happens if you have a table that had a trigger attached to it that replication hid due to this being a subscriber node, and then you added a trigger by the same name back to replication.  Now, when trying to "fix up" triggers, those two triggers conflict. </P
><P
> The DDL script will keep running and rerunning, or the UNINSTALL NODE will keep failing, until you drop the <SPAN
CLASS="QUOTE"
>"visible"</SPAN
> trigger, by hand, much as you must have added it, by hand, earlier. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: Unable to disable triggers</TT
></P
><P
> This is the error that follows the <SPAN
CLASS="QUOTE"
>"multiple triggers"</SPAN
> problem. </P
></LI
></UL
></DIV
><DIV
CLASS="SECT3"
><H3
CLASS="SECT3"
><A
NAME="AEN3193"
>5.5.6.3. Threading Issues</A
></H3
><A
NAME="AEN3195"
></A
><P
> There should not be any <SPAN
CLASS="QUOTE"
>"user-serviceable"</SPAN
> aspects
to the <SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
> threading model; each <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> creates a well-specified
set of helper threads to manage the various database connections that
it requires.  The only way that anything should break on the threading
side is if you have not compiled <SPAN
CLASS="PRODUCTNAME"
>PostgreSQL</SPAN
> libraries to <SPAN
CLASS="QUOTE"
>"play
well"</SPAN
> with threading, in which case you will be unable to
compile <SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
> in the first place. </P
><P
></P
><UL
><LI
><P
><TT
CLASS="COMMAND"
>FATAL: remoteWorkerThread_%d: pthread_create() - %s</TT
></P
><P
> Couldn't create a new remote worker thread. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG1 remoteWorkerThread_%d: helper thread for provider %d created</TT
></P
><P
> This normally happens when the <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> starts: a thread is created for each node to which the local node should be listening for events.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG1: remoteWorkerThread_%d: helper thread for provider %d terminated </TT
></P
><P
> If subscriptions reshape such that a node no longer provides a
subscription, then the thread that works on that node can be
dropped. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG1: remoteWorkerThread_%d: disconnecting
from data provider %d </TT
></P
><P
> A no-longer-used data provider may be dropped; if connection
information is changed, the <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> needs to disconnect and
reconnect. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: ignore new events due to shutdown</TT
></P
><P
> If the <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> is shutting down, it is futile to process more events</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG1: remoteWorkerThread_%d: node %d - no worker thread</TT
></P
><P
> Curious: we can't wake up the worker thread; there probably
should already be one... </P
></LI
></UL
></DIV
><DIV
CLASS="SECT3"
><H3
CLASS="SECT3"
><A
NAME="LOGSUBTIME"
>5.5.6.4. Log Entries At Subscription Time</A
></H3
><A
NAME="AEN3234"
></A
><P
> Subscription time is quite a special time in <SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
>.  If you
have a large amount of data to be copied to subscribers, this may take
a considerable period of time.  <SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
> logs a fairly considerable
amount of information about its progress, which is sure to be useful
to the gentle reader.  In particular, it generates log output every
time it starts and finishes copying data for a given table as well as
when it completes reindexing the table.  That may not make a 28 hour
subscription go any faster, but at least helps you have some idea of
how it is progressing. </P
><P
></P
><UL
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG1: copy_set %d</TT
></P
><P
> This indicates the beginning of copying data for a new subscription. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: set %d not found in runtime configuration </TT
></P
><P
> <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> tried starting up a subscription; it couldn't find conninfo for the data source.  Perhaps paths are not properly propagated?</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: node %d has no pa_conninfo </TT
></P
><P
> Apparently the conninfo configuration
was <SPAN
CLASS="emphasis"
><I
CLASS="EMPHASIS"
>wrong</I
></SPAN
>...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: copy set %d cannot connect to provider DB node %d </TT
></P
><P
> <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> couldn't connect to the provider.  Is the conninfo
wrong?  Or perhaps authentication is misconfigured?  Or perhaps the
database is down?</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG1: remoteWorkerThread_%d: connected to provider DB </TT
></P
><P
> Excellent: the copy set has a connection to its provider</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: sequenceSetValue(): sequence % not found</TT
></P
><P
> Curious; the sequence object is missing.  Could someone have dropped it from the schema by hand (<SPAN
CLASS="emphasis"
><I
CLASS="EMPHASIS"
>e.g.</I
></SPAN
> - not using <A
HREF="stmtddlscript.html"
>SLONIK EXECUTE SCRIPT</A
>)?</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: subscribeSet() must be called on provider</TT
></P
><P
> This function should only get called on the provider node.  <A
HREF="slonik.html"
><SPAN
CLASS="APPLICATION"
>slonik</SPAN
></A
> normally handles this right, unless one had wrong DSNs in a <A
HREF="slonik.html"
><SPAN
CLASS="APPLICATION"
>slonik</SPAN
></A
> script...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: subscribeSet(): set % not found</TT
></P
><P
> Hmm.  The provider node isn't aware of this set.  Wrong parms to a <A
HREF="slonik.html"
><SPAN
CLASS="APPLICATION"
>slonik</SPAN
></A
> script?</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: subscribeSet(): set origin and receiver cannot be identical</TT
></P
><P
> Duh, an origin node can't subscribe to itself.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: subscribeSet(): set provider and receiver cannot be identical</TT
></P
><P
> A receiver must subscribe to a <SPAN
CLASS="emphasis"
><I
CLASS="EMPHASIS"
>different</I
></SPAN
> node...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>Slony-I: subscribeSet(): provider % is not an active forwarding node for replication set %</TT
></P
><P
> You can only use a live, active, forwarding provider as a data
source.  </P
></LI
><LI
><P
>Slony-I: subscribeSet_int(): set % is not active, cannot change provider<TT
CLASS="COMMAND"
></TT
></P
><P
> You can't change the provider just yet...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>Slony-I: subscribeSet_int(): set % not found</TT
></P
><P
> This node isn't aware of the set...  Perhaps you submitted wrong parms?</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>Slony-I: unsubscribeSet() must be called on receiver</TT
></P
><P
> Seems obvious...  This probably indicates a bad <A
HREF="slonik.html"
><SPAN
CLASS="APPLICATION"
>slonik</SPAN
></A
> admin DSN...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>Slony-I: Cannot unsubscribe set % while being provider</TT
></P
><P
> This should seem obvious; <A
HREF="stmtunsubscribeset.html"
>SLONIK UNSUBSCRIBE SET</A
> will fail if a node has dependent subscribers for which it is the provider </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>Slony-I: cleanupEvent(): Single node - deleting events &#60; %</TT
></P
><P
> If there's only one node, the cleanup event will delete old events so that you don't get <SPAN
CLASS="QUOTE"
>"build-up of crud."</SPAN
></P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>Slony-I: determineIdxnameUnique(): table % not found</TT
></P
><P
>Did you properly copy over the schema to a new node???</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>Slony-I: table % has no primary key</TT
></P
><P
> This likely signifies a bad loading of schema...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>Slony-I: table % has no unique index %</TT
></P
><P
> This likely signifies a bad loading of schema...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>WARN: remoteWorkerThread_%d: transactions
earlier than XID %s are still in progress</TT
></P
><P
> This indicates that some old transaction is in progress from before the earliest available <TT
CLASS="COMMAND"
>SYNC</TT
> on the provider.  <SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
> cannot start replicating until that transaction completes.  This will repeat until thetransaction completes...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: prepare to copy table %s </TT
></P
><P
> This indicates that <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> is beginning preparations to set up subscription for a table.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: Could not lock table %s on subscriber</TT
></P
><P
> For whatever reason, the table could not be locked, so the
subscription needs to be restarted.  If the problem was something like
a deadlock, retrying may help.  If the problem was otherwise, you may
need to intervene...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: all tables for set %d found on subscriber</TT
></P
><P
> An informational message indicating that the first pass through the tables found no problems... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: copy sequence %s</TT
></P
><P
> Processing some sequence... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: copy table %s</TT
></P
><P
> <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> is starting to copy a table... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG3: remoteWorkerThread_%d: table %s Slony-I serial key added local</TT
></P
><P
> Just added new column to the table to provide surrogate primary key.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG3: remoteWorkerThread_%d: local table %s already has Slony-I serial key</TT
></P
><P
> Did not need to add serial key; apparently it was already there.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG3: remoteWorkerThread_%d: table %s does not require Slony-I serial key</TT
></P
><P
> Apparently this table didn't require a special serial key... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG3: remoteWorkerThread_%d: table %s Slony-I serial key added local</TT
></P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: Begin COPY of table %s</TT
></P
><P
> <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> is about to start the COPY on both sides to copy a table... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: Could not generate copy_set request for %s - %s</TT
></P
><P
> This indicates that the <TT
CLASS="COMMAND"
>delete/copy</TT
> requests
failed on the subscriber.  The <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> will repeat
the <TT
CLASS="COMMAND"
>COPY_SET</TT
> attempt; it will probably continue to
fail.. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: copy to stdout on provider - %s %s</TT
></P
><P
> Evidently something about the COPY to <TT
CLASS="FILENAME"
>stdout</TT
> on the provider node broke...  The event will be retried... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: copy from stdin on local node - %s %s</TT
></P
><P
> Evidently something about the COPY into the table on the
subscriber node broke...  The event will be
retried... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: %d bytes copied for table %s</TT
></P
><P
> This message indicates that the COPY of the table has
completed.  This is followed by running <TT
CLASS="COMMAND"
>ANALYZE</TT
> and
reindexing the table on the subscriber.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: %.3f seconds
to copy table %s</TT
></P
><P
> After this message, copying and reindexing and analyzing the table on the subscriber is complete.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: set last_value of sequence %s (%s) to %s</TT
></P
><P
> As should be no surprise, this indicates that a sequence has been processed on the subscriber.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: %.3 seconds to copy sequences</TT
></P
><P
> Summarizing the time spent processing sequences in the <TT
CLASS="COMMAND"
>COPY_SET</TT
> event. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: query %s did not return a result </TT
></P
><P
> This indicates that the query, as part of final processing of <TT
CLASS="COMMAND"
>COPY_SET</TT
>, failed.  The copy will restart... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: copy_set no previous SYNC found, use enable event</TT
></P
><P
> This takes place if no past SYNC event was found; the current
event gets set to the event point of
the <TT
CLASS="COMMAND"
>ENABLE_SUBSCRIPTION</TT
> event.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: copy_set SYNC found, use event seqno %s</TT
></P
><P
> This takes place if a SYNC event was found; the current
event gets set as shown. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: sl_setsync entry for set %d not found on provider</TT
></P
><P
> SYNC synchronization information was expected to be drawn from
an existing subscriber, but wasn't found.  Something
replication-breakingly-bad has probably
happened... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG1: remoteWorkerThread_%d: could not insert to sl_setsync_offline</TT
></P
><P
> Oh, dear.  After setting up a subscriber, and getting pretty
well everything ready, some writes to a log shipping file failed.
Perhaps disk filled up...  </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG1: remoteWorkerThread_%d: %.3f seconds to build initial setsync status</TT
></P
><P
> Indicates the total time required to get the copy_set event finalized...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG1: remoteWorkerThread_%d: disconnected from provider DB</TT
></P
><P
> At the end of a subscribe set event, the subscriber's <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
>
will disconnect from the provider, clearing out
connections... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG1: remoteWorkerThread_%d: copy_set %d done in %.3f seconds</TT
></P
><P
> Indicates the total time required to complete copy_set...  This indicates a successful subscription!</P
></LI
></UL
></DIV
><DIV
CLASS="SECT3"
><H3
CLASS="SECT3"
><A
NAME="LOGMERGESET"
>5.5.6.5. Log Entries Associated with MERGE SET</A
></H3
><A
NAME="AEN3447"
></A
><P
> These various exceptions cause <A
HREF="stmtmergeset.html"
>SLONIK MERGE
     SET</A
> to
be rejected; something ought to be corrected before submitting the request again. </P
><P
></P
><UL
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: merged set ids cannot be identical</TT
></P
><P
> It is illogical to try to merge a set with itself. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: set % not found </TT
></P
><P
> A missing set cannot be merged. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: set % does not originate on local node</TT
></P
><P
> The <A
HREF="stmtmergeset.html"
>SLONIK MERGE
     SET</A
> request must be submitted to
the origin node for the sets that are to be merged. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: subscriber lists of set % and % are different</TT
></P
><P
> Sets can only be merged if they have identical subscriber
lists.  </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: set % has subscriptions in progress - cannot merge</TT
></P
><P
> <A
HREF="stmtmergeset.html"
>SLONIK MERGE
     SET</A
> cannot proceed until all
subscriptions have completed processing.  If this message arises, that
indicates that the subscriber lists <SPAN
CLASS="emphasis"
><I
CLASS="EMPHASIS"
>are</I
></SPAN
> the same,
but that one or more of the nodes has not yet completed setting up its
subscription.  It may be that waiting a short while will permit
resubmitting the <A
HREF="stmtmergeset.html"
>SLONIK MERGE
     SET</A
> request.</P
></LI
></UL
></DIV
><DIV
CLASS="SECT3"
><H3
CLASS="SECT3"
><A
NAME="LOGNORMALSYNC"
>5.5.6.6. Log Entries Associated With Normal SYNC activity</A
></H3
><A
NAME="AEN3478"
></A
><P
> Some of these messages indicate exceptions, but
the <SPAN
CLASS="QUOTE"
>"normal"</SPAN
> stuff represents what you should expect to
see most of the time when replication is just plain working.</P
><P
></P
><UL
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: forward confirm %d,%s received by %d</TT
></P
><P
> These events should occur frequently and routinely as nodes report confirmations of the events they receive. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG1: remoteWorkerThread_%d: SYNC %d processing</TT
></P
><P
> This indicates the start of processing of a <TT
CLASS="COMMAND"
>SYNC</TT
> </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: No pa_conninfo
for data provider %d</TT
></P
><P
> Oh dear, we haven't connection information to connect to the
data provider.  That shouldn't be possible,
normally...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteListenThread_%d: timeout for event selection</TT
></P
><P
> This means that the listener thread
(<TT
CLASS="FILENAME"
>src/slon/remote_listener.c</TT
>) timed out when
trying to determine what events were outstanding for it.</P
><P
> This could occur because network connections broke, in which case restarting the <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> might help. </P
><P
> Alternatively, this might occur because the <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> for this
node has been broken for a long time, and there are an enormous number
of entries in <TT
CLASS="ENVAR"
>sl_event</TT
> on this or other nodes for the
node to work through, and it is taking more than <A
HREF="slon-config-interval.html#SLON-CONFIG-REMOTE-LISTEN-TIMEOUT"
>slon_conf_remote_listen_timeout</A
> seconds to run the query.
In older versions of <SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
>, that configuration parameter did not
exist; the timeout was fixed at 300 seconds.  In newer versions, you
might increase that timeout in the <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> config file to a larger
value so that it can continue to completion.  And then investigate why
nobody was monitoring things such that replication broke for such a
long time... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: cannot connect to data provider %d on 'dsn'</TT
></P
><P
> Oh dear, we haven't got <SPAN
CLASS="emphasis"
><I
CLASS="EMPHASIS"
>correct</I
></SPAN
> connection
information to connect to the data provider.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG1: remoteWorkerThread_%d: connected to data provider %d on 'dsn'</TT
></P
><P
> Excellent; the <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> has connected to the provider. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>WARN: remoteWorkerThread_%d: don't know what ev_seqno node %d confirmed for ev_origin %d</TT
></P
><P
> There's no confirmation information available for this node's provider; need to abort the <TT
CLASS="COMMAND"
>SYNC</TT
> and wait a bit in hopes that that information will emerge soon...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG1: remoteWorkerThread_%d: data provider %d only confirmed up to ev_seqno %d for ev_origin %d </TT
></P
><P
> The provider for this node is a subscriber, and apparently that subscriber is a bit behind.  The <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> will need to wait for the provider to catch up until it has <SPAN
CLASS="emphasis"
><I
CLASS="EMPHASIS"
> new</I
></SPAN
> data. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: data provider %d confirmed up to ev_seqno %s for ev_origin %d - OK</TT
></P
><P
> All's well; the provider should have the data that the subscriber needs...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: syncing set %d with %d table(s) from provider %d</TT
></P
><P
> This is declaring the plans for a <TT
CLASS="COMMAND"
>SYNC</TT
>: we have a set with some tables to process.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: ssy_action_list value: %s length: %d</TT
></P
><P
> This portion of the query to collect log data to be applied has been known to <SPAN
CLASS="QUOTE"
>"bloat up"</SPAN
>; this shows how it has gotten compressed... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: Didn't add OR to provider</TT
></P
><P
> This indicates that there wasn't anything in a <SPAN
CLASS="QUOTE"
>"provider"</SPAN
> clause in the query to collect log data to be applied, which shouldn't be.  Things are quite likely to go bad at this point... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: no sets need syncing for this event</TT
></P
><P
>This will be the case for all <TT
CLASS="COMMAND"
>SYNC</TT
> events generated on nodes that are not originating replication sets.  You can expect to see these messages reasonably frequently. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG3: remoteWorkerThread_%d: activate helper %d</TT
></P
><P
> We're about to kick off a thread to help process <TT
CLASS="COMMAND"
>SYNC</TT
> data...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG4: remoteWorkerThread_%d: waiting for log data</TT
></P
><P
> The thread is waiting to get data to consume (e.g. - apply to the replica).</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: %s %s - qualification was %s </TT
></P
><P
> Apparently an application of replication data to the subscriber failed...  This quite likely indicates some sort of serious corruption.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: replication query did not affect one row (cmdTuples = %s) - query was: %s qualification was: %s</TT
></P
><P
> If <TT
CLASS="ENVAR"
> SLON_CHECK_CMDTUPLES</TT
> is set, <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> applies
changes one tuple at a time, and verifies that each change affects
exactly one tuple.  Apparently that wasn't the case here, which
suggests a corruption of replication.  That's a rather bad
thing...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: SYNC aborted</TT
></P
><P
>The <TT
CLASS="COMMAND"
>SYNC</TT
> has been aborted. The <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> will
likely retry this <TT
CLASS="COMMAND"
>SYNC</TT
> some time soon.  If the
<TT
CLASS="COMMAND"
>SYNC</TT
> continues to fail, there is some continuing
problem, and replication will likely never catch up without
intervention.  It may be necessary to unsubscribe/resubscribe the
affected slave set, or, if there is only one set on the slave node, it
may be simpler to drop and recreate the slave node.  If application
connections may be shifted over to the master during this time,
application downtime may not be necessary.  </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: new sl_rowid_seq value: %s</TT
></P
><P
> This marks the progression of this internal <SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
> sequence. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: SYNC %d done in %.3f seconds</TT
></P
><P
> This indicates the successful completion of a <TT
CLASS="COMMAND"
>SYNC</TT
>.  Hurray!</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG1: remoteWorkerThread_%d_d:%.3f seconds delay for first row </TT
></P
><P
> This indicates how long it took to get the first row from the LOG cursor that pulls in data from the sl_log tables.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d_d: large log_cmddata for actionseq %s not found</TT
></P
><P
> <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> could not find the data for one of the <SPAN
CLASS="QUOTE"
>"very large"</SPAN
> sl_log table tuples that are pulled individually.  This shouldn't happen.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d_d:%.3f seconds until close cursor </TT
></P
><P
> This indicates how long it took to complete reading data from the LOG cursor that pulls in data from the sl_log tables.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d_d: inserts=%d updates=%d deletes=%d </TT
></P
><P
> This reports how much activity was recorded in the current <TT
CLASS="COMMAND"
>SYNC</TT
> set. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG3: remoteWorkerThread_%d: compress_actionseq(list,subquery) Action list: %s</TT
></P
><P
> This indicates a portion of the LOG cursor query that is about to be compressed.  (In some cases, this could grow to <SPAN
CLASS="emphasis"
><I
CLASS="EMPHASIS"
>enormous</I
></SPAN
> size, blowing up the query parser...) </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG3: remoteWorkerThread_%d: compressed actionseq subquery %s</TT
></P
><P
> This indicates what that subquery compressed into. </P
></LI
></UL
></DIV
><DIV
CLASS="SECT3"
><H3
CLASS="SECT3"
><A
NAME="LOGADDOBJECTS"
>5.5.6.7. Log Entries - Adding Objects to Sets</A
></H3
><A
NAME="AEN3621"
></A
><P
> These entries will be seen on an origin node's logs at the time
you are configuring a replication set; some of them will be seen on
subscribers at subscription time.  </P
><P
></P
><UL
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: setAddTable_int(): table % has no index %</TT
></P
><P
> Apparently a PK index was specified that is absent on this node...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setAddTable_int(): table % not found</TT
></P
><P
> Table wasn't found on this node; did you load the schema in properly?. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setAddTable_int(): table % is not a regular table</TT
></P
><P
> You tried to replicate something that isn't a table; you can't do that! </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>NOTICE: Slony-I setAddTable_int(): table % PK column % nullable</TT
></P
><P
> You tried to replicate a table where one of the columns in the would-be primary key is allowed to be null.  All PK columns must be <TT
CLASS="COMMAND"
>NOT NULL.</TT
> This request is about to fail. </P
><P
> A check for this condition was introduced in <SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
> version
1.2.  If you have a 1.1 replica, it will continue to function after
upgrading to 1.2, but you will experience this complaint when you try
to add new subscribers. </P
><P
> You can look for table/index combinations on an existing
node that have NULLABLE columns in the primary key via the
following query:
</P><PRE
CLASS="SCREEN"
>select c.relname as table_name, ic.relname as index_name, att.attname, att2.attnotnull
from _cluster.sl_table t, pg_catalog.pg_class c, pg_index i, pg_catalog.pg_class ic, pg_catalog.pg_attribute att, pg_catalog.pg_attribute att2
where t.tab_reloid = c.oid 
    and t.tab_idxname = ic.relname 
    and  ic.oid = i.indexrelid
    and att.attrelid = i.indexrelid
    and att2.attname = att.attname
    and att2.attrelid = c.oid
    and att2.attnotnull = 'f';</PRE
><P> </P
><P
> These may be rectified via submitting, for each one, a query of
the form: <TT
CLASS="COMMAND"
> alter table mytable alter column nullablecol set
not null; </TT
> Running this against a subscriber where the table
is empty will complete very quickly. It will take longer to apply this
change to a table that already contains a great deal of data, as the
alteration will scan the table to verify that there are no tuples
where the column is NULL.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setAddTable_int(): table % not replicable!</TT
></P
><P
> This happens because of the NULLable PK column. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setAddTable_int(): table id % has already been assigned!</TT
></P
><P
> The table ID value needs to be assigned uniquely
in <A
HREF="stmtsetaddtable.html"
>SLONIK SET ADD TABLE</A
>; apparently you requested a value
already in use.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setAddSequence(): set % not found</TT
></P
><P
> Apparently the set you requested is not available...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setAddSequence(): set % has remote origin</TT
></P
><P
> You may only add things at the origin node.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setAddSequence(): cannot add sequence to currently subscribed set %</TT
></P
><P
> Apparently the set you requested has already been subscribed.  You cannot add tables/sequences to an already-subscribed set.  You will need to create a new set, add the objects to that new set, and set up subscriptions to that.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setAddSequence_int(): set % not found</TT
></P
><P
> Apparently the set you requested is not available...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setAddSequence_int(): sequence % not found</TT
></P
><P
> Apparently the sequence you requested is not available on this node.  How did you set up the schemas on the subscribers???</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setAddSequence_int(): % is not a sequence</TT
></P
><P
> Seems pretty obvious :-).</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setAddSequence_int(): sequence ID % has already been assigned</TT
></P
><P
> Each sequence ID added must be unique; apparently you have reused an ID.</P
></LI
></UL
></DIV
><DIV
CLASS="SECT3"
><H3
CLASS="SECT3"
><A
NAME="AEN3685"
>5.5.6.8. Logging When Moving Objects Between Sets</A
></H3
><A
NAME="AEN3687"
></A
><P
></P
><UL
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setMoveTable_int(): table % not found</TT
></P
><P
> Table wasn't found on this node; you probably gave the wrong ID number... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setMoveTable_int(): set ids cannot be identical</TT
></P
><P
> Does it make sense to move a table from a set into the very same set? </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setMoveTable_int(): set % not found</TT
></P
><P
> Set wasn't found on this node; you probably gave the wrong ID number... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setMoveTable_int(): set % does not originate on local node</TT
></P
><P
> Set wasn't found to have origin on this node; you probably gave the wrong EVENT NODE... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setMoveTable_int(): subscriber lists of set % and % are different</TT
></P
><P
> You can only move objects between sets that have identical subscriber lists. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setMoveSequence_int(): sequence % not found</TT
></P
><P
> Sequence wasn't found on this node; you probably gave the wrong ID number... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setMoveSequence_int(): set ids cannot be identical</TT
></P
><P
> Does it make sense to move a sequence from a set into the very same set? </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setMoveSequence_int(): set % not found</TT
></P
><P
> Set wasn't found on this node; you probably gave the wrong ID number... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setMoveSequence_int(): set % does not originate on local node</TT
></P
><P
> Set wasn't found to have origin on this node; you probably gave the wrong EVENT NODE... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setMoveSequence_int(): subscriber lists of set % and % are different</TT
></P
><P
> You can only move objects between sets that have identical subscriber lists. </P
></LI
></UL
></DIV
><DIV
CLASS="SECT3"
><H3
CLASS="SECT3"
><A
NAME="AEN3730"
>5.5.6.9. Issues with Dropping Objects</A
></H3
><A
NAME="AEN3732"
></A
><P
></P
><UL
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setDropTable(): table % not found</TT
></P
><P
> Table wasn't found on this node; are you sure you had the ID right? </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setDropTable(): set % not found</TT
></P
><P
> The replication set wasn't found on this node; are you sure you had the ID right? </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setDropTable(): set % has remote origin</TT
></P
><P
> The replication set doesn't originate on this node; you probably need to specify an <TT
CLASS="COMMAND"
>EVENT NODE</TT
> in the <A
HREF="stmtsetdroptable.html"
>SLONIK SET DROP TABLE</A
> command. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setDropSequence_int(): sequence % not found</TT
></P
><P
> Could this sequence be in another set?</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setDropSequence_int(): set % not found</TT
></P
><P
> Could you have gotten the set ID wrong?</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I setDropSequence_int(): set % has origin at another node - submit this to that node</TT
></P
><P
> This message seems fairly self-explanatory...</P
></LI
></UL
></DIV
><DIV
CLASS="SECT3"
><H3
CLASS="SECT3"
><A
NAME="AEN3761"
>5.5.6.10. Issues with MOVE SET, FAILOVER, DROP NODE</A
></H3
><A
NAME="AEN3763"
></A
><P
> Many of these errors will occur if you submit a <A
HREF="slonik.html"
><SPAN
CLASS="APPLICATION"
>slonik</SPAN
></A
>
script that describes a reconfiguration incompatible with your
cluster's current configuration.  Those will lead to the
feeling: <SPAN
CLASS="QUOTE"
>"Whew, I'm glad <A
HREF="slonik.html"
><SPAN
CLASS="APPLICATION"
>slonik</SPAN
></A
> caught that for me!"</SPAN
> </P
><P
> Some of the others lead to a <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> telling itself to fall
over; all <SPAN
CLASS="emphasis"
><I
CLASS="EMPHASIS"
>should</I
></SPAN
> be well when you restart it, as
it will read in the revised, newly-correct configuration when it
starts up.</P
><P
> Alas, a few indicate that <SPAN
CLASS="QUOTE"
>"something bad
happened,"</SPAN
> for which the resolution may not necessarily be
easy.  Nobody said that replication was easy, alas...</P
><P
></P
><UL
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: DROP_NODE cannot initiate on the dropped node</TT
></P
><P
> You need to have an EVENT NODE other than the node that is to be dropped.... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: Node % is still configured as a data provider</TT
></P
><P
> You cannot drop a node that is in use as a data provider; you
need to reshape subscriptions so no nodes are dependent on it first. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: Node % is still origin of one or more sets</TT
></P
><P
> You can't drop a node if it is the origin for a set!  Use <A
HREF="stmtmoveset.html"
>SLONIK MOVE SET</A
> or <A
HREF="stmtfailover.html"
>SLONIK FAILOVER</A
> first. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: cannot failover - node % has no path to the backup node</TT
></P
><P
> You cannot failover to a node that isn't connected to all the subscribers, at least indirectly. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: cannot failover - node % is not subscribed to set %</TT
></P
><P
> You can't failover to a node that doesn't subscribe to all the relevant sets. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: cannot failover - subscription for set % is not active</TT
></P
><P
> If the subscription has been set up, but isn't yet active, that's still no good.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: cannot failover - node % is not a forwarder of set %</TT
></P
><P
> You can only failover or move a set to a node that has
forwarding turned on. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>NOTICE: failedNode: set % has no other direct receivers - move now</TT
></P
><P
> If the backup node is the only direct subscriber, then life is a bit simplified...  No need to reshape any subscriptions!</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>NOTICE: failedNode set % has other direct receivers - change providers only</TT
></P
><P
> In this case, all direct subscribers are pointed to the backup node, and the backup node is pointed to receive from another node so it can get caught up.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>NOTICE: Slony-I: Please drop schema _@CLUSTERNAME@</TT
></P
><P
> A node has been uninstalled; you may need to drop the schema... </P
></LI
></UL
></DIV
><DIV
CLASS="SECT3"
><H3
CLASS="SECT3"
><A
NAME="AEN3817"
>5.5.6.11. Log Switching</A
></H3
><A
NAME="AEN3819"
></A
><P
> These messages relate to the new-in-1.2 facility whereby
<SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
> periodically switches back and forth between storing data
in <TT
CLASS="ENVAR"
>sl_log_1</TT
> and <TT
CLASS="ENVAR"
>sl_log_2</TT
>.</P
><P
></P
><UL
><LI
><P
><TT
CLASS="COMMAND"
>Slony-I: Logswitch to sl_log_2 initiated'</TT
></P
><P
> Indicates that <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> is in the process of switching over to this log table.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>Slony-I: Logswitch to sl_log_1 initiated'</TT
></P
><P
> Indicates that <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> is in the process of switching over to this log table.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>Previous logswitch still in progress</TT
></P
><P
> An attempt was made to do a log switch while one was in progress...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: remoteWorkerThread_%d: cannot determine current log status</TT
></P
><P
> The attempt to read from sl_log_status, which determines
whether we're working on <TT
CLASS="ENVAR"
>sl_log_1</TT
>
or <TT
CLASS="ENVAR"
>sl_log_2</TT
> got no results; that can't be a good thing,
as there certainly should be data here...  Replication is likely about
to halt...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: current local log_status is %d</TT
></P
><P
> This indicates which of <TT
CLASS="ENVAR"
>sl_log_1</TT
> and <TT
CLASS="ENVAR"
>sl_log_2</TT
> are being used to store replication data. </P
></LI
></UL
></DIV
><DIV
CLASS="SECT3"
><H3
CLASS="SECT3"
><A
NAME="AEN3852"
>5.5.6.12. Miscellanea</A
></H3
><A
NAME="AEN3854"
></A
><P
> Perhaps these messages should be categorized further; that
remains a task for the documentors.</P
><P
></P
><UL
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slonik version: @MODULEVERSION@ != Slony-I version in PG build %</TT
></P
><P
> This is raised in <CODE
CLASS="FUNCTION"
>checkmoduleversion()</CODE
> if there is a mismatch between the version of <SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
> as reported by <A
HREF="slonik.html"
><SPAN
CLASS="APPLICATION"
>slonik</SPAN
></A
> versus what the <SPAN
CLASS="PRODUCTNAME"
>PostgreSQL</SPAN
> build has.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: registry key % is not an int4 value</TT
></P
><P
> Raised in <CODE
CLASS="FUNCTION"
>registry_get_int4()</CODE
>, this complains if a requested value turns out to be NULL.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: registry key % is not a text value</TT
></P
><P
> Raised in <CODE
CLASS="FUNCTION"
>registry_get_text()</CODE
>, this complains if a requested value turns out to be NULL.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: registry key % is not a timestamp value</TT
></P
><P
> Raised in <CODE
CLASS="FUNCTION"
>registry_get_timestamp()</CODE
>, this complains if a requested value turns out to be NULL.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>NOTICE: Slony-I: cleanup stale sl_nodelock entry for pid=%</TT
></P
><P
> This will occur when a <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> starts up after another has crashed; this is routine cleanup.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: This node is already initialized</TT
></P
><P
> This would typically happen if you submit <A
HREF="stmtstorenode.html"
>SLONIK STORE NODE</A
> against a node that has already been set up with the <SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
> schema. </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: node % not found</TT
></P
><P
> An attempt to mark a node not listed locally as enabled should fail...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>ERROR: Slony-I: node % is already active</TT
></P
><P
> An attempt to mark a node already marked as active as active should fail...</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG4: remoteWorkerThread_%d: added active set %d to provider %d</TT
></P
><P
> Indicates that this set is being provided by this
provider.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: event %d
ignored - unknown origin</TT
></P
><P
> Probably happens if events arrive before
the <TT
CLASS="COMMAND"
>STORE_NODE</TT
> event that tells that the new node
now exists... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>WARN: remoteWorkerThread_%d: event %d ignored - origin inactive</TT
></P
><P
> This shouldn't occur now (2007) as we don't support the notion
of deactivating a node... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: event %d ignored - duplicate </TT
></P
><P
> This might be expected to happen if the event notification
comes in concurrently from two sources... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>DEBUG2: remoteWorkerThread_%d: unknown node %d</TT
></P
><P
> Happens if the <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> is unaware of this node; probably a sign
of <TT
CLASS="COMMAND"
>STORE_NODE</TT
> requests not
propagating... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>insert or update on table "sl_path" violates
foreign key constraint "pa_client-no_id-ref".  DETAIL: Key
(pa_client)=(2) is not present on table "s1_node</TT
></P
><P
> This happens if you try to do <A
HREF="stmtsubscribeset.html"
>SLONIK SUBSCRIBE SET</A
>
when the node unaware of a would-be new node; probably a sign of
<TT
CLASS="COMMAND"
>STORE_NODE</TT
> and <TT
CLASS="COMMAND"
>STORE_PATH</TT
>
requests not propagating... </P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>monitorThread: stack reallocation - size %d &#62; warning threshold of 100.  Stack perhaps isn't getting processed properly by monitoring thread</TT
></P
><P
> This is liable to occur if the monitoring thread isn't properly
consuming updates from the stack, so the stack is growing in memory.</P
></LI
><LI
><P
><TT
CLASS="COMMAND"
>monitor_state - unable to allocate memory for actor (len %d)</TT
></P
><P
> This occurs when the <A
HREF="slon.html"
><SPAN
CLASS="APPLICATION"
>slon</SPAN
></A
> function
<CODE
CLASS="FUNCTION"
>monitor_state()</CODE
> is unable to allocate memory,
which likely indicates that something has grown in memory in an
unbounded way.  </P
><P
> Similar log entries may also occur for event types.</P
></LI
></UL
></DIV
></DIV
></DIV
><DIV
CLASS="NAVFOOTER"
><HR
ALIGN="LEFT"
WIDTH="100%"><TABLE
SUMMARY="Footer navigation table"
WIDTH="100%"
BORDER="0"
CELLPADDING="0"
CELLSPACING="0"
><TR
><TD
WIDTH="33%"
ALIGN="left"
VALIGN="top"
><A
HREF="slonyupgrade.html"
ACCESSKEY="P"
>Prev</A
></TD
><TD
WIDTH="34%"
ALIGN="center"
VALIGN="top"
><A
HREF="index.html"
ACCESSKEY="H"
>Home</A
></TD
><TD
WIDTH="33%"
ALIGN="right"
VALIGN="top"
><A
HREF="performance.html"
ACCESSKEY="N"
>Next</A
></TD
></TR
><TR
><TD
WIDTH="33%"
ALIGN="left"
VALIGN="top"
><SPAN
CLASS="PRODUCTNAME"
>Slony-I</SPAN
> Upgrade</TD
><TD
WIDTH="34%"
ALIGN="center"
VALIGN="top"
><A
HREF="deploymentconcerns.html"
ACCESSKEY="U"
>Up</A
></TD
><TD
WIDTH="33%"
ALIGN="right"
VALIGN="top"
>Performance Considerations</TD
></TR
></TABLE
></DIV
></BODY
></HTML
>
slony1-2-doc 2.1.4-1ubuntu1 / usr / share / doc / slony1-2-doc / adminguide / loganalysis.html
