Jeff Frost wrote:
> On Sat, 12 Jan 2008, Craig James wrote:
> =

>> Now all of my tables are locked, and I can't do our weekend update of =

>> our data.  When I try to do anything, I get:
>>
>>  execute failed: ERROR: Slony-I: Table sample is currently locked =

>> against updates because of MOVE_SET operation in progress.
>>
>> Help!  This is critical.  I need to at least get back to where I can =

>> update our database, like TONIGHT!  I thought this would be a fast =

>> operation, because in the past (on smaller databases), it's been =

>> virtually instantaneous.
>>
>> 1. How do I release the lock?
>> 2. Why didn't the migration work???
>>
> =

> Craig,
> =

> You can unlock it with the UNLOCK SET command.  You can find it here in =

> the docs:
> =

> http://slony.info/documentation/stmtunlockset.html

Thanks, Jeff, you saved my day.


> I'd check the logs to see if there are any clues as to why the move set =

> failed to complete.

Nothing jumps out at me.  On the master node, there's nothing at all during=
 the time the script was running.  Just a bunch of "DST DEBUG1 cleanupThrea=
d" events, nothing else.

On the slave node, there are some messages; maybe the attached logfile will=
 mean something to you.

One fact I discovered: The clocks on the two machines were badly out of syn=
c, about 30 minutes.  I assume this is a Bad Thing?

Another fact: After the migrate-node operation failed, I had to restart Pos=
tgres because one Postgres process was using 100% CPU, and several hundred =
other processes were waiting on SELECT statements -- the CPU was rapidly ge=
tting wedged and wasn't far from locking up altogether.  (These were web-si=
te visitors trying to do queries, each one caused another blocked process.)

So the "lost connection" message may be when I shut down Postgres.

> BTW, what version of slony are you using?

Version 1.2.9, Postgres 8.1.4.

Thanks,
Craig

-------------- next part --------------
2008-01-12 16:24:08 PST DEBUG2 remoteWorkerThread_1: current local log_stat=
us is 0
2008-01-12 16:24:08 PST DEBUG2 remoteWorkerThread_1_1: current remote log_s=
tatus =3D 0
2008-01-12 16:24:08 PST DEBUG2 remoteHelperThread_1_1: 0.003 seconds delay =
for first row
2008-01-12 16:24:08 PST DEBUG2 remoteHelperThread_1_1: 0.004 seconds until =
close cursor
2008-01-12 16:24:08 PST DEBUG2 remoteHelperThread_1_1: inserts=3D0 updates=
=3D0 deletes=3D0
2008-01-12 16:24:08 PST DEBUG2 remoteWorkerThread_1: new sl_rowid_seq value=
: 1000000000000000
2008-01-12 16:24:08 PST DEBUG2 remoteWorkerThread_1: SYNC 791981 done in 0.=
011 seconds
2008-01-12 16:24:16 PST DEBUG2 remoteListenThread_1: LISTEN
2008-01-12 16:24:17 PST DEBUG2 syncThread: new sl_action_seq 1 - SYNC 759693
2008-01-12 16:24:17 PST DEBUG2 remoteWorkerThread_1: forward confirm 2,7596=
93 received by 1
2008-01-12 16:24:17 PST ERROR  remoteListenThread_1: "select ev_origin, ev_=
seqno, ev_timestamp,        ev_minxid, ev_maxxid, ev_xip,        ev_type,  =
      ev_data1, ev_data2,        ev_data3, ev_data4,        ev_data5, ev_da=
ta6,        ev_data7, ev_data8 from "_emol_warehouse_1_cluster".sl_event e =
where (e.ev_origin =3D '1' and e.ev_seqno > '791981') order by e.ev_origin,=
 e.ev_seqno" - FATAL:  terminating connection due to administrator command
2008-01-12 16:24:20 PST DEBUG2 localListenThread: Received event 2,759693 S=
YNC
2008-01-12 16:24:27 PST DEBUG2 syncThread: new sl_action_seq 1 - SYNC 759694
2008-01-12 16:24:31 PST DEBUG1 remoteListenThread_1: connected to 'dbname=
=3Demol_warehouse_1  host=3Dradon user=3Dpostgres'
2008-01-12 16:24:32 PST DEBUG2 localListenThread: Received event 2,759694 S=
YNC
2008-01-12 16:24:32 PST DEBUG2 remoteWorkerThread_1: forward confirm 2,7596=
94 received by 1
2008-01-12 16:24:35 PST DEBUG2 remoteListenThread_1: queue event 1,791982 S=
YNC
2008-01-12 16:24:35 PST DEBUG2 remoteListenThread_1: UNLISTEN
2008-01-12 16:24:35 PST DEBUG2 remoteWorkerThread_1: Received event 1,79198=
2 SYNC
2008-01-12 16:24:35 PST DEBUG2 remoteWorkerThread_1: SYNC 791982 processing
2008-01-12 16:24:35 PST DEBUG2 remoteWorkerThread_1: syncing set 1 with 19 =
table(s) from provider 1
2008-01-12 16:24:35 PST DEBUG2  ssy_action_list length: 0
2008-01-12 16:24:35 PST DEBUG2 remoteWorkerThread_1: current local log_stat=
us is 0
2008-01-12 16:24:35 PST ERROR  remoteWorkerThread_1: "start transaction; se=
t enable_seqscan =3D off; set enable_indexscan =3D on; " PGRES_FATAL_ERROR =
FATAL:  terminating connection due to administrator command
server closed the connection unexpectedly
	This probably means the server terminated abnormally
	before or while processing the request.
