From 3e109b13bcbf7fe415d13902bb6d5433696914ac Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Emmanuel=20Beno=C3=AEt?= Date: Sat, 7 Jan 2012 11:14:17 +0100 Subject: [PATCH] SQL logging fixes * Added user mapping on the "remote" logging database for the administrative user. This allows calls to sys.write_sql_log() to succeed when they are executed by code with administrative privileges. * Added test suites for both the link to the database and the function itself. * Replaced RAISE NOTICE with actual logging in the universe generator --- .../db-structure/parts/020-extensions.sql | 7 ++++ .../parts/040-functions/005-logs.sql | 39 ++++++++++-------- .../040-functions/055-generator-resources.sql | 19 +++++---- .../tests/admin/020-extensions/010-dblink.sql | 40 +++++++++++++++++++ .../005-logs/010-write-sql-log.sql | 32 +++++++++++++++ .../tests/user/020-extensions/010-dblink.sql | 23 +++++++++++ .../user/030-data/150-logs/010-sys-logs.sql | 29 ++++++++++++++ .../005-logs/010-write-sql-log.sql | 13 ++++++ .../db-structure/tests/user/priv/sys/logs.sql | 39 ------------------ 9 files changed, 177 insertions(+), 64 deletions(-) create mode 100644 legacyworlds-server-data/db-structure/tests/admin/020-extensions/010-dblink.sql create mode 100644 legacyworlds-server-data/db-structure/tests/admin/040-functions/005-logs/010-write-sql-log.sql create mode 100644 legacyworlds-server-data/db-structure/tests/user/020-extensions/010-dblink.sql create mode 100644 legacyworlds-server-data/db-structure/tests/user/030-data/150-logs/010-sys-logs.sql create mode 100644 legacyworlds-server-data/db-structure/tests/user/040-functions/005-logs/010-write-sql-log.sql delete mode 100644 legacyworlds-server-data/db-structure/tests/user/priv/sys/logs.sql diff --git a/legacyworlds-server-data/db-structure/parts/020-extensions.sql b/legacyworlds-server-data/db-structure/parts/020-extensions.sql index 0889c1d..9adc475 100644 --- a/legacyworlds-server-data/db-structure/parts/020-extensions.sql +++ b/legacyworlds-server-data/db-structure/parts/020-extensions.sql @@ -14,10 +14,17 @@ CREATE EXTENSION dblink; */ CREATE FOREIGN DATA WRAPPER pgsql VALIDATOR postgresql_fdw_validator; + CREATE SERVER srv_logging FOREIGN DATA WRAPPER pgsql OPTIONS ( hostaddr '127.0.0.1' , dbname :dbname_string ); + +CREATE USER MAPPING FOR :pgadmin + SERVER srv_logging + OPTIONS ( user :dbuser_string , password :dbupass ); + CREATE USER MAPPING FOR :dbuser SERVER srv_logging OPTIONS ( user :dbuser_string , password :dbupass ); + GRANT USAGE ON FOREIGN SERVER srv_logging TO :dbuser; diff --git a/legacyworlds-server-data/db-structure/parts/040-functions/005-logs.sql b/legacyworlds-server-data/db-structure/parts/040-functions/005-logs.sql index 65bd5b7..0579cda 100644 --- a/legacyworlds-server-data/db-structure/parts/040-functions/005-logs.sql +++ b/legacyworlds-server-data/db-structure/parts/040-functions/005-logs.sql @@ -124,21 +124,21 @@ $$ LANGUAGE plpgsql; GRANT EXECUTE ON FUNCTION sys.write_log( TEXT , log_level , TEXT ) TO :dbuser; --- --- Remotely append a system log entry --- --- This function is called from within transactions in order to write to the --- system log. Unlike sys.write_log(), entries added through this function --- will not be lost if the transaction is rolled back. --- --- Since the function is meant to be called from SQL code, it does not return --- anything as the identifier of the new entry is not required. --- --- Parameters: --- _component The component that is appending to the log --- _level The log level --- _message The message to write --- +/* + * Remotely append a system log entry + * + * This function is called from within transactions in order to write to the + * system log. Unlike sys.write_log(), entries added through this function + * will not be lost if the transaction is rolled back. + * + * Since the function is meant to be called from SQL code, it does not return + * anything as the identifier of the new entry is not required. + * + * Parameters: + * _component The component that is appending to the log + * _level The log level + * _message The message to write + */ CREATE OR REPLACE FUNCTION sys.write_sql_log( _component TEXT , _level log_level , _message TEXT ) RETURNS VOID @@ -146,14 +146,19 @@ CREATE OR REPLACE FUNCTION sys.write_sql_log( _component TEXT , _level log_level SECURITY INVOKER AS $write_sql_log$ BEGIN - PERFORM dblink_connect( 'cn_logging' , 'srv_logging' ); + BEGIN + PERFORM dblink_connect( 'cn_logging' , 'srv_logging' ); + EXCEPTION + WHEN duplicate_object THEN + -- Ignore the error, assume we're connected + END; + PERFORM * FROM dblink( 'cn_logging' , 'SELECT * FROM sys.write_log( ' || quote_literal( _component ) || ' , ''' || _level::text || '''::log_level , ' || quote_literal( _message ) || ' )' ) AS ( entry_id bigint ); - PERFORM dblink_disconnect( 'cn_logging' ); END; $write_sql_log$ LANGUAGE plpgsql; diff --git a/legacyworlds-server-data/db-structure/parts/040-functions/055-generator-resources.sql b/legacyworlds-server-data/db-structure/parts/040-functions/055-generator-resources.sql index a2418ac..2e0e0fe 100644 --- a/legacyworlds-server-data/db-structure/parts/040-functions/055-generator-resources.sql +++ b/legacyworlds-server-data/db-structure/parts/040-functions/055-generator-resources.sql @@ -250,9 +250,10 @@ BEGIN _recovery := verse.get_random_part( _tot_recovery , _providers_left , _data.recovery_avg , _data.recovery_dev ); - RAISE NOTICE 'Resource #% planet #%: quantity: % difficulty: % recovery: %', - _data.resource_name_id , _planet , - _quantity , _difficulty , _recovery; + PERFORM sys.write_sql_log( 'UniverseGenerator' , 'TRACE'::log_level , + 'Resource #' || _data.resource_name_id || ', planet #' || _planet + || ': quantity ' || _quantity || ' , difficulty ' + || _difficulty || ' , recovery ' || _recovery ); INSERT INTO verse.resource_providers ( planet_id , resource_name_id , resprov_quantity_max , @@ -326,11 +327,13 @@ BEGIN _tot_recovery := verse.compute_rpp_delta( _data.providers , _create , _data.recovery , _data.recovery_avg , _data.recovery_dev ); - RAISE NOTICE 'Resource #%: % new provider(s), quantity: % (avg. %) , difficulty: % (avg. %), recovery: % (avg. %)', - _data.resource_name_id , _create , - _tot_quantity , _tot_quantity / _create , - _tot_difficulty , _tot_difficulty / _create , - _tot_recovery , _tot_recovery / _create; + PERFORM sys.write_sql_log( 'UniverseGenerator' , 'TRACE'::log_level , + 'Resource #' || _data.resource_name_id || ': ' || _create + || ' new provider(s), quantity: ' || _tot_quantity || ' (avg. ' + || ( _tot_quantity / _create ) || ') , difficulty: ' + || _tot_difficulty || ' (avg. ' || ( _tot_difficulty / _create ) + || '), recovery: ' || _tot_recovery || ' (avg. ' + || _tot_recovery / _create || ')' ); -- Select random planets to add resource providers to FOR _planet IN SELECT * FROM verse.list_random_planets_in( _area , _create ) diff --git a/legacyworlds-server-data/db-structure/tests/admin/020-extensions/010-dblink.sql b/legacyworlds-server-data/db-structure/tests/admin/020-extensions/010-dblink.sql new file mode 100644 index 0000000..24f8267 --- /dev/null +++ b/legacyworlds-server-data/db-structure/tests/admin/020-extensions/010-dblink.sql @@ -0,0 +1,40 @@ +/* + * Test the presence and configuration of the dblink + * extension + */ +BEGIN; + SELECT plan( 6 ); + + SELECT diag_test_name( 'dblink - dblink_connect() exists' ); + SELECT has_function( 'dblink_connect' ); + + SELECT diag_test_name( 'dblink - Foreign data wrapper defined' ); + SELECT is( p.proname , 'postgresql_fdw_validator' ) + FROM pg_foreign_data_wrapper w + INNER JOIN pg_proc p ON w.fdwvalidator = p.oid + WHERE w.fdwname = 'pgsql'; + + SELECT diag_test_name( 'dblink - Foreign server defined' ); + SELECT is ( w.fdwname , 'pgsql' ) + FROM pg_foreign_server s + INNER JOIN pg_foreign_data_wrapper w + ON s.srvfdw = w.oid + WHERE s.srvname = 'srv_logging'; + + SELECT diag_test_name( 'dblink - Connection' ); + SELECT lives_ok( + $$ SELECT dblink_connect( 'cn_logging' , 'srv_logging' ) $$ + ); + + SELECT diag_test_name( 'dblink - Remote user is not the administrator' ); + SELECT isnt( username , current_user::TEXT ) + FROM dblink( 'cn_logging' , 'SELECT current_user' ) + AS ( username TEXT ); + + SELECT diag_test_name( 'dblink - Disconnection' ); + SELECT lives_ok( + $$ SELECT dblink_disconnect( 'cn_logging' ) $$ + ); + + SELECT * FROM finish( ); +ROLLBACK; \ No newline at end of file diff --git a/legacyworlds-server-data/db-structure/tests/admin/040-functions/005-logs/010-write-sql-log.sql b/legacyworlds-server-data/db-structure/tests/admin/040-functions/005-logs/010-write-sql-log.sql new file mode 100644 index 0000000..e8bef15 --- /dev/null +++ b/legacyworlds-server-data/db-structure/tests/admin/040-functions/005-logs/010-write-sql-log.sql @@ -0,0 +1,32 @@ +/* + * Test the sys.write_sql_log( ) function + */ +BEGIN; + DELETE FROM sys.logs; + SELECT plan( 4 ); + + SELECT diag_test_name( 'sys.write_sql_log( ) - Initial call' ); + SELECT lives_ok( + $$ SELECT sys.write_sql_log( 'test' , 'WARNING'::log_level , 'test' ) $$ + ); + SELECT diag_test_name( 'sys.write_sql_log( ) - Contents of system log after call' ); + SELECT is( COUNT(*)::INT , 1 ) FROM sys.logs; + DELETE FROM sys.logs; + + SELECT diag_test_name( 'sys.write_sql_log( ) - Two calls in sequence' ); + SELECT lives_ok( + $$ SELECT sys.write_sql_log( 'test' , 'WARNING'::log_level , 'test' ); + SELECT sys.write_sql_log( 'test' , 'WARNING'::log_level , 'test' ) $$ + ); + DELETE FROM sys.logs; + + SELECT diag_test_name( 'sys.write_sql_log( ) - Calling and rolling back' ); + SAVEPOINT before_log; + SELECT sys.write_sql_log( 'test' , 'WARNING'::log_level , 'test' ); + SELECT sys.write_log( 'test' , 'WARNING'::log_level , 'test' ); + ROLLBACK TO SAVEPOINT before_log; + SELECT is( COUNT(*)::INT , 1 ) FROM sys.logs; + DELETE FROM sys.logs; + + SELECT * FROM finish( ); +ROLLBACK; \ No newline at end of file diff --git a/legacyworlds-server-data/db-structure/tests/user/020-extensions/010-dblink.sql b/legacyworlds-server-data/db-structure/tests/user/020-extensions/010-dblink.sql new file mode 100644 index 0000000..271e969 --- /dev/null +++ b/legacyworlds-server-data/db-structure/tests/user/020-extensions/010-dblink.sql @@ -0,0 +1,23 @@ +/* + * Test the configuration of the dblink extension from the user's perspective + */ +BEGIN; + SELECT plan( 3 ); + + SELECT diag_test_name( 'dblink - Connection' ); + SELECT lives_ok( + $$ SELECT dblink_connect( 'cn_logging' , 'srv_logging' ) $$ + ); + + SELECT diag_test_name( 'dblink - Remote user = local user' ); + SELECT is( username , current_user::TEXT ) + FROM dblink( 'cn_logging' , 'SELECT current_user' ) + AS ( username TEXT ); + + SELECT diag_test_name( 'dblink - Disconnection' ); + SELECT lives_ok( + $$ SELECT dblink_disconnect( 'cn_logging' ) $$ + ); + + SELECT * FROM finish( ); +ROLLBACK; \ No newline at end of file diff --git a/legacyworlds-server-data/db-structure/tests/user/030-data/150-logs/010-sys-logs.sql b/legacyworlds-server-data/db-structure/tests/user/030-data/150-logs/010-sys-logs.sql new file mode 100644 index 0000000..78a8f77 --- /dev/null +++ b/legacyworlds-server-data/db-structure/tests/user/030-data/150-logs/010-sys-logs.sql @@ -0,0 +1,29 @@ +/* + * Test privileges on sys.logs + */ +BEGIN; + SELECT plan( 4 ); + + SELECT diag_test_name( 'sys.logs - INSERT privileges' ); + SELECT throws_ok( + $$ INSERT INTO sys.logs( component , level , message ) + VALUES ( 'test' , 'WARNING'::log_level , 'test' ); + $$ , 42501 ); + + SELECT diag_test_name( 'sys.logs - UPDATE privileges' ); + SELECT throws_ok( + $$ UPDATE sys.logs SET component = 'retest'; $$ , + 42501 ); + + SELECT diag_test_name( 'sys.logs - SELECT privileges' ); + SELECT lives_ok( + $$ SELECT * FROM sys.logs; $$ + ); + + SELECT diag_test_name( 'sys.logs - DELETE privileges' ); + SELECT throws_ok( + $$ DELETE FROM sys.logs; $$ , + 42501 ); + + SELECT * FROM finish( ); +ROLLBACK; \ No newline at end of file diff --git a/legacyworlds-server-data/db-structure/tests/user/040-functions/005-logs/010-write-sql-log.sql b/legacyworlds-server-data/db-structure/tests/user/040-functions/005-logs/010-write-sql-log.sql new file mode 100644 index 0000000..3996f8a --- /dev/null +++ b/legacyworlds-server-data/db-structure/tests/user/040-functions/005-logs/010-write-sql-log.sql @@ -0,0 +1,13 @@ +/* + * Test the sys.write_sql_log( ) function + */ +BEGIN; + SELECT plan( 1 ); + + SELECT diag_test_name( 'sys.write_sql_log( ) - Privileges' ); + SELECT lives_ok( + $$ SELECT sys.write_sql_log( 'test' , 'WARNING'::log_level , 'test' ) $$ + ); + + SELECT * FROM finish( ); +ROLLBACK; \ No newline at end of file diff --git a/legacyworlds-server-data/db-structure/tests/user/priv/sys/logs.sql b/legacyworlds-server-data/db-structure/tests/user/priv/sys/logs.sql deleted file mode 100644 index e7c7948..0000000 --- a/legacyworlds-server-data/db-structure/tests/user/priv/sys/logs.sql +++ /dev/null @@ -1,39 +0,0 @@ -BEGIN; - SELECT plan( 3 ); - - -- - -- Insertion through sys.write_log() - -- - CREATE OR REPLACE FUNCTION _test_this( ) - RETURNS BIGINT - AS $$ - SELECT sys.write_log( 'test' , 'WARNING'::log_level , 'test' ); - $$ LANGUAGE SQL; - SELECT lives_ok( 'SELECT _test_this()' ); - DROP FUNCTION _test_this( ); - - -- - -- Direct insertion must fail - -- - CREATE FUNCTION _test_this( ) - RETURNS VOID - AS $$ - INSERT INTO sys.logs( component , level , message ) - VALUES ( 'test' , 'WARNING'::log_level , 'test' ); - $$ LANGUAGE SQL; - SELECT throws_ok( 'SELECT _test_this()' , 42501 ); - DROP FUNCTION _test_this( ); - - -- - -- Updates must fail - -- - CREATE OR REPLACE FUNCTION _test_this( ) - RETURNS VOID - AS $$ - UPDATE sys.logs SET component = 'random' WHERE component = 'test'; - $$ LANGUAGE SQL; - SELECT throws_ok( 'SELECT _test_this()' , 42501 ); - DROP FUNCTION _test_this( ); - - SELECT * FROM finish( ); -ROLLBACK;