From f0f7a691a34abfea91b0ceaaedc52413df11baa2 Mon Sep 17 00:00:00 2001 From: Brian Cloutier Date: Tue, 31 Jul 2018 14:30:56 -0700 Subject: [PATCH] Prevent failure tests from hanging by using a port outside the ephemeral port range - mitmdump now listens on port 9060 - Add some logging to fluent.py, making issues like this easier to debug in the future - Fail the tests if something is already running on the port mitmProxy tries to use - check-failure now works with VPATH builds --- .../expected/failure_add_disable_node.out | 44 ++-- .../expected/failure_copy_to_reference.out | 16 +- .../failure_create_index_concurrently.out | 8 +- src/test/regress/expected/failure_ddl.out | 220 +++++++++--------- src/test/regress/expected/failure_setup.out | 10 +- .../regress/expected/failure_truncate.out | 46 ++-- src/test/regress/mitmscripts/fluent.py | 11 + src/test/regress/pg_regress_multi.pl | 44 +++- src/test/regress/sql/failure_setup.sql | 4 +- 9 files changed, 221 insertions(+), 182 deletions(-) diff --git a/src/test/regress/expected/failure_add_disable_node.out b/src/test/regress/expected/failure_add_disable_node.out index c81d0ab3f..3423e239d 100644 --- a/src/test/regress/expected/failure_add_disable_node.out +++ b/src/test/regress/expected/failure_add_disable_node.out @@ -17,8 +17,8 @@ SELECT * FROM master_get_active_worker_nodes() ORDER BY 1, 2; node_name | node_port -----------+----------- + localhost | 9060 localhost | 57637 - localhost | 57640 (2 rows) -- verify there are no tables that could prevent add/remove node operations @@ -54,7 +54,7 @@ ORDER BY placementid; (2 rows) SELECT master_disable_node('localhost', :worker_2_proxy_port); -NOTICE: Node localhost:57640 has active shard placements. Some queries may fail after this operation. Use SELECT master_activate_node('localhost', 57640) to activate this node back. +NOTICE: Node localhost:9060 has active shard placements. Some queries may fail after this operation. Use SELECT master_activate_node('localhost', 9060) to activate this node back. master_disable_node --------------------- @@ -84,11 +84,11 @@ SELECT citus.mitmproxy('conn.onQuery(query="CREATE TABLE").kill()'); (1 row) SELECT master_activate_node('localhost', :worker_2_proxy_port); -NOTICE: Replicating reference table "user_table" to the node localhost:57640 +NOTICE: Replicating reference table "user_table" to the node localhost:9060 ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -120,11 +120,11 @@ SELECT citus.mitmproxy('conn.onQuery(query="CREATE SCHEMA").kill()'); (1 row) SELECT master_activate_node('localhost', :worker_2_proxy_port); -NOTICE: Replicating reference table "user_table" to the node localhost:57640 +NOTICE: Replicating reference table "user_table" to the node localhost:9060 ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 -- verify node is not activated SELECT * FROM master_get_active_worker_nodes() ORDER BY 1, 2; @@ -150,7 +150,7 @@ SELECT citus.mitmproxy('conn.onQuery(query="CREATE TABLE").cancel(' || pg_backen (1 row) SELECT master_activate_node('localhost', :worker_2_proxy_port); -NOTICE: Replicating reference table "user_table" to the node localhost:57640 +NOTICE: Replicating reference table "user_table" to the node localhost:9060 ERROR: canceling statement due to user request -- verify node is not activated SELECT * FROM master_get_active_worker_nodes() @@ -207,9 +207,9 @@ ORDER BY placementid; -- it does not create any network activity therefore can not -- be injected failure through network SELECT master_add_inactive_node('localhost', :worker_2_proxy_port); - master_add_inactive_node ---------------------------------------------------- - (3,3,localhost,57640,default,f,f,primary,default) + master_add_inactive_node +-------------------------------------------------- + (3,3,localhost,9060,default,f,f,primary,default) (1 row) SELECT master_remove_node('localhost', :worker_2_proxy_port); @@ -236,11 +236,11 @@ SELECT citus.mitmproxy('conn.onQuery(query="CREATE TABLE").kill()'); (1 row) SELECT master_add_node('localhost', :worker_2_proxy_port); -NOTICE: Replicating reference table "user_table" to the node localhost:57640 +NOTICE: Replicating reference table "user_table" to the node localhost:9060 ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 -- verify node is not added SELECT * FROM master_get_active_worker_nodes() ORDER BY 1, 2; @@ -265,7 +265,7 @@ SELECT citus.mitmproxy('conn.onQuery(query="CREATE TABLE").cancel(' || pg_backen (1 row) SELECT master_add_node('localhost', :worker_2_proxy_port); -NOTICE: Replicating reference table "user_table" to the node localhost:57640 +NOTICE: Replicating reference table "user_table" to the node localhost:9060 ERROR: canceling statement due to user request -- verify node is not added SELECT * FROM master_get_active_worker_nodes() @@ -292,10 +292,10 @@ SELECT citus.mitmproxy('conn.allow()'); (1 row) SELECT master_add_node('localhost', :worker_2_proxy_port); -NOTICE: Replicating reference table "user_table" to the node localhost:57640 - master_add_node ---------------------------------------------------- - (6,6,localhost,57640,default,f,t,primary,default) +NOTICE: Replicating reference table "user_table" to the node localhost:9060 + master_add_node +-------------------------------------------------- + (6,6,localhost,9060,default,f,t,primary,default) (1 row) -- verify node is added @@ -303,8 +303,8 @@ SELECT * FROM master_get_active_worker_nodes() ORDER BY 1, 2; node_name | node_port -----------+----------- + localhost | 9060 localhost | 57637 - localhost | 57640 (2 rows) SELECT shardid, shardstate @@ -332,14 +332,14 @@ SELECT citus.mitmproxy('conn.onQuery(query="COPY").kill()'); SELECT master_add_node('localhost', :worker_1_port); NOTICE: Replicating reference table "user_table" to the node localhost:57637 -ERROR: could not copy table "user_table_200000" from "localhost:57640" +ERROR: could not copy table "user_table_200000" from "localhost:9060" CONTEXT: while executing command on localhost:57637 -- verify node is not added SELECT * FROM master_get_active_worker_nodes() ORDER BY 1, 2; node_name | node_port -----------+----------- - localhost | 57640 + localhost | 9060 (1 row) SELECT citus.mitmproxy('conn.allow()'); @@ -360,8 +360,8 @@ SELECT * FROM master_get_active_worker_nodes() ORDER BY 1, 2; node_name | node_port -----------+----------- + localhost | 9060 localhost | 57637 - localhost | 57640 (2 rows) SELECT shardid, shardstate @@ -381,7 +381,7 @@ SELECT * FROM run_command_on_workers('DROP SCHEMA IF EXISTS add_remove_node CASC ORDER BY nodeport; nodename | nodeport | success | result -----------+----------+---------+------------- + localhost | 9060 | t | DROP SCHEMA localhost | 57637 | t | DROP SCHEMA - localhost | 57640 | t | DROP SCHEMA (2 rows) diff --git a/src/test/regress/expected/failure_copy_to_reference.out b/src/test/regress/expected/failure_copy_to_reference.out index c53aeed4b..2ca89f67e 100644 --- a/src/test/regress/expected/failure_copy_to_reference.out +++ b/src/test/regress/expected/failure_copy_to_reference.out @@ -35,7 +35,7 @@ SELECT citus.mitmproxy('conn.kill()'); (1 row) \copy test_table FROM STDIN DELIMITER ',' -ERROR: connection error: localhost:57640 +ERROR: connection error: localhost:9060 DETAIL: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. @@ -66,7 +66,7 @@ SELECT citus.mitmproxy('conn.onQuery(query="^BEGIN TRANSACTION ISOLATION LEVEL R (1 row) \copy test_table FROM STDIN DELIMITER ',' -ERROR: failure on connection marked as essential: localhost:57640 +ERROR: failure on connection marked as essential: localhost:9060 CONTEXT: COPY test_table, line 1: "1,2" SELECT citus.mitmproxy('conn.allow()'); mitmproxy @@ -125,7 +125,7 @@ SELECT citus.mitmproxy('conn.onQuery(query="^COPY").kill()'); ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 COPY test_table, line 1: "1,2" SELECT citus.mitmproxy('conn.allow()'); mitmproxy @@ -181,7 +181,7 @@ SELECT citus.mitmproxy('conn.onCommandComplete(command="^COPY 3").kill()'); (1 row) \copy test_table FROM STDIN DELIMITER ',' -ERROR: failed to COPY to shard 130000 on localhost:57640 +ERROR: failed to COPY to shard 130000 on localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -239,7 +239,7 @@ SELECT citus.mitmproxy('conn.onQuery(query="FROM STDIN WITH").killall()'); ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 COPY test_table, line 1: "1,2" SELECT citus.mitmproxy('conn.allow()'); mitmproxy @@ -268,7 +268,7 @@ SELECT citus.mitmproxy('conn.onQuery(query="^PREPARE TRANSACTION").kill()'); \copy test_table FROM STDIN DELIMITER ',' ERROR: connection not open -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -399,7 +399,7 @@ SET LOCAL client_min_messages TO WARNING; \copy test_table FROM STDIN DELIMITER ',' ROLLBACK; WARNING: connection not open -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -432,7 +432,7 @@ SET LOCAL client_min_messages TO WARNING; \copy test_table FROM STDIN DELIMITER ',' ROLLBACK; WARNING: connection not open -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- diff --git a/src/test/regress/expected/failure_create_index_concurrently.out b/src/test/regress/expected/failure_create_index_concurrently.out index e243fc0a2..97add8e25 100644 --- a/src/test/regress/expected/failure_create_index_concurrently.out +++ b/src/test/regress/expected/failure_create_index_concurrently.out @@ -40,7 +40,7 @@ SELECT * FROM run_command_on_workers($$SELECT count(*) FROM pg_indexes WHERE ind WHERE nodeport = :worker_2_proxy_port; nodename | nodeport | success | result -----------+----------+---------+-------- - localhost | 57640 | t | 0 + localhost | 9060 | t | 0 (1 row) DROP TABLE index_test; @@ -73,7 +73,7 @@ SELECT * FROM run_command_on_workers($$SELECT count(*) FROM pg_indexes WHERE ind WHERE nodeport = :worker_2_proxy_port; nodename | nodeport | success | result -----------+----------+---------+-------- - localhost | 57640 | t | 1 + localhost | 9060 | t | 1 (1 row) DROP TABLE index_test; @@ -184,7 +184,7 @@ SELECT * FROM run_command_on_workers($$SELECT count(*) FROM pg_indexes WHERE ind WHERE nodeport = :worker_2_proxy_port; nodename | nodeport | success | result -----------+----------+---------+-------- - localhost | 57640 | t | 4 + localhost | 9060 | t | 4 (1 row) RESET SEARCH_PATH; @@ -195,6 +195,6 @@ SELECT * FROM run_command_on_workers($$SELECT count(*) FROM pg_indexes WHERE ind WHERE nodeport = :worker_2_proxy_port; nodename | nodeport | success | result -----------+----------+---------+-------- - localhost | 57640 | t | 0 + localhost | 9060 | t | 0 (1 row) diff --git a/src/test/regress/expected/failure_ddl.out b/src/test/regress/expected/failure_ddl.out index e53ff1dfd..27436dd56 100644 --- a/src/test/regress/expected/failure_ddl.out +++ b/src/test/regress/expected/failure_ddl.out @@ -34,7 +34,7 @@ SELECT citus.mitmproxy('conn.onAuthenticationOk().kill()'); (1 row) ALTER TABLE test_table ADD COLUMN new_column INT; -ERROR: connection error: localhost:57640 +ERROR: connection error: localhost:9060 DETAIL: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. @@ -68,7 +68,7 @@ SELECT citus.mitmproxy('conn.onQuery(query="^BEGIN TRANSACTION ISOLATION LEVEL R (1 row) ALTER TABLE test_table ADD COLUMN new_column INT; -ERROR: failure on connection marked as essential: localhost:57640 +ERROR: failure on connection marked as essential: localhost:9060 SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = 'test_table'::regclass; array_agg ------------- @@ -101,7 +101,7 @@ ALTER TABLE test_table ADD COLUMN new_column INT; ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 -- show that we've never commited the changes SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = 'test_table'::regclass; array_agg @@ -153,10 +153,10 @@ SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where r SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ----------------------------------------------------- - (localhost,57637,100800,t,"{key,new_column,value}") - (localhost,57637,100802,t,"{key,new_column,value}") - (localhost,57640,100801,t,"{key,value}") - (localhost,57640,100803,t,"{key,value}") + (localhost,9060,100800,t,"{key,value}") + (localhost,9060,100802,t,"{key,value}") + (localhost,57637,100801,t,"{key,new_column,value}") + (localhost,57637,100803,t,"{key,new_column,value}") (4 rows) -- manually drop & re-create the table for the next tests @@ -197,10 +197,10 @@ SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where r SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ----------------------------------------------------- - (localhost,57637,100800,t,"{key,new_column,value}") - (localhost,57637,100802,t,"{key,new_column,value}") - (localhost,57640,100801,t,"{key,new_column,value}") - (localhost,57640,100803,t,"{key,new_column,value}") + (localhost,9060,100800,t,"{key,new_column,value}") + (localhost,9060,100802,t,"{key,new_column,value}") + (localhost,57637,100801,t,"{key,new_column,value}") + (localhost,57637,100803,t,"{key,new_column,value}") (4 rows) -- the following tests rely the column not exists, so drop manually @@ -217,17 +217,17 @@ SELECT citus.mitmproxy('conn.onCommandComplete(command="^COMMIT").kill()'); ALTER TABLE test_table ADD COLUMN new_column INT; WARNING: connection not open -CONTEXT: while executing command on localhost:57640 -WARNING: failed to commit critical transaction on localhost:57640, metadata is likely out of sync +CONTEXT: while executing command on localhost:9060 +WARNING: failed to commit critical transaction on localhost:9060, metadata is likely out of sync WARNING: connection not open -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 WARNING: connection not open -CONTEXT: while executing command on localhost:57640 -WARNING: failed to commit critical transaction on localhost:57640, metadata is likely out of sync +CONTEXT: while executing command on localhost:9060 +WARNING: failed to commit critical transaction on localhost:9060, metadata is likely out of sync WARNING: connection not open -CONTEXT: while executing command on localhost:57640 -WARNING: could not commit transaction for shard 100803 on any active node -WARNING: could not commit transaction for shard 100801 on any active node +CONTEXT: while executing command on localhost:9060 +WARNING: could not commit transaction for shard 100802 on any active node +WARNING: could not commit transaction for shard 100800 on any active node SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -244,10 +244,10 @@ SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where r SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ----------------------------------------------------- - (localhost,57637,100800,t,"{key,new_column,value}") - (localhost,57637,100802,t,"{key,new_column,value}") - (localhost,57640,100801,t,"{key,new_column,value}") - (localhost,57640,100803,t,"{key,new_column,value}") + (localhost,9060,100800,t,"{key,new_column,value}") + (localhost,9060,100802,t,"{key,new_column,value}") + (localhost,57637,100801,t,"{key,new_column,value}") + (localhost,57637,100803,t,"{key,new_column,value}") (4 rows) -- now cancel just after the worker sends response to @@ -283,9 +283,9 @@ SET LOCAL client_min_messages TO WARNING; ALTER TABLE test_table DROP COLUMN new_column; ROLLBACK; WARNING: connection not open -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 WARNING: connection not open -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 -- now cancel just after the worker sends response to -- but Postgres doesn't accepts interrupts during COMMIT and ROLLBACK -- so should not cancel at all, so not an effective test but adding in @@ -326,10 +326,10 @@ SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where r SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ----------------------------------------------------- - (localhost,57637,100800,t,"{key,new_column,value}") - (localhost,57637,100802,t,"{key,new_column,value}") - (localhost,57640,100801,t,"{key,new_column,value}") - (localhost,57640,100803,t,"{key,new_column,value}") + (localhost,9060,100800,t,"{key,new_column,value}") + (localhost,9060,100802,t,"{key,new_column,value}") + (localhost,57637,100801,t,"{key,new_column,value}") + (localhost,57637,100803,t,"{key,new_column,value}") (4 rows) -- now, lets test with 2PC @@ -343,7 +343,7 @@ SELECT citus.mitmproxy('conn.onAuthenticationOk().kill()'); (1 row) ALTER TABLE test_table DROP COLUMN new_column; -ERROR: connection error: localhost:57640 +ERROR: connection error: localhost:9060 DETAIL: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. @@ -377,7 +377,7 @@ SELECT citus.mitmproxy('conn.onQuery(query="^BEGIN TRANSACTION ISOLATION LEVEL R (1 row) ALTER TABLE test_table DROP COLUMN new_column; -ERROR: failure on connection marked as essential: localhost:57640 +ERROR: failure on connection marked as essential: localhost:9060 SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = 'test_table'::regclass; array_agg ------------------------ @@ -410,7 +410,7 @@ ALTER TABLE test_table DROP COLUMN new_column; ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = 'test_table'::regclass; array_agg ------------------------ @@ -441,7 +441,7 @@ SELECT citus.mitmproxy('conn.onCommandComplete(command="PREPARE TRANSACTION").ki ALTER TABLE test_table DROP COLUMN new_column; ERROR: connection not open -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -457,10 +457,10 @@ SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where r SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ----------------------------------------------------- - (localhost,57637,100800,t,"{key,new_column,value}") - (localhost,57637,100802,t,"{key,new_column,value}") - (localhost,57640,100801,t,"{key,new_column,value}") - (localhost,57640,100803,t,"{key,new_column,value}") + (localhost,9060,100800,t,"{key,new_column,value}") + (localhost,9060,100802,t,"{key,new_column,value}") + (localhost,57637,100801,t,"{key,new_column,value}") + (localhost,57637,100803,t,"{key,new_column,value}") (4 rows) -- we should be able to recover the transaction and @@ -474,10 +474,10 @@ SELECT recover_prepared_transactions(); SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ----------------------------------------------------- - (localhost,57637,100800,t,"{key,new_column,value}") - (localhost,57637,100802,t,"{key,new_column,value}") - (localhost,57640,100801,t,"{key,new_column,value}") - (localhost,57640,100803,t,"{key,new_column,value}") + (localhost,9060,100800,t,"{key,new_column,value}") + (localhost,9060,100802,t,"{key,new_column,value}") + (localhost,57637,100801,t,"{key,new_column,value}") + (localhost,57637,100803,t,"{key,new_column,value}") (4 rows) -- cancelling on PREPARE should be fine, everything should be rollbacked @@ -504,10 +504,10 @@ SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where r SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ----------------------------------------------------- - (localhost,57637,100800,t,"{key,new_column,value}") - (localhost,57637,100802,t,"{key,new_column,value}") - (localhost,57640,100801,t,"{key,new_column,value}") - (localhost,57640,100803,t,"{key,new_column,value}") + (localhost,9060,100800,t,"{key,new_column,value}") + (localhost,9060,100802,t,"{key,new_column,value}") + (localhost,57637,100801,t,"{key,new_column,value}") + (localhost,57637,100803,t,"{key,new_column,value}") (4 rows) -- we should be able to recover the transaction and @@ -521,10 +521,10 @@ SELECT recover_prepared_transactions(); SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ----------------------------------------------------- - (localhost,57637,100800,t,"{key,new_column,value}") - (localhost,57637,100802,t,"{key,new_column,value}") - (localhost,57640,100801,t,"{key,new_column,value}") - (localhost,57640,100803,t,"{key,new_column,value}") + (localhost,9060,100800,t,"{key,new_column,value}") + (localhost,9060,100802,t,"{key,new_column,value}") + (localhost,57637,100801,t,"{key,new_column,value}") + (localhost,57637,100803,t,"{key,new_column,value}") (4 rows) -- killing on command complete of COMMIT PREPARE, we should see that the command succeeds @@ -551,10 +551,10 @@ SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where r SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ------------------------------------------ - (localhost,57637,100800,t,"{key,value}") - (localhost,57637,100802,t,"{key,value}") - (localhost,57640,100801,t,"{key,value}") - (localhost,57640,100803,t,"{key,value}") + (localhost,9060,100800,t,"{key,value}") + (localhost,9060,100802,t,"{key,value}") + (localhost,57637,100801,t,"{key,value}") + (localhost,57637,100803,t,"{key,value}") (4 rows) -- we shouldn't have any prepared transactions in the workers @@ -567,10 +567,10 @@ SELECT recover_prepared_transactions(); SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ------------------------------------------ - (localhost,57637,100800,t,"{key,value}") - (localhost,57637,100802,t,"{key,value}") - (localhost,57640,100801,t,"{key,value}") - (localhost,57640,100803,t,"{key,value}") + (localhost,9060,100800,t,"{key,value}") + (localhost,9060,100802,t,"{key,value}") + (localhost,57637,100801,t,"{key,value}") + (localhost,57637,100803,t,"{key,value}") (4 rows) -- kill as soon as the coordinator sends COMMIT @@ -598,10 +598,10 @@ SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where r SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ----------------------------------------------------- - (localhost,57637,100800,t,"{key,new_column,value}") - (localhost,57637,100802,t,"{key,new_column,value}") - (localhost,57640,100801,t,"{key,value}") - (localhost,57640,100803,t,"{key,value}") + (localhost,9060,100800,t,"{key,value}") + (localhost,9060,100802,t,"{key,value}") + (localhost,57637,100801,t,"{key,new_column,value}") + (localhost,57637,100803,t,"{key,new_column,value}") (4 rows) -- we should be able to recover the transaction and @@ -615,10 +615,10 @@ SELECT recover_prepared_transactions(); SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ----------------------------------------------------- - (localhost,57637,100800,t,"{key,new_column,value}") - (localhost,57637,100802,t,"{key,new_column,value}") - (localhost,57640,100801,t,"{key,new_column,value}") - (localhost,57640,100803,t,"{key,new_column,value}") + (localhost,9060,100800,t,"{key,new_column,value}") + (localhost,9060,100802,t,"{key,new_column,value}") + (localhost,57637,100801,t,"{key,new_column,value}") + (localhost,57637,100803,t,"{key,new_column,value}") (4 rows) -- finally, test failing on ROLLBACK with 2PC @@ -649,10 +649,10 @@ SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where r SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ----------------------------------------------------- - (localhost,57637,100800,t,"{key,new_column,value}") - (localhost,57637,100802,t,"{key,new_column,value}") - (localhost,57640,100801,t,"{key,new_column,value}") - (localhost,57640,100803,t,"{key,new_column,value}") + (localhost,9060,100800,t,"{key,new_column,value}") + (localhost,9060,100802,t,"{key,new_column,value}") + (localhost,57637,100801,t,"{key,new_column,value}") + (localhost,57637,100803,t,"{key,new_column,value}") (4 rows) -- but now kill just after the worker sends response to @@ -683,10 +683,10 @@ SELECT recover_prepared_transactions(); SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ----------------------------------------------------- - (localhost,57637,100800,t,"{key,new_column,value}") - (localhost,57637,100802,t,"{key,new_column,value}") - (localhost,57640,100801,t,"{key,new_column,value}") - (localhost,57640,100803,t,"{key,new_column,value}") + (localhost,9060,100800,t,"{key,new_column,value}") + (localhost,9060,100802,t,"{key,new_column,value}") + (localhost,57637,100801,t,"{key,new_column,value}") + (localhost,57637,100803,t,"{key,new_column,value}") (4 rows) -- another set of tests with 2PC and replication factor = 2 @@ -711,7 +711,7 @@ SELECT citus.mitmproxy('conn.onAuthenticationOk().kill()'); (1 row) ALTER TABLE test_table ADD COLUMN new_column INT; -ERROR: connection error: localhost:57640 +ERROR: connection error: localhost:9060 DETAIL: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. @@ -745,7 +745,7 @@ SELECT citus.mitmproxy('conn.onQuery(query="^BEGIN TRANSACTION ISOLATION LEVEL R (1 row) ALTER TABLE test_table ADD COLUMN new_column INT; -ERROR: failure on connection marked as essential: localhost:57640 +ERROR: failure on connection marked as essential: localhost:9060 SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = 'test_table'::regclass; array_agg ------------- @@ -778,7 +778,7 @@ ALTER TABLE test_table ADD COLUMN new_column INT; ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = 'test_table'::regclass; array_agg ------------- @@ -809,7 +809,7 @@ SELECT citus.mitmproxy('conn.onCommandComplete(command="PREPARE TRANSACTION").ki ALTER TABLE test_table ADD COLUMN new_column INT; ERROR: connection not open -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -830,14 +830,14 @@ SELECT recover_prepared_transactions(); SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ------------------------------------------ + (localhost,9060,100804,t,"{key,value}") + (localhost,9060,100805,t,"{key,value}") + (localhost,9060,100806,t,"{key,value}") + (localhost,9060,100807,t,"{key,value}") (localhost,57637,100804,t,"{key,value}") (localhost,57637,100805,t,"{key,value}") (localhost,57637,100806,t,"{key,value}") (localhost,57637,100807,t,"{key,value}") - (localhost,57640,100804,t,"{key,value}") - (localhost,57640,100805,t,"{key,value}") - (localhost,57640,100806,t,"{key,value}") - (localhost,57640,100807,t,"{key,value}") (8 rows) -- killing on command complete of COMMIT PREPARE, we should see that the command succeeds @@ -864,14 +864,14 @@ SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where r SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ----------------------------------------------------- + (localhost,9060,100804,t,"{key,new_column,value}") + (localhost,9060,100805,t,"{key,new_column,value}") + (localhost,9060,100806,t,"{key,new_column,value}") + (localhost,9060,100807,t,"{key,new_column,value}") (localhost,57637,100804,t,"{key,new_column,value}") (localhost,57637,100805,t,"{key,new_column,value}") (localhost,57637,100806,t,"{key,new_column,value}") (localhost,57637,100807,t,"{key,new_column,value}") - (localhost,57640,100804,t,"{key,new_column,value}") - (localhost,57640,100805,t,"{key,new_column,value}") - (localhost,57640,100806,t,"{key,new_column,value}") - (localhost,57640,100807,t,"{key,new_column,value}") (8 rows) -- we shouldn't have any prepared transactions in the workers @@ -884,14 +884,14 @@ SELECT recover_prepared_transactions(); SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ----------------------------------------------------- + (localhost,9060,100804,t,"{key,new_column,value}") + (localhost,9060,100805,t,"{key,new_column,value}") + (localhost,9060,100806,t,"{key,new_column,value}") + (localhost,9060,100807,t,"{key,new_column,value}") (localhost,57637,100804,t,"{key,new_column,value}") (localhost,57637,100805,t,"{key,new_column,value}") (localhost,57637,100806,t,"{key,new_column,value}") (localhost,57637,100807,t,"{key,new_column,value}") - (localhost,57640,100804,t,"{key,new_column,value}") - (localhost,57640,100805,t,"{key,new_column,value}") - (localhost,57640,100806,t,"{key,new_column,value}") - (localhost,57640,100807,t,"{key,new_column,value}") (8 rows) -- kill as soon as the coordinator sends COMMIT @@ -917,16 +917,16 @@ SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where r (1 row) SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; - run_command_on_placements ------------------------------------------------------ + run_command_on_placements +---------------------------------------------------- + (localhost,9060,100804,t,"{key,new_column,value}") + (localhost,9060,100805,t,"{key,new_column,value}") + (localhost,9060,100806,t,"{key,new_column,value}") + (localhost,9060,100807,t,"{key,new_column,value}") (localhost,57637,100804,t,"{key,value}") (localhost,57637,100805,t,"{key,value}") (localhost,57637,100806,t,"{key,value}") (localhost,57637,100807,t,"{key,value}") - (localhost,57640,100804,t,"{key,new_column,value}") - (localhost,57640,100805,t,"{key,new_column,value}") - (localhost,57640,100806,t,"{key,new_column,value}") - (localhost,57640,100807,t,"{key,new_column,value}") (8 rows) -- we should be able to recover the transaction and @@ -940,14 +940,14 @@ SELECT recover_prepared_transactions(); SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ------------------------------------------ + (localhost,9060,100804,t,"{key,value}") + (localhost,9060,100805,t,"{key,value}") + (localhost,9060,100806,t,"{key,value}") + (localhost,9060,100807,t,"{key,value}") (localhost,57637,100804,t,"{key,value}") (localhost,57637,100805,t,"{key,value}") (localhost,57637,100806,t,"{key,value}") (localhost,57637,100807,t,"{key,value}") - (localhost,57640,100804,t,"{key,value}") - (localhost,57640,100805,t,"{key,value}") - (localhost,57640,100806,t,"{key,value}") - (localhost,57640,100807,t,"{key,value}") (8 rows) -- finally, test failing on ROLLBACK with 2PC @@ -978,14 +978,14 @@ SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where r SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ------------------------------------------ + (localhost,9060,100804,t,"{key,value}") + (localhost,9060,100805,t,"{key,value}") + (localhost,9060,100806,t,"{key,value}") + (localhost,9060,100807,t,"{key,value}") (localhost,57637,100804,t,"{key,value}") (localhost,57637,100805,t,"{key,value}") (localhost,57637,100806,t,"{key,value}") (localhost,57637,100807,t,"{key,value}") - (localhost,57640,100804,t,"{key,value}") - (localhost,57640,100805,t,"{key,value}") - (localhost,57640,100806,t,"{key,value}") - (localhost,57640,100807,t,"{key,value}") (8 rows) -- but now kill just after the worker sends response to @@ -1016,14 +1016,14 @@ SELECT recover_prepared_transactions(); SELECT run_command_on_placements('test_table', $$SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = '%s'::regclass;$$) ORDER BY 1; run_command_on_placements ------------------------------------------ + (localhost,9060,100804,t,"{key,value}") + (localhost,9060,100805,t,"{key,value}") + (localhost,9060,100806,t,"{key,value}") + (localhost,9060,100807,t,"{key,value}") (localhost,57637,100804,t,"{key,value}") (localhost,57637,100805,t,"{key,value}") (localhost,57637,100806,t,"{key,value}") (localhost,57637,100807,t,"{key,value}") - (localhost,57640,100804,t,"{key,value}") - (localhost,57640,100805,t,"{key,value}") - (localhost,57640,100806,t,"{key,value}") - (localhost,57640,100807,t,"{key,value}") (8 rows) -- now do some tests with sequential mode @@ -1036,7 +1036,7 @@ SELECT citus.mitmproxy('conn.onQuery(query="^BEGIN TRANSACTION ISOLATION LEVEL R (1 row) ALTER TABLE test_table ADD COLUMN new_column INT; -ERROR: failure on connection marked as essential: localhost:57640 +ERROR: failure on connection marked as essential: localhost:9060 SELECT array_agg(name::text ORDER BY name::text) FROM public.table_attrs where relid = 'test_table'::regclass; array_agg ------------- @@ -1069,7 +1069,7 @@ ALTER TABLE test_table ADD COLUMN new_column INT; ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 -- kill as soon as the coordinator after it sends worker_apply_shard_ddl_command 2nd time SELECT citus.mitmproxy('conn.onQuery(query="worker_apply_shard_ddl_command").after(2).kill()'); mitmproxy @@ -1081,7 +1081,7 @@ ALTER TABLE test_table ADD COLUMN new_column INT; ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 -- cancel as soon as the coordinator after it sends worker_apply_shard_ddl_command 2nd time SELECT citus.mitmproxy('conn.onQuery(query="worker_apply_shard_ddl_command").after(2).cancel(' || pg_backend_pid() || ')'); mitmproxy diff --git a/src/test/regress/expected/failure_setup.out b/src/test/regress/expected/failure_setup.out index 666f87960..dbaab7948 100644 --- a/src/test/regress/expected/failure_setup.out +++ b/src/test/regress/expected/failure_setup.out @@ -5,15 +5,15 @@ SELECT citus.mitmproxy('conn.allow()'); (1 row) -- add the workers -SELECT master_add_node('localhost', :worker_1_port); -- the second worker +SELECT master_add_node('localhost', :worker_1_port); master_add_node --------------------------------------------------- (1,1,localhost,57637,default,f,t,primary,default) (1 row) -SELECT master_add_node('localhost', :worker_2_port + 2); -- the first worker, behind a mitmproxy - master_add_node ---------------------------------------------------- - (2,2,localhost,57640,default,f,t,primary,default) +SELECT master_add_node('localhost', :worker_2_proxy_port); -- an mitmproxy which forwards to the second worker + master_add_node +-------------------------------------------------- + (2,2,localhost,9060,default,f,t,primary,default) (1 row) diff --git a/src/test/regress/expected/failure_truncate.out b/src/test/regress/expected/failure_truncate.out index 4954b8574..82d90e90d 100644 --- a/src/test/regress/expected/failure_truncate.out +++ b/src/test/regress/expected/failure_truncate.out @@ -40,7 +40,7 @@ SELECT citus.mitmproxy('conn.onAuthenticationOk().kill()'); (1 row) TRUNCATE test_table; -ERROR: connection error: localhost:57640 +ERROR: connection error: localhost:9060 DETAIL: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. @@ -98,7 +98,7 @@ SELECT citus.mitmproxy('conn.onQuery(query="^BEGIN TRANSACTION ISOLATION LEVEL R (1 row) TRUNCATE test_table; -ERROR: failure on connection marked as essential: localhost:57640 +ERROR: failure on connection marked as essential: localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -155,7 +155,7 @@ TRUNCATE test_table; ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -228,7 +228,7 @@ SELECT * FROM unhealthy_shard_count; SELECT count(*) FROM test_table; count ------- - 12 + 8 (1 row) -- refill the table @@ -277,17 +277,17 @@ SELECT citus.mitmproxy('conn.onCommandComplete(command="^COMMIT").kill()'); TRUNCATE test_table; WARNING: connection not open -CONTEXT: while executing command on localhost:57640 -WARNING: failed to commit critical transaction on localhost:57640, metadata is likely out of sync +CONTEXT: while executing command on localhost:9060 +WARNING: failed to commit critical transaction on localhost:9060, metadata is likely out of sync WARNING: connection not open -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 WARNING: connection not open -CONTEXT: while executing command on localhost:57640 -WARNING: failed to commit critical transaction on localhost:57640, metadata is likely out of sync +CONTEXT: while executing command on localhost:9060 +WARNING: failed to commit critical transaction on localhost:9060, metadata is likely out of sync WARNING: connection not open -CONTEXT: while executing command on localhost:57640 -WARNING: could not commit transaction for shard 120001 on any active node -WARNING: could not commit transaction for shard 120003 on any active node +CONTEXT: while executing command on localhost:9060 +WARNING: could not commit transaction for shard 120002 on any active node +WARNING: could not commit transaction for shard 120000 on any active node SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -358,7 +358,7 @@ SELECT citus.mitmproxy('conn.onQuery(query="PREPARE TRANSACTION").kill()'); TRUNCATE reference_table CASCADE; ERROR: connection not open -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -429,7 +429,7 @@ TRUNCATE reference_table CASCADE; ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -499,7 +499,7 @@ SELECT citus.mitmproxy('conn.onCommandComplete(command="PREPARE TRANSACTION").ki TRUNCATE reference_table CASCADE; ERROR: connection not open -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -570,7 +570,7 @@ SELECT citus.mitmproxy('conn.onAuthenticationOk().kill()'); (1 row) TRUNCATE test_table; -ERROR: connection error: localhost:57640 +ERROR: connection error: localhost:9060 DETAIL: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. @@ -628,7 +628,7 @@ SELECT citus.mitmproxy('conn.onQuery(query="^BEGIN TRANSACTION ISOLATION LEVEL R (1 row) TRUNCATE test_table; -ERROR: failure on connection marked as essential: localhost:57640 +ERROR: failure on connection marked as essential: localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -685,7 +685,7 @@ TRUNCATE test_table; ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -740,7 +740,7 @@ SELECT citus.mitmproxy('conn.onCommandComplete(command="^PREPARE TRANSACTION").k TRUNCATE test_table; ERROR: connection not open -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -946,7 +946,7 @@ SELECT citus.mitmproxy('conn.onAuthenticationOk().kill()'); (1 row) TRUNCATE test_table; -ERROR: connection error: localhost:57640 +ERROR: connection error: localhost:9060 DETAIL: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. @@ -1004,7 +1004,7 @@ SELECT citus.mitmproxy('conn.onQuery(query="^BEGIN TRANSACTION ISOLATION LEVEL R (1 row) TRUNCATE test_table; -ERROR: failure on connection marked as essential: localhost:57640 +ERROR: failure on connection marked as essential: localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -1061,7 +1061,7 @@ TRUNCATE test_table; ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- @@ -1116,7 +1116,7 @@ SELECT citus.mitmproxy('conn.onCommandComplete(command="PREPARE TRANSACTION").ki TRUNCATE test_table; ERROR: connection not open -CONTEXT: while executing command on localhost:57640 +CONTEXT: while executing command on localhost:9060 SELECT citus.mitmproxy('conn.allow()'); mitmproxy ----------- diff --git a/src/test/regress/mitmscripts/fluent.py b/src/test/regress/mitmscripts/fluent.py index 5cb9b32dd..f1ba4f33d 100644 --- a/src/test/regress/mitmscripts/fluent.py +++ b/src/test/regress/mitmscripts/fluent.py @@ -1,3 +1,4 @@ +import logging import re import os import pprint @@ -15,6 +16,8 @@ from mitmproxy.proxy.protocol import TlsLayer, RawTCPLayer import structs +logging.basicConfig(format="%(asctime)s %(levelname)s %(message)s", level=logging.DEBUG) + # I. Command Strings class Stop(Exception): @@ -307,12 +310,17 @@ def listen_for_commands(fifoname): pass result = '\n'.join(results) + logging.debug('about to write to fifo') with open(fifoname, mode='w') as fifo: + logging.debug('successfully opened the fifo for writing') fifo.write('{}'.format(result)) while True: + logging.debug('about to read from fifo') with open(fifoname, mode='r') as fifo: + logging.debug('successfully opened the fifo for reading') slug = fifo.read() + logging.info('received new command: %s', slug.rstrip()) try: handler = build_handler(slug) @@ -329,8 +337,11 @@ def listen_for_commands(fifoname): command_queue.put(slug) result = response_queue.get() + logging.debug('about to write to fifo') with open(fifoname, mode='w') as fifo: + logging.debug('successfully opened the fifo for writing') fifo.write('{}\n'.format(result)) + logging.info('responded to command: %s', result.split("\n")[0]) def create_thread(fifoname): global command_thread diff --git a/src/test/regress/pg_regress_multi.pl b/src/test/regress/pg_regress_multi.pl index aa23ad264..05771a193 100755 --- a/src/test/regress/pg_regress_multi.pl +++ b/src/test/regress/pg_regress_multi.pl @@ -22,6 +22,8 @@ use Config; use POSIX qw( WNOHANG mkfifo ); use Cwd 'abs_path'; +my $regressdir = (File::Spec->splitpath(__FILE__))[1]; + sub Usage() { print "pg_regress_multi - Citus test runner\n"; @@ -252,6 +254,13 @@ sub revert_replace_postgres # partial run, even if we're now not using valgrind. revert_replace_postgres(); +# n.b. previously this was on port 57640, which caused issues because that's in the +# ephemeral port range, it was sometimes in the TIME_WAIT state which prevented us from +# binding to it. 9060 is now used because it will never be used for client connections, +# and there don't appear to be any other applications on this port that developers are +# likely to be running. +my $mitmPort = 9060; + # Set some default configuration options my $masterPort = 57636; my $workerCount = 2; @@ -269,8 +278,6 @@ for (my $workerIndex = 1; $workerIndex <= $workerCount; $workerIndex++) { push(@followerWorkerPorts, $workerPort); } -my $workerBehindProxyPort = $workerPorts[1] + 2; - my $host = "localhost"; my $user = "postgres"; my @pgOptions = (); @@ -419,7 +426,7 @@ if ($usingWindows) } print $fh catfile($bindir, "psql")." "; print $fh "--variable=master_port=$masterPort "; -print $fh "--variable=worker_2_proxy_port=$workerBehindProxyPort "; +print $fh "--variable=worker_2_proxy_port=$mitmPort "; print $fh "--variable=follower_master_port=$followerCoordPort "; print $fh "--variable=default_user=$user "; print $fh "--variable=SHOW_CONTEXT=always "; @@ -548,6 +555,16 @@ sub ShutdownServers() } } +# setup the signal handler before we fork +$SIG{CHLD} = sub { + # If, for some reason, mitmproxy dies before we do, we should also die! + while ((my $waitpid = waitpid(-1, WNOHANG)) > 0) { + if ($mitmPid != 0 && $mitmPid == $waitpid) { + die "aborting tests because mitmdump failed unexpectedly"; + } + } +}; + if ($useMitmproxy) { if (! -e $mitmFifoPath) @@ -560,6 +577,20 @@ if ($useMitmproxy) die "a file already exists at $mitmFifoPath, delete it before trying again"; } + system("lsof -i :$mitmPort"); + if (! $?) { + die "cannot start mitmproxy because a process already exists on port $mitmPort"; + } + + if ($Config{osname} eq "linux") + { + system("netstat --tcp -n | grep $mitmPort"); + } + else + { + system("netstat -p tcp -n | grep $mitmPort"); + } + my $childPid = fork(); die("Failed to fork\n") @@ -571,16 +602,13 @@ if ($useMitmproxy) $mitmPid = $childPid; if ($mitmPid eq 0) { + print("forked, about to exec mitmdump\n"); setpgrp(0,0); # we're about to spawn both a shell and a mitmdump, kill them as a group - exec("mitmdump --rawtcp -p 57640 --mode reverse:localhost:57638 -s mitmscripts/fluent.py --set fifo=$mitmFifoPath --set flow_detail=0 --set termlog_verbosity=warn >proxy.output 2>&1"); + exec("mitmdump --rawtcp -p $mitmPort --mode reverse:localhost:57638 -s $regressdir/mitmscripts/fluent.py --set fifo=$mitmFifoPath --set flow_detail=0 --set termlog_verbosity=warn >proxy.output 2>&1"); die 'could not start mitmdump'; } } -$SIG{CHLD} = sub { - while ((my $waitpid = waitpid(-1, WNOHANG)) > 0) {} -}; # If, for some reason, mitmproxy dies before we do - # Set signals to shutdown servers $SIG{INT} = \&ShutdownServers; $SIG{QUIT} = \&ShutdownServers; diff --git a/src/test/regress/sql/failure_setup.sql b/src/test/regress/sql/failure_setup.sql index 695c47c3c..4c209f14d 100644 --- a/src/test/regress/sql/failure_setup.sql +++ b/src/test/regress/sql/failure_setup.sql @@ -1,5 +1,5 @@ SELECT citus.mitmproxy('conn.allow()'); -- add the workers -SELECT master_add_node('localhost', :worker_1_port); -- the second worker -SELECT master_add_node('localhost', :worker_2_port + 2); -- the first worker, behind a mitmproxy +SELECT master_add_node('localhost', :worker_1_port); +SELECT master_add_node('localhost', :worker_2_proxy_port); -- an mitmproxy which forwards to the second worker