2008-01-12 16:24:35 PST ERROR  remoteWorkerThread_1: "close LOG; " PGRES_FA=
TAL_ERROR 2008-01-12 16:24:35 PST ERROR  remoteWorkerThread_1: "rollback tr=
ansaction; set enable_seqscan =3D default; set enable_indexscan =3D default=
; " PGRES_FATAL_ERROR 2008-01-12 16:24:35 PST DEBUG2 remoteHelperThread_1_1=
: 26.656 seconds until close cursor
2008-01-12 16:24:35 PST DEBUG2 remoteHelperThread_1_1: inserts=3D0 updates=
=3D0 deletes=3D0
2008-01-12 16:24:35 PST ERROR  remoteWorkerThread_1: helper 1 finished with=
 error
2008-01-12 16:24:35 PST ERROR  remoteWorkerThread_1: SYNC aborted
2008-01-12 16:24:37 PST DEBUG2 syncThread: new sl_action_seq 1 - SYNC 759695
2008-01-12 16:24:38 PST DEBUG2 localListenThread: Received event 2,759695 S=
YNC
2008-01-12 16:24:43 PST DEBUG2 remoteListenThread_1: LISTEN
2008-01-12 16:24:45 PST DEBUG2 remoteListenThread_1: queue event 1,791983 S=
YNC
2008-01-12 16:24:45 PST DEBUG2 remoteListenThread_1: UNLISTEN
2008-01-12 16:24:45 PST DEBUG2 remoteWorkerThread_1: SYNC 791982 processing
2008-01-12 16:24:45 PST DEBUG1 remoteWorkerThread_1: connected to data prov=
ider 1 on 'dbname=3Demol_warehouse_1  host=3Dradon user=3Dpostgres'
2008-01-12 16:24:45 PST DEBUG2 remoteWorkerThread_1: syncing set 1 with 19 =
table(s) from provider 1
2008-01-12 16:24:45 PST DEBUG2  ssy_action_list length: 0
2008-01-12 16:24:45 PST DEBUG2 remoteWorkerThread_1: current local log_stat=
us is 0
2008-01-12 16:24:45 PST DEBUG2 remoteWorkerThread_1_1: current remote log_s=
tatus =3D 0
2008-01-12 16:24:46 PST DEBUG2 remoteHelperThread_1_1: 0.794 seconds delay =
for first row
2008-01-12 16:24:46 PST DEBUG2 remoteHelperThread_1_1: 0.794 seconds until =
close cursor
2008-01-12 16:24:46 PST DEBUG2 remoteHelperThread_1_1: inserts=3D0 updates=
=3D0 deletes=3D0
2008-01-12 16:24:46 PST DEBUG2 remoteWorkerThread_1: new sl_rowid_seq value=
: 1000000000000000
2008-01-12 16:24:46 PST DEBUG2 remoteWorkerThread_1: SYNC 791982 done in 1.=
066 seconds
2008-01-12 16:24:46 PST DEBUG2 remoteWorkerThread_1: forward confirm 2,7596=
95 received by 1
2008-01-12 16:24:46 PST DEBUG2 remoteWorkerThread_1: Received event 1,79198=
3 SYNC
2008-01-12 16:24:46 PST DEBUG2 remoteWorkerThread_1: SYNC 791983 processing
2008-01-12 16:24:46 PST DEBUG2 remoteWorkerThread_1: syncing set 1 with 19 =
table(s) from provider 1
2008-01-12 16:24:46 PST DEBUG2  ssy_action_list length: 0
2008-01-12 16:24:46 PST DEBUG2 remoteWorkerThread_1: current local log_stat=
us is 0
2008-01-12 16:24:46 PST DEBUG2 remoteWorkerThread_1_1: current remote log_s=
tatus =3D 0
2008-01-12 16:24:46 PST DEBUG2 remoteHelperThread_1_1: 0.001 seconds delay =
for first row