<html><body style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space; ">Running slony 1.2.10 we encountered an issue with a schema upgrade when it propagated to the secondary in a two-node slony mirror. Our typical procedure for doing schema upgrades is as follows:
<div><br class="webkit-block-placeholder"></div><div>1, Point the application server clients to the secondary (the app becomes "read-only" as a result)</div><div>2. After a few minutes, turn off the slon daemons so we can control when the schema changes propagate</div><div>3. Appy the schema changes (to the primary) via slonik using execute script also adding and removing tables from the replication set as needed.</div><div>4. After the upgrade completes on the primary, point the app servers back to it, so the secondary is quiet.</div><div>5. Turn on the slon daemons and wait for the changes to propagate to the secondary.</div><div>6. Go to sleep or play video games or what-have-you 8^)</div><div><br class="webkit-block-placeholder"></div><div>This has worked well for us for dozens (if not hundreds) of upgrades, with very occasional hiccups in step 5 due to timing related issues (when adding tables, etc). Last night though we had a problem with step 4, a wedged pgpool process prevented the app servers from switching back to the primary. When we tried to switch them, the timed out trying to connect and spontaneously failed over to the secondary once again as they are programmed to. Unfortunately this went unnoticed as we proceeded to step 5. Due to the level of concurrency, this lead to the following deadlock error on the secondary:</div><div><br class="webkit-block-placeholder"></div><div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">2007-12-18 21:41:12.174 PST [d:radio_prod_seg11 u:slony p:6313 9] ERROR: deadlo</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">ck detected</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">2007-12-18 21:41:12.174 PST [d:radio_prod_seg11 u:slony p:6313 10] DETAIL: Proc</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">ess 6313 waits for AccessExclusiveLock on relation 20355 of database 19833; bloc</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">ked by process 11991.</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "> Process 11991 waits for AccessShareLock on relation 20083 of database 19</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">833; blocked by process 6313.</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">2007-12-18 21:41:12.174 PST [d:radio_prod_seg11 u:slony p:6313 11] CONTEXT: SQL</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "> statement "lock table "public"."feedback_packed" in access exclusive mode"</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "> PL/pgSQL function "altertableforreplication" line 53 at execute statemen</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">t</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "> SQL statement "SELECT "_radio".alterTableForReplication( $1 )"</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "> PL/pgSQL function "ddlscript_complete_int" line 11 at perform</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">2007-12-18 21:41:12.174 PST [d:radio_prod_seg11 u:slony p:6313 12] STATEMENT: s</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">elect "_radio".ddlScript_complete_int(1, -1);</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "><br class="webkit-block-placeholder"></div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">Unfortunately this too went unnoticed at first, what we did notice was that the app servers were still failed over and we couldn't connect to the primary. This was quickly tracked down to the problem with pgpool which was fixed by restarting it. After that, we succeeded in switching the app servers back to the primary. </div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "><br class="webkit-block-placeholder"></div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">At that point the slon daemons were running, but the secondary daemon was not getting anywhere. A look at the logs revealed this error:</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "><br class="webkit-block-placeholder"></div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "><font face="Helvetica" size="3" style="font: 12.0px Helvetica">ERROR remoteWorkerThread_1: "select "_radio".ddlScript_prepare_int(1, -1); " PGRES_FATAL_ERROR ERROR: Slony-I: alterTableRestore(): Table "public"."settlement_log" is not in altered state</font></div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "><font face="Helvetica" size="3" style="font: 12.0px Helvetica"> INFO <output from /usr/lib/postgresql/bin/slon> CONTEXT: SQL statement "SELECT "_radio".alterTableRestore( $1 )"</font></div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "><br class="webkit-block-placeholder"></div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">This resulted in a bit of a sinking feeling in my gut, since I knew this likely meant that none of the replicated tables were in the altered state, thus none of the slony triggers were present to prevent data from being written to the secondary. A quick look at the tables revealed this to be the case. Unfortunately by this time the app servers were happily writing to the primary, thus the mirror was broken and the slony pair was hosed.</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "><br class="webkit-block-placeholder"></div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">So the end result was that data got written to the secondary, and is more-or-less lost because other rows with the same primary key values got added to the primary subsequent to that.</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "><br class="webkit-block-placeholder"></div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">This situation points to a lack of atomicity in execute script. Obviously the removal of the slony trigggers and the schema changes were applied in a separate transaction from the restoration of the triggers. This leads to this dangerous possibly that the former will succeed but the latter will fail, leading to the issue I ran into here.</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "><br class="webkit-block-placeholder"></div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">Glancing at the changelog for slony 1.2.12, there appear to be changes around transaction handling in execute script. Would those changes prevent this problem? Note I plan to upgrade soon anyway, but obviously such a fix makes upgrading a more compelling thing for me to do even sooner.</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "><br class="webkit-block-placeholder"></div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">Thanks.</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "><br class="webkit-block-placeholder"></div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; ">-Casey</div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "><br class="webkit-block-placeholder"></div><div style="margin-top: 0px; margin-right: 0px; margin-bottom: 0px; margin-left: 0px; "><br class="webkit-block-placeholder"></div></div></div><div><br class="webkit-block-placeholder"></div><div><br class="webkit-block-placeholder"></div></body></html>