Add job exit status and runtime to log

When a job finishes execution, either because of an error or a success,
this commit will print out the execution time of the job in the log
together with a message about what job that finished.

For continuous aggregate refreshes, the number of rows deleted from and
inserted into the materialization table will be printed.
This commit is contained in:
Mats Kindahl 2023-07-13 14:32:55 +02:00 committed by Mats Kindahl
parent 36e7100013
commit 906bd38573
13 changed files with 333 additions and 204 deletions

1
.unreleased/feature_5875 Normal file
View File

@ -0,0 +1 @@
Implements: #5875 Add job exit status and runtime to log

View File

@ -25,6 +25,7 @@
#include <utils/acl.h>
#include <utils/elog.h>
#include <executor/execdebug.h>
#include <executor/instrument.h>
#include <utils/jsonb.h>
#include <utils/snapmgr.h>
#include <unistd.h>
@ -1175,6 +1176,8 @@ ts_bgw_job_entrypoint(PG_FUNCTION_ARGS)
BgwJob *job;
JobResult res = JOB_FAILURE;
bool got_lock;
instr_time start;
instr_time duration;
memcpy(&params, MyBgworkerEntry->bgw_extra, sizeof(BgwParams));
Ensure(params.user_oid != 0 && params.job_id != 0,
@ -1196,6 +1199,8 @@ ts_bgw_job_entrypoint(PG_FUNCTION_ARGS)
ts_license_enable_module_loading();
INSTR_TIME_SET_CURRENT(start);
StartTransactionCommand();
/* Grab a session lock on the job row to prevent concurrent deletes. Lock is released
* when the job process exits */
@ -1316,17 +1321,22 @@ ts_bgw_job_entrypoint(PG_FUNCTION_ARGS)
CommitTransactionCommand();
INSTR_TIME_SET_CURRENT(duration);
INSTR_TIME_SUBTRACT(duration, start);
elog(LOG,
"job %d (%s) exiting with %s: execution time %.2f ms",
params.job_id,
NameStr(job->fd.application_name),
(res == JOB_SUCCESS ? "success" : "failure"),
INSTR_TIME_GET_MILLISEC(duration));
if (job != NULL)
{
pfree(job);
job = NULL;
}
elog(DEBUG1,
"exiting job %d with %s",
params.job_id,
(res == JOB_SUCCESS ? "success" : "failure"));
PG_RETURN_VOID();
}

View File

@ -271,7 +271,16 @@ spi_delete_materializations(SchemaAndName materialization_table, const NameData
res = SPI_execute(command->data, false /* read_only */, 0 /*count*/);
if (res < 0)
elog(ERROR, "could not delete old values from materialization table");
elog(ERROR,
"could not delete old values from materialization table \"%s.%s\"",
NameStr(*materialization_table.schema),
NameStr(*materialization_table.name));
else
elog(LOG,
"deleted " UINT64_FORMAT " row(s) from materialization table \"%s.%s\"",
SPI_processed,
NameStr(*materialization_table.schema),
NameStr(*materialization_table.name));
}
static void
@ -306,7 +315,16 @@ spi_insert_materializations(Hypertable *mat_ht, SchemaAndName partial_view,
res = SPI_execute(command->data, false /* read_only */, 0 /*count*/);
if (res < 0)
elog(ERROR, "could not materialize values into the materialization table");
elog(ERROR,
"could not materialize values into the materialization table \"%s.%s\"",
NameStr(*materialization_table.schema),
NameStr(*materialization_table.name));
else
elog(LOG,
"inserted " UINT64_FORMAT " row(s) into materialization table \"%s.%s\"",
SPI_processed,
NameStr(*materialization_table.schema),
NameStr(*materialization_table.name));
/* Get the max(time_dimension) of the materialized data */
if (SPI_processed > 0)

View File

@ -96,7 +96,10 @@ CREATE TABLE public.bgw_log(
msg TEXT
);
CREATE VIEW sorted_bgw_log AS
SELECT msg_no, application_name, regexp_replace(regexp_replace(msg, 'Wait until [0-9]+, started at [0-9]+', 'Wait until (RANDOM), started at (RANDOM)'), 'background worker "[^"]+"','connection') AS msg FROM bgw_log ORDER BY mock_time, application_name COLLATE "C", msg_no;
SELECT msg_no,
application_name,
regexp_replace(regexp_replace(msg, '(Wait until|started at|execution time) [0-9]+(\.[0-9]+)?', '\1 (RANDOM)', 'g'), 'background worker "[^"]+"','connection') AS msg
FROM bgw_log ORDER BY mock_time, application_name COLLATE "C", msg_no;
CREATE TABLE public.bgw_dsm_handle_store(
handle BIGINT
);
@ -202,13 +205,14 @@ SELECT * FROM timescaledb_information.job_stats;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+-------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | unscheduled | Execute job 1
(4 rows)
1 | unscheduled | job 1000 (unscheduled) exiting with success: execution time (RANDOM) ms
(5 rows)
SELECT delete_job(1000);
delete_job
@ -312,12 +316,13 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_1 | Execute job 1
(3 rows)
1 | test_job_1 | job 1000 (test_job_1) exiting with success: execution time (RANDOM) ms
(4 rows)
--Test that the scheduler will not run job again if not enough time has passed
SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(25, 25);
@ -334,13 +339,14 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_1 | Execute job 1
1 | test_job_1 | job 1000 (test_job_1) exiting with success: execution time (RANDOM) ms
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
(4 rows)
(5 rows)
--After enough time has passed the scheduler will run the job again
SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(100, 50);
@ -357,17 +363,19 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_1 | Execute job 1
1 | test_job_1 | job 1000 (test_job_1) exiting with success: execution time (RANDOM) ms
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
1 | DB Scheduler | [TESTING] Registered new background worker
2 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_1 | Execute job 1
(8 rows)
1 | test_job_1 | job 1000 (test_job_1) exiting with success: execution time (RANDOM) ms
(10 rows)
--Now it runs it one more time
SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(120, 100);
@ -384,21 +392,24 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_1 | Execute job 1
1 | test_job_1 | job 1000 (test_job_1) exiting with success: execution time (RANDOM) ms
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
1 | DB Scheduler | [TESTING] Registered new background worker
2 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_1 | Execute job 1
1 | test_job_1 | job 1000 (test_job_1) exiting with success: execution time (RANDOM) ms
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
1 | DB Scheduler | [TESTING] Registered new background worker
2 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_1 | Execute job 1
(12 rows)
1 | test_job_1 | job 1000 (test_job_1) exiting with success: execution time (RANDOM) ms
(15 rows)
--
-- Test what happens when running a job that throws an error
@ -718,13 +729,14 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+-----------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_3_long | Before sleep job 3
1 | test_job_3_long | After sleep job 3
(4 rows)
2 | test_job_3_long | job 1003 (test_job_3_long) exiting with success: execution time (RANDOM) ms
(5 rows)
SELECT ts_bgw_params_mock_wait_returns_immediately(:WAIT_ON_JOB);
ts_bgw_params_mock_wait_returns_immediately
@ -805,8 +817,8 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+-----------------------------------------------------
msg_no | application_name | msg
--------+------------------+-----------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_3_long | Before sleep job 3
@ -817,7 +829,8 @@ SELECT * FROM sorted_bgw_log;
2 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_3_long | Before sleep job 3
1 | test_job_3_long | After sleep job 3
(10 rows)
2 | test_job_3_long | job 1004 (test_job_3_long) exiting with success: execution time (RANDOM) ms
(11 rows)
--Test sending a SIGHUP to a job
\c :TEST_DBNAME :ROLE_SUPERUSER
@ -982,8 +995,8 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+-----------------------------------------------------
msg_no | application_name | msg
--------+------------------+-----------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
@ -995,7 +1008,8 @@ SELECT * FROM sorted_bgw_log;
2 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_3_long | Before sleep job 3
1 | test_job_3_long | After sleep job 3
(11 rows)
2 | test_job_3_long | job 1005 (test_job_3_long) exiting with success: execution time (RANDOM) ms
(12 rows)
CREATE FUNCTION wait_for_timer_to_run(started_at INTEGER, spins INTEGER=:TEST_SPINWAIT_ITERS) RETURNS BOOLEAN LANGUAGE PLPGSQL AS
$BODY$
@ -1191,12 +1205,13 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_4 | Execute job 4
(3 rows)
1 | test_job_4 | job 1012 (test_job_4) exiting with success: execution time (RANDOM) ms
(4 rows)
-- Now just make sure that the job actually runs in 200ms
SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(200);
@ -1215,16 +1230,18 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_4 | Execute job 4
1 | test_job_4 | job 1012 (test_job_4) exiting with success: execution time (RANDOM) ms
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
1 | DB Scheduler | [TESTING] Registered new background worker
2 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_4 | Execute job 4
(7 rows)
1 | test_job_4 | job 1012 (test_job_4) exiting with success: execution time (RANDOM) ms
(9 rows)
-- Test updating jobs list
TRUNCATE bgw_log;
@ -1572,25 +1589,29 @@ SELECT ts_bgw_params_reset_time(500000, true);
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+---------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
1 | DB Scheduler | [TESTING] Registered new background worker
2 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | another | Execute job 1
1 | another | job 1024 (another) exiting with success: execution time (RANDOM) ms
3 | DB Scheduler | [TESTING] Registered new background worker
4 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | another | Execute job 1
1 | another | job 1024 (another) exiting with success: execution time (RANDOM) ms
5 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
6 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
7 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
8 | DB Scheduler | [TESTING] Registered new background worker
9 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | new_job | Execute job 1
1 | new_job | job 1025 (new_job) exiting with success: execution time (RANDOM) ms
10 | DB Scheduler | [TESTING] Registered new background worker
11 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | new_job | Execute job 1
(16 rows)
1 | new_job | job 1025 (new_job) exiting with success: execution time (RANDOM) ms
(20 rows)
\x on
SELECT * FROM _timescaledb_internal.bgw_job_stat;

View File

@ -100,9 +100,10 @@ CREATE TABLE public.bgw_log(
msg TEXT
);
CREATE VIEW sorted_bgw_log AS
SELECT msg_no, application_name,
regexp_replace(regexp_replace(msg, 'Wait until [0-9]+, started at [0-9]+', 'Wait until (RANDOM), started at (RANDOM)'), 'background worker "[^"]+"','connection')
AS msg FROM bgw_log ORDER BY mock_time, application_name COLLATE "C", msg_no;
SELECT msg_no,
application_name,
regexp_replace(regexp_replace(msg, '(Wait until|started at|execution time) [0-9]+(\.[0-9]+)?', '\1 (RANDOM)', 'g'), 'background worker "[^"]+"','connection') AS msg
FROM bgw_log ORDER BY mock_time, application_name COLLATE "C", msg_no;
CREATE TABLE public.bgw_dsm_handle_store(
handle BIGINT
);
@ -195,13 +196,14 @@ SELECT * FROM timescaledb_information.job_stats;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+-------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | unscheduled | Execute job 1
(4 rows)
1 | unscheduled | job 1000 (unscheduled) exiting with success: execution time (RANDOM) ms
(5 rows)
SELECT delete_job(1000);
delete_job
@ -311,12 +313,13 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_1 | Execute job 1
(3 rows)
1 | test_job_1 | job 1000 (test_job_1) exiting with success: execution time (RANDOM) ms
(4 rows)
--Test that the scheduler will not run job again if not enough time has passed
SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(25, 25);
@ -333,13 +336,14 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_1 | Execute job 1
1 | test_job_1 | job 1000 (test_job_1) exiting with success: execution time (RANDOM) ms
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
(4 rows)
(5 rows)
--After enough time has passed the scheduler will run the job again
SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(100, 50);
@ -356,17 +360,19 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_1 | Execute job 1
1 | test_job_1 | job 1000 (test_job_1) exiting with success: execution time (RANDOM) ms
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
1 | DB Scheduler | [TESTING] Registered new background worker
2 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_1 | Execute job 1
(8 rows)
1 | test_job_1 | job 1000 (test_job_1) exiting with success: execution time (RANDOM) ms
(10 rows)
--Now it runs it one more time
SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(120, 100);
@ -383,21 +389,24 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_1 | Execute job 1
1 | test_job_1 | job 1000 (test_job_1) exiting with success: execution time (RANDOM) ms
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
1 | DB Scheduler | [TESTING] Registered new background worker
2 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_1 | Execute job 1
1 | test_job_1 | job 1000 (test_job_1) exiting with success: execution time (RANDOM) ms
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
1 | DB Scheduler | [TESTING] Registered new background worker
2 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_1 | Execute job 1
(12 rows)
1 | test_job_1 | job 1000 (test_job_1) exiting with success: execution time (RANDOM) ms
(15 rows)
--
-- Test what happens when running a job that throws an error
@ -718,13 +727,14 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+-----------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_3_long | Before sleep job 3
1 | test_job_3_long | After sleep job 3
(4 rows)
2 | test_job_3_long | job 1003 (test_job_3_long) exiting with success: execution time (RANDOM) ms
(5 rows)
SELECT ts_bgw_params_mock_wait_returns_immediately(:WAIT_ON_JOB);
ts_bgw_params_mock_wait_returns_immediately
@ -805,8 +815,8 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+-----------------------------------------------------
msg_no | application_name | msg
--------+------------------+-----------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_3_long | Before sleep job 3
@ -817,7 +827,8 @@ SELECT * FROM sorted_bgw_log;
2 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_3_long | Before sleep job 3
1 | test_job_3_long | After sleep job 3
(10 rows)
2 | test_job_3_long | job 1004 (test_job_3_long) exiting with success: execution time (RANDOM) ms
(11 rows)
--Test sending a SIGHUP to a job
\c :TEST_DBNAME :ROLE_SUPERUSER
@ -982,8 +993,8 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+-----------------------------------------------------
msg_no | application_name | msg
--------+------------------+-----------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
@ -995,7 +1006,8 @@ SELECT * FROM sorted_bgw_log;
2 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_3_long | Before sleep job 3
1 | test_job_3_long | After sleep job 3
(11 rows)
2 | test_job_3_long | job 1005 (test_job_3_long) exiting with success: execution time (RANDOM) ms
(12 rows)
CREATE FUNCTION wait_for_timer_to_run(started_at INTEGER, spins INTEGER=:TEST_SPINWAIT_ITERS) RETURNS BOOLEAN LANGUAGE PLPGSQL AS
$BODY$
@ -1191,12 +1203,13 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_4 | Execute job 4
(3 rows)
1 | test_job_4 | job 1012 (test_job_4) exiting with success: execution time (RANDOM) ms
(4 rows)
-- Now just make sure that the job actually runs in 200ms
SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(200);
@ -1215,16 +1228,18 @@ FROM _timescaledb_internal.bgw_job_stat;
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+------------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Registered new background worker
1 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_4 | Execute job 4
1 | test_job_4 | job 1012 (test_job_4) exiting with success: execution time (RANDOM) ms
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
1 | DB Scheduler | [TESTING] Registered new background worker
2 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | test_job_4 | Execute job 4
(7 rows)
1 | test_job_4 | job 1012 (test_job_4) exiting with success: execution time (RANDOM) ms
(9 rows)
-- Test updating jobs list
TRUNCATE bgw_log;
@ -1558,25 +1573,29 @@ SELECT ts_bgw_params_reset_time(500000, true);
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | application_name | msg
--------+------------------+----------------------------------------------------
msg_no | application_name | msg
--------+------------------+---------------------------------------------------------------------
0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
1 | DB Scheduler | [TESTING] Registered new background worker
2 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | another | Execute job 1
1 | another | job 1024 (another) exiting with success: execution time (RANDOM) ms
3 | DB Scheduler | [TESTING] Registered new background worker
4 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | another | Execute job 1
1 | another | job 1024 (another) exiting with success: execution time (RANDOM) ms
5 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
6 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
7 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
8 | DB Scheduler | [TESTING] Registered new background worker
9 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | new_job | Execute job 1
1 | new_job | job 1025 (new_job) exiting with success: execution time (RANDOM) ms
10 | DB Scheduler | [TESTING] Registered new background worker
11 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | new_job | Execute job 1
(16 rows)
1 | new_job | job 1025 (new_job) exiting with success: execution time (RANDOM) ms
(20 rows)
SELECT * FROM _timescaledb_internal.bgw_job_stat;
job_id | last_start | last_finish | next_start | last_successful_finish | last_run_success | total_runs | total_duration | total_duration_failures | total_successes | total_failures | total_crashes | consecutive_failures | consecutive_crashes | flags

View File

@ -34,11 +34,8 @@ CREATE VIEW sorted_bgw_log AS
SELECT msg_no,
mock_time,
application_name,
CASE WHEN length(msg) > 80 THEN
substring(msg, 1, 80) || '...'
ELSE
msg
END AS msg
regexp_replace(CASE WHEN length(msg) > 80 THEN substring(msg, 1, 80) || '...' ELSE msg END,
'(execution time) [0-9]+(\.[0-9]+)?', '\1 (RANDOM)', 'g') AS msg
FROM bgw_log
ORDER BY mock_time,
application_name COLLATE "C",
@ -131,11 +128,12 @@ SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(25);
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-----------+------------------+--------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
(2 rows)
msg_no | mock_time | application_name | msg
--------+-----------+-----------------------+-----------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
0 | 0 | Reorder Policy [1000] | job 1000 (Reorder Policy [1000]) exiting with success: execution time (RANDOM) ms
(3 rows)
SELECT * FROM timescaledb_information.jobs WHERE job_id=:reorder_job_id;
job_id | application_name | schedule_interval | max_runtime | max_retries | retry_period | proc_schema | proc_name | owner | scheduled | fixed_schedule | config | next_start | initial_start | hypertable_schema | hypertable_name | check_schema | check_name
@ -169,13 +167,15 @@ SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(25);
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-----------+------------------+----------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
0 | 25000 | DB Scheduler | [TESTING] Registered new background worker
1 | 25000 | DB Scheduler | [TESTING] Wait until 50000, started at 25000
(4 rows)
msg_no | mock_time | application_name | msg
--------+-----------+-----------------------+-----------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
0 | 0 | Reorder Policy [1000] | job 1000 (Reorder Policy [1000]) exiting with success: execution time (RANDOM) ms
0 | 25000 | DB Scheduler | [TESTING] Registered new background worker
1 | 25000 | DB Scheduler | [TESTING] Wait until 50000, started at 25000
0 | 25000 | Reorder Policy [1000] | job 1000 (Reorder Policy [1000]) exiting with success: execution time (RANDOM) ms
(6 rows)
SELECT * FROM timescaledb_information.jobs WHERE job_id=:reorder_job_id;
job_id | application_name | schedule_interval | max_runtime | max_retries | retry_period | proc_schema | proc_name | owner | scheduled | fixed_schedule | config | next_start | initial_start | hypertable_schema | hypertable_name | check_schema | check_name
@ -211,15 +211,18 @@ SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(50);
-- job info is gone
SELECT * FROM sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-----------+------------------+-----------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
0 | 25000 | DB Scheduler | [TESTING] Registered new background worker
1 | 25000 | DB Scheduler | [TESTING] Wait until 50000, started at 25000
0 | 50000 | DB Scheduler | [TESTING] Registered new background worker
1 | 50000 | DB Scheduler | [TESTING] Wait until 100000, started at 50000
(6 rows)
msg_no | mock_time | application_name | msg
--------+-----------+-----------------------+-----------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
0 | 0 | Reorder Policy [1000] | job 1000 (Reorder Policy [1000]) exiting with success: execution time (RANDOM) ms
0 | 25000 | DB Scheduler | [TESTING] Registered new background worker
1 | 25000 | DB Scheduler | [TESTING] Wait until 50000, started at 25000
0 | 25000 | Reorder Policy [1000] | job 1000 (Reorder Policy [1000]) exiting with success: execution time (RANDOM) ms
0 | 50000 | DB Scheduler | [TESTING] Registered new background worker
1 | 50000 | DB Scheduler | [TESTING] Wait until 100000, started at 50000
0 | 50000 | Reorder Policy [1000] | job 1000 (Reorder Policy [1000]) exiting with success: execution time (RANDOM) ms
(9 rows)
SELECT * FROM timescaledb_information.jobs WHERE job_id=:reorder_job_id;
job_id | application_name | schedule_interval | max_runtime | max_retries | retry_period | proc_schema | proc_name | owner | scheduled | fixed_schedule | config | next_start | initial_start | hypertable_schema | hypertable_name | check_schema | check_name
@ -254,16 +257,19 @@ SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(100);
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-----------+------------------+------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
0 | 25000 | DB Scheduler | [TESTING] Registered new background worker
1 | 25000 | DB Scheduler | [TESTING] Wait until 50000, started at 25000
0 | 50000 | DB Scheduler | [TESTING] Registered new background worker
1 | 50000 | DB Scheduler | [TESTING] Wait until 100000, started at 50000
0 | 100000 | DB Scheduler | [TESTING] Wait until 200000, started at 100000
(7 rows)
msg_no | mock_time | application_name | msg
--------+-----------+-----------------------+-----------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
0 | 0 | Reorder Policy [1000] | job 1000 (Reorder Policy [1000]) exiting with success: execution time (RANDOM) ms
0 | 25000 | DB Scheduler | [TESTING] Registered new background worker
1 | 25000 | DB Scheduler | [TESTING] Wait until 50000, started at 25000
0 | 25000 | Reorder Policy [1000] | job 1000 (Reorder Policy [1000]) exiting with success: execution time (RANDOM) ms
0 | 50000 | DB Scheduler | [TESTING] Registered new background worker
1 | 50000 | DB Scheduler | [TESTING] Wait until 100000, started at 50000
0 | 50000 | Reorder Policy [1000] | job 1000 (Reorder Policy [1000]) exiting with success: execution time (RANDOM) ms
0 | 100000 | DB Scheduler | [TESTING] Wait until 200000, started at 100000
(10 rows)
SELECT * FROM timescaledb_information.jobs WHERE job_id=:reorder_job_id;
job_id | application_name | schedule_interval | max_runtime | max_retries | retry_period | proc_schema | proc_name | owner | scheduled | fixed_schedule | config | next_start | initial_start | hypertable_schema | hypertable_name | check_schema | check_name
@ -323,17 +329,20 @@ SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(125);
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-----------+------------------+------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
0 | 25000 | DB Scheduler | [TESTING] Registered new background worker
1 | 25000 | DB Scheduler | [TESTING] Wait until 50000, started at 25000
0 | 50000 | DB Scheduler | [TESTING] Registered new background worker
1 | 50000 | DB Scheduler | [TESTING] Wait until 100000, started at 50000
0 | 100000 | DB Scheduler | [TESTING] Wait until 200000, started at 100000
0 | 200000 | DB Scheduler | [TESTING] Wait until 325000, started at 200000
(8 rows)
msg_no | mock_time | application_name | msg
--------+-----------+-----------------------+-----------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
0 | 0 | Reorder Policy [1000] | job 1000 (Reorder Policy [1000]) exiting with success: execution time (RANDOM) ms
0 | 25000 | DB Scheduler | [TESTING] Registered new background worker
1 | 25000 | DB Scheduler | [TESTING] Wait until 50000, started at 25000
0 | 25000 | Reorder Policy [1000] | job 1000 (Reorder Policy [1000]) exiting with success: execution time (RANDOM) ms
0 | 50000 | DB Scheduler | [TESTING] Registered new background worker
1 | 50000 | DB Scheduler | [TESTING] Wait until 100000, started at 50000
0 | 50000 | Reorder Policy [1000] | job 1000 (Reorder Policy [1000]) exiting with success: execution time (RANDOM) ms
0 | 100000 | DB Scheduler | [TESTING] Wait until 200000, started at 100000
0 | 200000 | DB Scheduler | [TESTING] Wait until 325000, started at 200000
(11 rows)
SELECT * FROM timescaledb_information.jobs WHERE job_id=:reorder_job_id;
job_id | application_name | schedule_interval | max_runtime | max_retries | retry_period | proc_schema | proc_name | owner | scheduled | fixed_schedule | config | next_start | initial_start | hypertable_schema | hypertable_name | check_schema | check_name
@ -447,11 +456,12 @@ SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(25);
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-----------+------------------+--------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
(2 rows)
msg_no | mock_time | application_name | msg
--------+-----------+-------------------------+-------------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
0 | 0 | Retention Policy [1001] | job 1001 (Retention Policy [1001]) exiting with success: execution time (RANDOM) ms
(3 rows)
SELECT * FROM timescaledb_information.jobs WHERE job_id=:drop_chunks_job_id;
job_id | application_name | schedule_interval | max_runtime | max_retries | retry_period | proc_schema | proc_name | owner | scheduled | fixed_schedule | config | next_start | initial_start | hypertable_schema | hypertable_name | check_schema | check_name
@ -485,12 +495,13 @@ SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(25);
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-----------+------------------+----------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
0 | 25000 | DB Scheduler | [TESTING] Wait until 50000, started at 25000
(3 rows)
msg_no | mock_time | application_name | msg
--------+-----------+-------------------------+-------------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
0 | 0 | Retention Policy [1001] | job 1001 (Retention Policy [1001]) exiting with success: execution time (RANDOM) ms
0 | 25000 | DB Scheduler | [TESTING] Wait until 50000, started at 25000
(4 rows)
SELECT * FROM timescaledb_information.jobs WHERE job_id=:drop_chunks_job_id;
job_id | application_name | schedule_interval | max_runtime | max_retries | retry_period | proc_schema | proc_name | owner | scheduled | fixed_schedule | config | next_start | initial_start | hypertable_schema | hypertable_name | check_schema | check_name
@ -534,15 +545,17 @@ SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(10000);
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-----------+------------------+---------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
0 | 25000 | DB Scheduler | [TESTING] Wait until 50000, started at 25000
0 | 50000 | DB Scheduler | [TESTING] Wait until 1000000, started at 50000
1 | 1000000 | DB Scheduler | [TESTING] Registered new background worker
2 | 1000000 | DB Scheduler | [TESTING] Wait until 10050000, started at 1000000
(6 rows)
msg_no | mock_time | application_name | msg
--------+-----------+-------------------------+-------------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
0 | 0 | Retention Policy [1001] | job 1001 (Retention Policy [1001]) exiting with success: execution time (RANDOM) ms
0 | 25000 | DB Scheduler | [TESTING] Wait until 50000, started at 25000
0 | 50000 | DB Scheduler | [TESTING] Wait until 1000000, started at 50000
1 | 1000000 | DB Scheduler | [TESTING] Registered new background worker
2 | 1000000 | DB Scheduler | [TESTING] Wait until 10050000, started at 1000000
0 | 1000000 | Retention Policy [1001] | job 1001 (Retention Policy [1001]) exiting with success: execution time (RANDOM) ms
(8 rows)
SELECT * FROM timescaledb_information.jobs WHERE job_id=:drop_chunks_job_id;
job_id | application_name | schedule_interval | max_runtime | max_retries | retry_period | proc_schema | proc_name | owner | scheduled | fixed_schedule | config | next_start | initial_start | hypertable_schema | hypertable_name | check_schema | check_name
@ -655,9 +668,11 @@ SELECT * FROM sorted_bgw_log;
1 | 0 | DB Scheduler | [TESTING] Registered new background worker
2 | 0 | DB Scheduler | [TESTING] Wait until 1000000, started at 0
0 | 0 | Retention Policy [1002] | applying retention policy to hypertable "test_drop_chunks_table_date": dropping ...
1 | 0 | Retention Policy [1002] | job 1002 (Retention Policy [1002]) exiting with success: execution time (RANDOM) ms
0 | 0 | Retention Policy [1003] | applying retention policy to hypertable "test_drop_chunks_table_tsntz": dropping...
1 | 0 | Retention Policy [1003] | job 1003 (Retention Policy [1003]) exiting with success: execution time (RANDOM) ms
0 | 1000000 | DB Scheduler | [TESTING] Wait until 2000000, started at 1000000
(6 rows)
(8 rows)
-- test the schedule_interval parameter for policies
CREATE TABLE test_schedint(time timestamptz, a int, b int);

View File

@ -46,7 +46,11 @@ CREATE TABLE public.bgw_log(
msg TEXT
);
CREATE VIEW sorted_bgw_log AS
SELECT * FROM bgw_log ORDER BY mock_time, application_name COLLATE "C", msg_no;
SELECT msg_no,
mock_time,
application_name,
regexp_replace(regexp_replace(msg, '(Wait until|started at|execution time) [0-9]+(\.[0-9]+)?', '\1 (RANDOM)', 'g'), 'background worker "[^"]+"','connection') AS msg
FROM bgw_log ORDER BY mock_time, application_name COLLATE "C", msg_no;
CREATE TABLE public.bgw_dsm_handle_store(
handle BIGINT
);
@ -74,14 +78,14 @@ SELECT * FROM _timescaledb_catalog.continuous_agg;
-- though user on access node has required GRANTS, this will propagate GRANTS to the connected data nodes
GRANT CREATE ON SCHEMA public TO :ROLE_DEFAULT_PERM_USER;
psql:include/cagg_bgw_common.sql:72: WARNING: no privileges were granted for "public"
psql:include/cagg_bgw_common.sql:76: WARNING: no privileges were granted for "public"
\c :TEST_DBNAME :ROLE_DEFAULT_PERM_USER
CREATE TABLE test_continuous_agg_table(time int, data int);
\if :IS_DISTRIBUTED
SELECT create_distributed_hypertable('test_continuous_agg_table', 'time', chunk_time_interval => 10, replication_factor => 2);
\else
SELECT create_hypertable('test_continuous_agg_table', 'time', chunk_time_interval => 10);
psql:include/cagg_bgw_common.sql:78: NOTICE: adding not-null constraint to column "time"
psql:include/cagg_bgw_common.sql:82: NOTICE: adding not-null constraint to column "time"
create_hypertable
----------------------------------------
(1,public,test_continuous_agg_table,t)
@ -155,12 +159,15 @@ SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(25);
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-----------+--------------------------------------------+-----------------------------------------------------------------------------------------
msg_no | mock_time | application_name | msg
--------+-----------+--------------------------------------------+--------------------------------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
1 | 0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | 0 | Refresh Continuous Aggregate Policy [1000] | refreshing continuous aggregate "test_continuous_agg_view" in window [ -2147483648, 6 ]
(3 rows)
1 | 0 | Refresh Continuous Aggregate Policy [1000] | deleted 0 row(s) from materialization table "_timescaledb_internal._materialized_hypertable_2"
2 | 0 | Refresh Continuous Aggregate Policy [1000] | inserted 3 row(s) into materialization table "_timescaledb_internal._materialized_hypertable_2"
3 | 0 | Refresh Continuous Aggregate Policy [1000] | job 1000 (Refresh Continuous Aggregate Policy [1000]) exiting with success: execution time (RANDOM) ms
(6 rows)
SELECT * FROM _timescaledb_config.bgw_job where id=:job_id;
id | application_name | schedule_interval | max_runtime | max_retries | retry_period | proc_schema | proc_name | owner | scheduled | fixed_schedule | initial_start | hypertable_id | config | check_schema | check_name | timezone
@ -366,7 +373,7 @@ SELECT ts_bgw_params_reset_time();
(1 row)
DROP MATERIALIZED VIEW test_continuous_agg_view;
psql:include/cagg_bgw_common.sql:230: NOTICE: drop cascades to table _timescaledb_internal._hyper_2_3_chunk
psql:include/cagg_bgw_common.sql:234: NOTICE: drop cascades to table _timescaledb_internal._hyper_2_3_chunk
CREATE MATERIALIZED VIEW test_continuous_agg_view
WITH (timescaledb.continuous,
timescaledb.materialized_only=true)
@ -388,12 +395,15 @@ SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(25);
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-----------+--------------------------------------------+----------------------------------------------------------------------------------
msg_no | mock_time | application_name | msg
--------+-----------+--------------------------------------------+--------------------------------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
1 | 0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | 0 | Refresh Continuous Aggregate Policy [1001] | refreshing continuous aggregate "test_continuous_agg_view" in window [ -90, 12 ]
(3 rows)
1 | 0 | Refresh Continuous Aggregate Policy [1001] | deleted 0 row(s) from materialization table "_timescaledb_internal._materialized_hypertable_3"
2 | 0 | Refresh Continuous Aggregate Policy [1001] | inserted 6 row(s) into materialization table "_timescaledb_internal._materialized_hypertable_3"
3 | 0 | Refresh Continuous Aggregate Policy [1001] | job 1001 (Refresh Continuous Aggregate Policy [1001]) exiting with success: execution time (RANDOM) ms
(6 rows)
-- job ran once, successfully
SELECT job_id, last_finish - next_start as until_next, last_run_success, total_runs, total_successes, total_failures, total_crashes
@ -433,15 +443,21 @@ SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(25, 25);
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-------------+--------------------------------------------+----------------------------------------------------------------------------------
msg_no | mock_time | application_name | msg
--------+-------------+--------------------------------------------+--------------------------------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
1 | 0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | 0 | Refresh Continuous Aggregate Policy [1001] | refreshing continuous aggregate "test_continuous_agg_view" in window [ -90, 12 ]
1 | 0 | Refresh Continuous Aggregate Policy [1001] | deleted 0 row(s) from materialization table "_timescaledb_internal._materialized_hypertable_3"
2 | 0 | Refresh Continuous Aggregate Policy [1001] | inserted 6 row(s) into materialization table "_timescaledb_internal._materialized_hypertable_3"
3 | 0 | Refresh Continuous Aggregate Policy [1001] | job 1001 (Refresh Continuous Aggregate Policy [1001]) exiting with success: execution time (RANDOM) ms
0 | 43200000000 | DB Scheduler | [TESTING] Registered new background worker
1 | 43200000000 | DB Scheduler | [TESTING] Wait until 43200025000, started at 43200000000
1 | 43200000000 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | 43200000000 | Refresh Continuous Aggregate Policy [1001] | refreshing continuous aggregate "test_continuous_agg_view" in window [ -90, 12 ]
(6 rows)
1 | 43200000000 | Refresh Continuous Aggregate Policy [1001] | deleted 1 row(s) from materialization table "_timescaledb_internal._materialized_hypertable_3"
2 | 43200000000 | Refresh Continuous Aggregate Policy [1001] | inserted 1 row(s) into materialization table "_timescaledb_internal._materialized_hypertable_3"
3 | 43200000000 | Refresh Continuous Aggregate Policy [1001] | job 1001 (Refresh Continuous Aggregate Policy [1001]) exiting with success: execution time (RANDOM) ms
(12 rows)
SELECT job_id, next_start - last_finish as until_next, last_run_success, total_runs, total_successes, total_failures, total_crashes
FROM _timescaledb_internal.bgw_job_stat
@ -493,7 +509,7 @@ last_run_duration |
\x off
DROP MATERIALIZED VIEW test_continuous_agg_view;
psql:include/cagg_bgw_common.sql:290: NOTICE: drop cascades to table _timescaledb_internal._hyper_3_4_chunk
psql:include/cagg_bgw_common.sql:294: NOTICE: drop cascades to table _timescaledb_internal._hyper_3_4_chunk
--create a view with a function that it has no permission to execute
CREATE MATERIALIZED VIEW test_continuous_agg_view
WITH (timescaledb.continuous,
@ -559,7 +575,7 @@ CREATE TABLE test_continuous_agg_table_w_grant(time int, data int);
SELECT create_distributed_hypertable('test_continuous_agg_table_w_grant', 'time', chunk_time_interval => 10, replication_factor => 2);
\else
SELECT create_hypertable('test_continuous_agg_table_w_grant', 'time', chunk_time_interval => 10);
psql:include/cagg_bgw_common.sql:328: NOTICE: adding not-null constraint to column "time"
psql:include/cagg_bgw_common.sql:332: NOTICE: adding not-null constraint to column "time"
create_hypertable
------------------------------------------------
(5,public,test_continuous_agg_table_w_grant,t)
@ -661,16 +677,19 @@ SELECT * FROM test_continuous_agg_view_user_2;
\c :TEST_DBNAME :ROLE_DEFAULT_PERM_USER
SELECT * from sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-------------+--------------------------------------------+------------------------------------------------------------------------------------------------
msg_no | mock_time | application_name | msg
--------+-------------+--------------------------------------------+--------------------------------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
1 | 0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | 0 | Refresh Continuous Aggregate Policy [1003] | refreshing continuous aggregate "test_continuous_agg_view_user_2" in window [ -2147483648, 2 ]
1 | 0 | Refresh Continuous Aggregate Policy [1003] | deleted 0 row(s) from materialization table "_timescaledb_internal._materialized_hypertable_6"
2 | 0 | Refresh Continuous Aggregate Policy [1003] | inserted 1 row(s) into materialization table "_timescaledb_internal._materialized_hypertable_6"
3 | 0 | Refresh Continuous Aggregate Policy [1003] | job 1003 (Refresh Continuous Aggregate Policy [1003]) exiting with success: execution time (RANDOM) ms
0 | 43200000000 | DB Scheduler | [TESTING] Registered new background worker
1 | 43200000000 | DB Scheduler | [TESTING] Wait until 43200025000, started at 43200000000
1 | 43200000000 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | 43200000000 | Refresh Continuous Aggregate Policy [1003] | job 1003 threw an error
1 | 43200000000 | Refresh Continuous Aggregate Policy [1003] | permission denied for table test_continuous_agg_table_w_grant
(7 rows)
(10 rows)
-- Count the number of continuous aggregate policies
SELECT count(*) FROM _timescaledb_config.bgw_job

View File

@ -83,7 +83,11 @@ CREATE TABLE public.bgw_log(
msg TEXT
);
CREATE VIEW sorted_bgw_log AS
SELECT * FROM bgw_log ORDER BY mock_time, application_name COLLATE "C", msg_no;
SELECT msg_no,
mock_time,
application_name,
regexp_replace(regexp_replace(msg, '(Wait until|started at|execution time) [0-9]+(\.[0-9]+)?', '\1 (RANDOM)', 'g'), 'background worker "[^"]+"','connection') AS msg
FROM bgw_log ORDER BY mock_time, application_name COLLATE "C", msg_no;
CREATE TABLE public.bgw_dsm_handle_store(
handle BIGINT
);
@ -111,12 +115,12 @@ SELECT * FROM _timescaledb_catalog.continuous_agg;
-- though user on access node has required GRANTS, this will propagate GRANTS to the connected data nodes
GRANT CREATE ON SCHEMA public TO :ROLE_DEFAULT_PERM_USER;
psql:include/cagg_bgw_common.sql:72: WARNING: no privileges were granted for "public"
psql:include/cagg_bgw_common.sql:76: WARNING: no privileges were granted for "public"
\c :TEST_DBNAME :ROLE_DEFAULT_PERM_USER
CREATE TABLE test_continuous_agg_table(time int, data int);
\if :IS_DISTRIBUTED
SELECT create_distributed_hypertable('test_continuous_agg_table', 'time', chunk_time_interval => 10, replication_factor => 2);
psql:include/cagg_bgw_common.sql:76: NOTICE: adding not-null constraint to column "time"
psql:include/cagg_bgw_common.sql:80: NOTICE: adding not-null constraint to column "time"
create_distributed_hypertable
----------------------------------------
(1,public,test_continuous_agg_table,t)
@ -192,12 +196,15 @@ SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(25);
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-----------+--------------------------------------------+-----------------------------------------------------------------------------------------
msg_no | mock_time | application_name | msg
--------+-----------+--------------------------------------------+--------------------------------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
1 | 0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | 0 | Refresh Continuous Aggregate Policy [1000] | refreshing continuous aggregate "test_continuous_agg_view" in window [ -2147483648, 6 ]
(3 rows)
1 | 0 | Refresh Continuous Aggregate Policy [1000] | deleted 0 row(s) from materialization table "_timescaledb_internal._materialized_hypertable_2"
2 | 0 | Refresh Continuous Aggregate Policy [1000] | inserted 3 row(s) into materialization table "_timescaledb_internal._materialized_hypertable_2"
3 | 0 | Refresh Continuous Aggregate Policy [1000] | job 1000 (Refresh Continuous Aggregate Policy [1000]) exiting with success: execution time (RANDOM) ms
(6 rows)
SELECT * FROM _timescaledb_config.bgw_job where id=:job_id;
id | application_name | schedule_interval | max_runtime | max_retries | retry_period | proc_schema | proc_name | owner | scheduled | fixed_schedule | initial_start | hypertable_id | config | check_schema | check_name | timezone
@ -403,7 +410,7 @@ SELECT ts_bgw_params_reset_time();
(1 row)
DROP MATERIALIZED VIEW test_continuous_agg_view;
psql:include/cagg_bgw_common.sql:230: NOTICE: drop cascades to table _timescaledb_internal._hyper_2_3_chunk
psql:include/cagg_bgw_common.sql:234: NOTICE: drop cascades to table _timescaledb_internal._hyper_2_3_chunk
CREATE MATERIALIZED VIEW test_continuous_agg_view
WITH (timescaledb.continuous,
timescaledb.materialized_only=true)
@ -425,12 +432,15 @@ SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(25);
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-----------+--------------------------------------------+----------------------------------------------------------------------------------
msg_no | mock_time | application_name | msg
--------+-----------+--------------------------------------------+--------------------------------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
1 | 0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | 0 | Refresh Continuous Aggregate Policy [1001] | refreshing continuous aggregate "test_continuous_agg_view" in window [ -90, 12 ]
(3 rows)
1 | 0 | Refresh Continuous Aggregate Policy [1001] | deleted 0 row(s) from materialization table "_timescaledb_internal._materialized_hypertable_3"
2 | 0 | Refresh Continuous Aggregate Policy [1001] | inserted 6 row(s) into materialization table "_timescaledb_internal._materialized_hypertable_3"
3 | 0 | Refresh Continuous Aggregate Policy [1001] | job 1001 (Refresh Continuous Aggregate Policy [1001]) exiting with success: execution time (RANDOM) ms
(6 rows)
-- job ran once, successfully
SELECT job_id, last_finish - next_start as until_next, last_run_success, total_runs, total_successes, total_failures, total_crashes
@ -470,15 +480,21 @@ SELECT ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(25, 25);
(1 row)
SELECT * FROM sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-------------+--------------------------------------------+----------------------------------------------------------------------------------
msg_no | mock_time | application_name | msg
--------+-------------+--------------------------------------------+--------------------------------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
1 | 0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | 0 | Refresh Continuous Aggregate Policy [1001] | refreshing continuous aggregate "test_continuous_agg_view" in window [ -90, 12 ]
1 | 0 | Refresh Continuous Aggregate Policy [1001] | deleted 0 row(s) from materialization table "_timescaledb_internal._materialized_hypertable_3"
2 | 0 | Refresh Continuous Aggregate Policy [1001] | inserted 6 row(s) into materialization table "_timescaledb_internal._materialized_hypertable_3"
3 | 0 | Refresh Continuous Aggregate Policy [1001] | job 1001 (Refresh Continuous Aggregate Policy [1001]) exiting with success: execution time (RANDOM) ms
0 | 43200000000 | DB Scheduler | [TESTING] Registered new background worker
1 | 43200000000 | DB Scheduler | [TESTING] Wait until 43200025000, started at 43200000000
1 | 43200000000 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | 43200000000 | Refresh Continuous Aggregate Policy [1001] | refreshing continuous aggregate "test_continuous_agg_view" in window [ -90, 12 ]
(6 rows)
1 | 43200000000 | Refresh Continuous Aggregate Policy [1001] | deleted 1 row(s) from materialization table "_timescaledb_internal._materialized_hypertable_3"
2 | 43200000000 | Refresh Continuous Aggregate Policy [1001] | inserted 1 row(s) into materialization table "_timescaledb_internal._materialized_hypertable_3"
3 | 43200000000 | Refresh Continuous Aggregate Policy [1001] | job 1001 (Refresh Continuous Aggregate Policy [1001]) exiting with success: execution time (RANDOM) ms
(12 rows)
SELECT job_id, next_start - last_finish as until_next, last_run_success, total_runs, total_successes, total_failures, total_crashes
FROM _timescaledb_internal.bgw_job_stat
@ -530,7 +546,7 @@ last_run_duration |
\x off
DROP MATERIALIZED VIEW test_continuous_agg_view;
psql:include/cagg_bgw_common.sql:290: NOTICE: drop cascades to table _timescaledb_internal._hyper_3_4_chunk
psql:include/cagg_bgw_common.sql:294: NOTICE: drop cascades to table _timescaledb_internal._hyper_3_4_chunk
--create a view with a function that it has no permission to execute
CREATE MATERIALIZED VIEW test_continuous_agg_view
WITH (timescaledb.continuous,
@ -594,7 +610,7 @@ SELECT ts_bgw_params_reset_time();
CREATE TABLE test_continuous_agg_table_w_grant(time int, data int);
\if :IS_DISTRIBUTED
SELECT create_distributed_hypertable('test_continuous_agg_table_w_grant', 'time', chunk_time_interval => 10, replication_factor => 2);
psql:include/cagg_bgw_common.sql:326: NOTICE: adding not-null constraint to column "time"
psql:include/cagg_bgw_common.sql:330: NOTICE: adding not-null constraint to column "time"
create_distributed_hypertable
------------------------------------------------
(5,public,test_continuous_agg_table_w_grant,t)
@ -698,16 +714,19 @@ SELECT * FROM test_continuous_agg_view_user_2;
\c :TEST_DBNAME :ROLE_DEFAULT_PERM_USER
SELECT * from sorted_bgw_log;
msg_no | mock_time | application_name | msg
--------+-------------+--------------------------------------------+------------------------------------------------------------------------------------------------
msg_no | mock_time | application_name | msg
--------+-------------+--------------------------------------------+--------------------------------------------------------------------------------------------------------
0 | 0 | DB Scheduler | [TESTING] Registered new background worker
1 | 0 | DB Scheduler | [TESTING] Wait until 25000, started at 0
1 | 0 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | 0 | Refresh Continuous Aggregate Policy [1003] | refreshing continuous aggregate "test_continuous_agg_view_user_2" in window [ -2147483648, 2 ]
1 | 0 | Refresh Continuous Aggregate Policy [1003] | deleted 0 row(s) from materialization table "_timescaledb_internal._materialized_hypertable_6"
2 | 0 | Refresh Continuous Aggregate Policy [1003] | inserted 1 row(s) into materialization table "_timescaledb_internal._materialized_hypertable_6"
3 | 0 | Refresh Continuous Aggregate Policy [1003] | job 1003 (Refresh Continuous Aggregate Policy [1003]) exiting with success: execution time (RANDOM) ms
0 | 43200000000 | DB Scheduler | [TESTING] Registered new background worker
1 | 43200000000 | DB Scheduler | [TESTING] Wait until 43200025000, started at 43200000000
1 | 43200000000 | DB Scheduler | [TESTING] Wait until (RANDOM), started at (RANDOM)
0 | 43200000000 | Refresh Continuous Aggregate Policy [1003] | job 1003 threw an error
1 | 43200000000 | Refresh Continuous Aggregate Policy [1003] | permission denied for table test_continuous_agg_table_w_grant
(7 rows)
(10 rows)
-- Count the number of continuous aggregate policies
SELECT count(*) FROM _timescaledb_config.bgw_job

View File

@ -125,6 +125,8 @@ LOG: statement: CALL refresh_continuous_aggregate('daily_temp', '2020-04-30', '
DEBUG: refreshing continuous aggregate "daily_temp" in window [ Thu Apr 30 17:00:00 2020 PDT, Sun May 03 17:00:00 2020 PDT ]
DEBUG: hypertable 1 existing watermark >= new invalidation threshold 1588723200000000 1588550400000000
DEBUG: invalidation refresh on "daily_temp" in window [ Thu Apr 30 17:00:00 2020 PDT, Sat May 02 17:00:00 2020 PDT ]
LOG: deleted 0 row(s) from materialization table "_timescaledb_internal._materialized_hypertable_2"
LOG: inserted 8 row(s) into materialization table "_timescaledb_internal._materialized_hypertable_2"
DEBUG: hypertable 2 existing watermark >= new watermark 1588723200000000 1588464000000000
RESET client_min_messages;
LOG: statement: RESET client_min_messages;

View File

@ -112,7 +112,10 @@ CREATE TABLE public.bgw_log(
);
CREATE VIEW sorted_bgw_log AS
SELECT msg_no, application_name, regexp_replace(regexp_replace(msg, 'Wait until [0-9]+, started at [0-9]+', 'Wait until (RANDOM), started at (RANDOM)'), 'background worker "[^"]+"','connection') AS msg FROM bgw_log ORDER BY mock_time, application_name COLLATE "C", msg_no;
SELECT msg_no,
application_name,
regexp_replace(regexp_replace(msg, '(Wait until|started at|execution time) [0-9]+(\.[0-9]+)?', '\1 (RANDOM)', 'g'), 'background worker "[^"]+"','connection') AS msg
FROM bgw_log ORDER BY mock_time, application_name COLLATE "C", msg_no;
CREATE TABLE public.bgw_dsm_handle_store(
handle BIGINT

View File

@ -116,9 +116,10 @@ CREATE TABLE public.bgw_log(
);
CREATE VIEW sorted_bgw_log AS
SELECT msg_no, application_name,
regexp_replace(regexp_replace(msg, 'Wait until [0-9]+, started at [0-9]+', 'Wait until (RANDOM), started at (RANDOM)'), 'background worker "[^"]+"','connection')
AS msg FROM bgw_log ORDER BY mock_time, application_name COLLATE "C", msg_no;
SELECT msg_no,
application_name,
regexp_replace(regexp_replace(msg, '(Wait until|started at|execution time) [0-9]+(\.[0-9]+)?', '\1 (RANDOM)', 'g'), 'background worker "[^"]+"','connection') AS msg
FROM bgw_log ORDER BY mock_time, application_name COLLATE "C", msg_no;
CREATE TABLE public.bgw_dsm_handle_store(
handle BIGINT

View File

@ -45,11 +45,8 @@ CREATE VIEW sorted_bgw_log AS
SELECT msg_no,
mock_time,
application_name,
CASE WHEN length(msg) > 80 THEN
substring(msg, 1, 80) || '...'
ELSE
msg
END AS msg
regexp_replace(CASE WHEN length(msg) > 80 THEN substring(msg, 1, 80) || '...' ELSE msg END,
'(execution time) [0-9]+(\.[0-9]+)?', '\1 (RANDOM)', 'g') AS msg
FROM bgw_log
ORDER BY mock_time,
application_name COLLATE "C",
@ -363,4 +360,4 @@ select ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(40000);
select total_runs, total_successes, total_failures from timescaledb_information.job_stats where job_id = :polcomp_schedint;
-- if we wait another 40s, we should see 3 runs of the job
select ts_bgw_db_scheduler_test_run_and_wait_for_scheduler_finish(40000);
select total_runs, total_successes, total_failures from timescaledb_information.job_stats where job_id = :polcomp_schedint;
select total_runs, total_successes, total_failures from timescaledb_information.job_stats where job_id = :polcomp_schedint;

View File

@ -56,7 +56,11 @@ CREATE TABLE public.bgw_log(
);
CREATE VIEW sorted_bgw_log AS
SELECT * FROM bgw_log ORDER BY mock_time, application_name COLLATE "C", msg_no;
SELECT msg_no,
mock_time,
application_name,
regexp_replace(regexp_replace(msg, '(Wait until|started at|execution time) [0-9]+(\.[0-9]+)?', '\1 (RANDOM)', 'g'), 'background worker "[^"]+"','connection') AS msg
FROM bgw_log ORDER BY mock_time, application_name COLLATE "C", msg_no;
CREATE TABLE public.bgw_dsm_handle_store(
handle BIGINT