PostgreSQL Build Farm Log
Details for system "bowerbird" failure at stage subscriptionCheck, snapshot taken 2017-12-29 23:30:24
| System Information |
Farm member |
Branch |
OS |
Compiler |
Architecture |
Owner |
| bowerbird |
HEAD |
Windows 10 Pro |
Visual Studio 2012 |
x86_64 |
andrew [ a t ] dunslane.net |
Configuration summary
$Script_Config = {
'steps_completed' => [
'SCM-checkout',
'Configure',
'Make',
'Check',
'Install',
'pg_upgradeCheck',
'initdbCheck',
'pg_archivecleanupCheck',
'pg_basebackupCheck',
'pg_configCheck',
'pg_controldataCheck',
'pg_ctlCheck',
'pg_dumpCheck',
'pg_rewindCheck',
'pgbenchCheck',
'scriptsCheck',
'recoveryCheck'
],
'bf_perl_version' => '5.16.2',
'config_opts' => {
'asserts' => 1,
'krb5' => undef,
'iconv' => 'c:\\prog\\3p64',
'python' => 'c:\\python27',
'ldap' => 0,
'xslt' => 'c:\\prog\\3p64',
'tap_tests' => 1,
'perl' => 'c:\\perl64',
'openssl' => 'c:\\prog\\3p64\\openssl',
'xml' => 'c:\\prog\\3p64',
'tcl' => undef,
'integer_datetimes' => 1,
'zlib' => 'c:\\prog\\3p64',
'nls' => undef
},
'target' => 'https://buildfarm.postgresql.org/cgi-bin/pgstatus.pl',
'make_jobs' => undef,
'web_script_version' => 'REL_5',
'current_ts' => 1514593315,
'script_version' => 'REL_5',
'git_ignore_mirror_failure' => 1,
'build_env' => {
'Framework35Version' => 'v3.5',
'Platform' => 'x64',
'VisualStudioVersion' => '11.0',
'VCINSTALLDIR' => 'C:\\Program Files (x86)\\Microsoft Visual Studio 10.0\\VC',
'DevEnvDir' => 'C:\\Program Files (x86)\\Microsoft Visual Studio 11.0\\Common7\\IDE',
'FrameworkVersion32' => 'v4.0.30319',
'TEMPDIR' => 'c:/prog/bf/root/tmp',
'FrameworkDIR64' => 'C:\\windows\\Microsoft.NET\\Framework64',
'VSINSTALLDIR' => 'C:\\Program Files (x86)\\Microsoft Visual Studio 11.0',
'LIBPATH' => 'C:\\windows\\Microsoft.NET\\Framework64\\v4.0.30319i;C:\\windows\\Microsoft.NET\\Framework64\\v3.5;C:\\windows\\Microsoft.NET\\Framework\\v4.0.30319;C:\\windows\\Microsoft.NET\\Framework\\v3.5;C:\\Program Files (x86)\\Microsoft Visual Studio 11.0\\VC\\LIB\\amd64;C:\\Program Files (x86)\\Windows Kits\\8.0\\References\\CommonConfiguration\\Neutral;C:\\Program Files (x86)\\Microsoft SDKs\\Windows\\v8.0\\ExtensionSDKs\\Microsoft.VCLibs\\11.0\\References\\CommonConfiguration\\neutral',
'WindowsSdkDir' => 'C:\\Program Files (x86)\\Windows Kits\\8.0',
'PERL5LIB' => 'c:/prog/bf/p5lib',
'PATH' => 'C:\\Program Files (x86)\\Microsoft Visual Studio 11.0\\Common7\\IDE\\CommonExtensions\\Microsoft\\TestWindow;C:\\Program Files (x86)\\Microsoft Visual Studio 11.0\\Common7\\IDE;C:\\Program Files (x86)\\Microsoft Visual Studio 11.0\\VC\\BIN\\x86_amd64;C:\\Program Files (x86)\\Microsoft Visual Studio 11.0\\VC\\BIN;C:\\Program Files (x86)\\Microsoft Visual Studio 11.0\\Common7\\Tools;C:\\windows\\Microsoft.NET\\Framework\\v4.0.30319;C:\\windows\\Microsoft.NET\\Framework\\v3.5;C:\\Program Files (x86)\\Microsoft Visual Studio 11.0\\VC\\VCPackages;C:\\Program Files (x86)\\Microsoft Visual Studio 11.0\\Team Tools\\Performance Tools;C:\\Program Files (x86)\\Windows Kits\\8.0\\bin\\x86;C:\\Program Files (x86)\\Microsoft SDKs\\Windows\\v8.0A\\bin\\NETFX 4.0 Tools;C:\\Perl64\\Bin;c:\\prog\\3p64\\bin;c:\\prog\\git\\cmd;c:\\prog\\git\\bin;c:\\perl64\\bin;c:\\perl64\\bin;C:\\ProgramData\\Oracle\\Java\\javapath;c:\\Program Files (x86)\\Intel\\iCLS Client\\;c:\\Program Files\\Intel\\iCLS Client\\;C:\\WINDOWS\\system32;C:\\WINDOWS;C:\\WINDOWS\\System32\\Wbem;C:\\WINDOWS\\System32\\WindowsPowerShell\\v1.0\\;C:\\Program Files\\Intel\\Intel(R) Management Engine Components\\DAL;C:\\Program Files\\Intel\\Intel(R) Management Engine Components\\IPT;C:\\Program Files (x86)\\Intel\\Intel(R) Management Engine Components\\DAL;C:\\Program Files (x86)\\Intel\\Intel(R) Management Engine Components\\IPT;C:\\Program Files (x86)\\Intel\\OpenCL SDK\\2.0\\bin\\x86;C:\\Program Files (x86)\\Intel\\OpenCL SDK\\2.0\\bin\\x64;C:\\Program Files (x86)\\Windows Live\\Shared;C:\\prog\\Git\\cmd;C:\\Program Files\\Microsoft SQL Server\\110\\Tools\\Binn\\;C:\\vagrant\\vagrant\\bin;C:\\Program Files (x86)\\Microsoft SQL Server\\110\\Tools\\Binn\\;C:\\Program Files\\Microsoft SQL Server\\110\\DTS\\Binn\\;C:\\Program Files (x86)\\Microsoft SQL Server\\110\\Tools\\Binn\\ManagementStudio\\;C:\\Program Files (x86)\\Microsoft SQL Server\\110\\DTS\\Binn\\;C:\\Program Files\\jEdit;C:\\Program Files (x86)\\GtkSharp\\2.12\\bin;%USERPROFILE%\\.dnx\\bin;C:\\Program Files\\Microsoft DNX\\Dnvm\\;C:\\Program Files\\Microsoft SQL Server\\130\\Tools\\Binn\\;C:\\Program Files (x86)\\Windows Kits\\10\\Windows Performance Toolkit\\;C:\\Program Files (x86)\\Skype\\Phone\\;C:\\Users\\pgrunner\\AppData\\Local\\Microsoft\\WindowsApps',
'INCLUDE' => 'C:\\Program Files (x86)\\Microsoft Visual Studio 11.0\\VC\\INCLUDE;C:\\Program Files (x86)\\Windows Kits\\8.0\\include\\shared;C:\\Program Files (x86)\\Windows Kits\\8.0\\include\\um;C:\\Program Files (x86)\\Windows Kits\\8.0\\include\\winrt',
'WindowsSdkDir_old' => 'C:\\Program Files (x86)\\Microsoft SDKs\\Windows\\v8.0A',
'ExtensionSdkDir' => 'C:\\Program Files (x86)\\Microsoft SDKs\\Windows\\v8.0\\ExtensionSDKs',
'LIB' => 'C:\\Program Files (x86)\\Microsoft Visual Studio 11.0\\VC\\LIB\\amd64;C:\\Program Files (x86)\\Windows Kits\\8.0\\lib\\win8\\um\\x64',
'FrameworkVersion64' => 'v4.0.30319',
'FrameworkDIR32' => 'C:\\windows\\Microsoft.NET\\Framework',
'FrameworkVersion' => 'v4.0.30319',
'INSTALLDIR' => 'C:\\Program Files (x86)\\Microsoft Visual Studio 11.0\\VC',
'FrameworkDir' => 'C:\\windows\\Microsoft.NET\\Framework'
},
'git_use_workdirs' => 1,
'base_port' => 5678,
'force_every' => {},
'ccache_failure_remove' => undef,
'locales' => [
'C'
],
'trigger_include' => undef,
'optional_steps' => {},
'invocation_args' => [
'--skip-steps',
'ecpg-check',
'--verbose',
'--config',
'bowerbird.conf',
'HEAD'
],
'modules' => [
'TestUpgrade'
],
'keep_error_builds' => 0,
'use_vpath' => undef,
'orig_env' => {
'USERPROFILE' => 'xxxxxx',
'COMMONPROGRAMFILES' => 'xxxxxx',
'VBOX_MSI_INSTALL_PATH' => 'xxxxxx',
'APPDATA' => 'xxxxxx',
'PROGRAMFILES' => 'xxxxxx',
'OS' => 'xxxxxx',
'LOCALAPPDATA' => 'xxxxxx',
'PATHEXT' => 'xxxxxx',
'PROGRAMW6432' => 'xxxxxx',
'VS120COMNTOOLS' => 'xxxxxx',
'PROMPT' => 'xxxxxx',
'ONLINESERVICES' => 'xxxxxx',
'VS140COMNTOOLS' => 'xxxxxx',
'NUMBER_OF_PROCESSORS' => 'xxxxxx',
'FP_NO_HOST_CHECK' => 'xxxxxx',
'COMMONPROGRAMFILES(X86)' => 'xxxxxx',
'PATH' => 'c:\\perl64\\bin;C:\\ProgramData\\Oracle\\Java\\javapath;c:\\Program Files (x86)\\Intel\\iCLS Client\\;c:\\Program Files\\Intel\\iCLS Client\\;C:\\WINDOWS\\system32;C:\\WINDOWS;C:\\WINDOWS\\System32\\Wbem;C:\\WINDOWS\\System32\\WindowsPowerShell\\v1.0\\;C:\\Program Files\\Intel\\Intel(R) Management Engine Components\\DAL;C:\\Program Files\\Intel\\Intel(R) Management Engine Components\\IPT;C:\\Program Files (x86)\\Intel\\Intel(R) Management Engine Components\\DAL;C:\\Program Files (x86)\\Intel\\Intel(R) Management Engine Components\\IPT;C:\\Program Files (x86)\\Intel\\OpenCL SDK\\2.0\\bin\\x86;C:\\Program Files (x86)\\Intel\\OpenCL SDK\\2.0\\bin\\x64;C:\\Program Files (x86)\\Windows Live\\Shared;C:\\prog\\Git\\cmd;C:\\Program Files\\Microsoft SQL Server\\110\\Tools\\Binn\\;C:\\vagrant\\vagrant\\bin;C:\\Program Files (x86)\\Microsoft SQL Server\\110\\Tools\\Binn\\;C:\\Program Files\\Microsoft SQL Server\\110\\DTS\\Binn\\;C:\\Program Files (x86)\\Microsoft SQL Server\\110\\Tools\\Binn\\ManagementStudio\\;C:\\Program Files (x86)\\Microsoft SQL Server\\110\\DTS\\Binn\\;C:\\Program Files\\jEdit;C:\\Program Files (x86)\\GtkSharp\\2.12\\bin;%USERPROFILE%\\.dnx\\bin;C:\\Program Files\\Microsoft DNX\\Dnvm\\;C:\\Program Files\\Microsoft SQL Server\\130\\Tools\\Binn\\;C:\\Program Files (x86)\\Windows Kits\\10\\Windows Performance Toolkit\\;C:\\Program Files (x86)\\Skype\\Phone\\;C:\\Users\\pgrunner\\AppData\\Local\\Microsoft\\WindowsApps',
'OPENSSL_CONF' => 'xxxxxx',
'USERDOMAIN' => 'xxxxxx',
'PROGRAMDATA' => 'xxxxxx',
'PROCESSOR_ARCHITECTURE' => 'xxxxxx',
'PSMODULEPATH' => 'xxxxxx',
'TEMP' => 'xxxxxx',
'PROCESSOR_REVISION' => 'xxxxxx',
'SYSTEMDRIVE' => 'xxxxxx',
'SYSTEMROOT' => 'xxxxxx',
'COMMONPROGRAMW6432' => 'xxxxxx',
'COMSPEC' => 'xxxxxx',
'WINDIR' => 'xxxxxx',
'VS110COMNTOOLS' => 'xxxxxx',
'PROCESSOR_LEVEL' => 'xxxxxx',
'PUBLIC' => 'xxxxxx',
'USERNAME' => 'xxxxxx',
'PROCESSOR_IDENTIFIER' => 'xxxxxx',
'PLATFORM' => 'xxxxxx',
'PROGRAMFILES(X86)' => 'xxxxxx',
'GTK_BASEPATH' => 'xxxxxx',
'COMPUTERNAME' => 'xxxxxx',
'ALLUSERSPROFILE' => 'xxxxxx',
'TMP' => 'xxxxxx'
},
'scm' => 'git',
'git_keep_mirror' => 1,
'extra_config' => {
'DEFAULT' => [
'log_line_prefix = \'%m [%p:%l] %q%a \'',
'log_connections = \'true\'',
'log_disconnections = \'true\'',
'log_statement = \'all\'',
'fsync = off'
]
},
'module_versions' => {
'PGBuild::SCM' => 'REL_5',
'PGBuild::Modules::TestUpgrade' => 'REL_5',
'PGBuild::Options' => 'REL_5',
'PGBuild::Utils' => 'REL_5',
'PGBuild::WebTxn' => 'REL_5'
},
'wait_timeout' => undef,
'mail_events' => {
'green' => [],
'change' => [],
'fail' => [],
'all' => []
},
'scmrepo' => undef,
'use_git_cvsserver' => undef,
'tar_log_cmd' => undef,
'make' => 'make',
'core_file_glob' => 'core*',
'alerts' => {},
'build_root' => '/prog/bf/root',
'git_ignore_errors' => 1,
'using_msvc' => 'true',
'config_env' => {
'CC' => 'ccache gcc'
},
'trigger_exclude' => qr/(?^:^doc\/|\.po$)/,
'use_default_ccache_dir' => 1,
'scm_url' => undef,
'upgrade_target' => 'https://buildfarm.postgresql.org/cgi-bin/upgrade.pl',
'animal' => 'bowerbird'
};
Log
Last file mtime in snapshot: Fri Dec 29 21:33:32 2017 GMT
===================================================
Bailout called. Further testing stopped: system pg_ctl failed
FAILED--Further testing stopped: system pg_ctl failed
================== pgsql.build/src/test/subscription/tmp_check/log/001_rep_changes_publisher.log ===================
2017-12-29 19:21:22.675 EST [1576] LOG: listening on IPv4 address "127.0.0.1", port 59751
2017-12-29 19:21:22.692 EST [1576] LOG: could not open directory "base/pgsql_tmp": No such file or directory
2017-12-29 19:21:22.693 EST [1576] LOG: could not open directory "pgsql_tmp": No such file or directory
2017-12-29 19:21:22.714 EST [13072] LOG: database system was shut down at 2017-12-29 19:21:22 EST
2017-12-29 19:21:22.734 EST [1576] LOG: database system is ready to accept connections
2017-12-29 19:21:36.409 EST [12504] 001_rep_changes.pl LOG: statement: CREATE TABLE tab_notrep AS SELECT generate_series(1,10) AS a
2017-12-29 19:21:37.388 EST [11372] 001_rep_changes.pl LOG: statement: CREATE TABLE tab_ins AS SELECT generate_series(1,1002) AS a
2017-12-29 19:21:37.563 EST [10156] 001_rep_changes.pl LOG: statement: CREATE TABLE tab_full AS SELECT generate_series(1,10) AS a
2017-12-29 19:21:37.646 EST [12824] 001_rep_changes.pl LOG: statement: CREATE TABLE tab_full2 (x text)
2017-12-29 19:21:37.878 EST [10152] 001_rep_changes.pl LOG: statement: INSERT INTO tab_full2 VALUES ('a'), ('b'), ('b')
2017-12-29 19:21:38.046 EST [11572] 001_rep_changes.pl LOG: statement: CREATE TABLE tab_rep (a int primary key)
2017-12-29 19:21:38.527 EST [5764] 001_rep_changes.pl LOG: statement: CREATE TABLE tab_mixed (a int primary key, b text)
2017-12-29 19:21:38.640 EST [680] 001_rep_changes.pl LOG: statement: INSERT INTO tab_mixed (a, b) VALUES (1, 'foo')
2017-12-29 19:21:39.954 EST [6924] 001_rep_changes.pl LOG: statement: CREATE PUBLICATION tap_pub
2017-12-29 19:21:40.120 EST [3384] 001_rep_changes.pl LOG: statement: CREATE PUBLICATION tap_pub_ins_only WITH (publish = insert)
2017-12-29 19:21:40.227 EST [8772] 001_rep_changes.pl LOG: statement: ALTER PUBLICATION tap_pub ADD TABLE tab_rep, tab_full, tab_full2, tab_mixed
2017-12-29 19:21:40.372 EST [7596] 001_rep_changes.pl LOG: statement: ALTER PUBLICATION tap_pub_ins_only ADD TABLE tab_ins
2017-12-29 19:21:40.604 EST [11932] tap_sub LOG: statement: SELECT DISTINCT t.schemaname, t.tablename
FROM pg_catalog.pg_publication_tables t
WHERE t.pubname IN ('tap_pub', 'tap_pub_ins_only')
2017-12-29 19:21:41.053 EST [11932] tap_sub LOG: received replication command: CREATE_REPLICATION_SLOT "tap_sub" LOGICAL pgoutput NOEXPORT_SNAPSHOT
2017-12-29 19:21:41.157 EST [11932] tap_sub LOG: logical decoding found consistent point at 0/1614EC0
2017-12-29 19:21:41.157 EST [11932] tap_sub DETAIL: There are no running transactions.
2017-12-29 19:21:42.513 EST [3392] 001_rep_changes.pl LOG: statement: SELECT pg_current_wal_lsn() <= replay_lsn FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:42.550 EST [3076] tap_sub LOG: received replication command: IDENTIFY_SYSTEM
2017-12-29 19:21:42.550 EST [3076] tap_sub LOG: received replication command: START_REPLICATION SLOT "tap_sub" LOGICAL 0/0 (proto_version '1', publication_names '"tap_pub","tap_pub_ins_only"')
2017-12-29 19:21:42.552 EST [3076] tap_sub LOG: starting logical decoding for slot "tap_sub"
2017-12-29 19:21:42.552 EST [3076] tap_sub DETAIL: streaming transactions committing after 0/1614EF8, reading WAL from 0/1614EC0
2017-12-29 19:21:42.552 EST [3076] tap_sub LOG: logical decoding found consistent point at 0/1614EC0
2017-12-29 19:21:42.552 EST [3076] tap_sub DETAIL: There are no running transactions.
2017-12-29 19:21:42.665 EST [4312] tap_sub LOG: statement: BEGIN READ ONLY ISOLATION LEVEL REPEATABLE READ
2017-12-29 19:21:42.665 EST [4312] tap_sub LOG: received replication command: CREATE_REPLICATION_SLOT "tap_sub_16412_sync_16390" TEMPORARY LOGICAL pgoutput USE_SNAPSHOT
2017-12-29 19:21:42.684 EST [8380] tap_sub LOG: statement: BEGIN READ ONLY ISOLATION LEVEL REPEATABLE READ
2017-12-29 19:21:42.685 EST [8380] tap_sub LOG: received replication command: CREATE_REPLICATION_SLOT "tap_sub_16412_sync_16393" TEMPORARY LOGICAL pgoutput USE_SNAPSHOT
2017-12-29 19:21:42.691 EST [4312] tap_sub LOG: logical decoding found consistent point at 0/1614EF8
2017-12-29 19:21:42.691 EST [4312] tap_sub DETAIL: There are no running transactions.
2017-12-29 19:21:42.708 EST [8380] tap_sub LOG: logical decoding found consistent point at 0/1614F30
2017-12-29 19:21:42.708 EST [8380] tap_sub DETAIL: There are no running transactions.
2017-12-29 19:21:42.730 EST [4312] tap_sub LOG: statement: SELECT c.oid, c.relreplident FROM pg_catalog.pg_class c INNER JOIN pg_catalog.pg_namespace n ON (c.relnamespace = n.oid) WHERE n.nspname = 'public' AND c.relname = 'tab_full' AND c.relkind = 'r'
2017-12-29 19:21:42.730 EST [8380] tap_sub LOG: statement: SELECT c.oid, c.relreplident FROM pg_catalog.pg_class c INNER JOIN pg_catalog.pg_namespace n ON (c.relnamespace = n.oid) WHERE n.nspname = 'public' AND c.relname = 'tab_full2' AND c.relkind = 'r'
2017-12-29 19:21:42.785 EST [8380] tap_sub LOG: statement: SELECT a.attname, a.atttypid, a.atttypmod, a.attnum = ANY(i.indkey) FROM pg_catalog.pg_attribute a LEFT JOIN pg_catalog.pg_index i ON (i.indexrelid = pg_get_replica_identity_index(16393)) WHERE a.attnum > 0::pg_catalog.int2 AND NOT a.attisdropped AND a.attrelid = 16393 ORDER BY a.attnum
2017-12-29 19:21:42.785 EST [4312] tap_sub LOG: statement: SELECT a.attname, a.atttypid, a.atttypmod, a.attnum = ANY(i.indkey) FROM pg_catalog.pg_attribute a LEFT JOIN pg_catalog.pg_index i ON (i.indexrelid = pg_get_replica_identity_index(16390)) WHERE a.attnum > 0::pg_catalog.int2 AND NOT a.attisdropped AND a.attrelid = 16390 ORDER BY a.attnum
2017-12-29 19:21:42.860 EST [8380] tap_sub LOG: statement: COPY public.tab_full2 TO STDOUT
2017-12-29 19:21:42.860 EST [4312] tap_sub LOG: statement: COPY public.tab_full TO STDOUT
2017-12-29 19:21:42.861 EST [8380] tap_sub LOG: statement: COMMIT
2017-12-29 19:21:42.861 EST [4312] tap_sub LOG: statement: COMMIT
2017-12-29 19:21:42.896 EST [4312] tap_sub LOG: received replication command: START_REPLICATION SLOT "tap_sub_16412_sync_16390" LOGICAL 0/1614F30 (proto_version '1', publication_names '"tap_pub","tap_pub_ins_only"')
2017-12-29 19:21:42.897 EST [4312] tap_sub LOG: starting logical decoding for slot "tap_sub_16412_sync_16390"
2017-12-29 19:21:42.897 EST [4312] tap_sub DETAIL: streaming transactions committing after 0/1614F30, reading WAL from 0/1614EF8
2017-12-29 19:21:42.897 EST [4312] tap_sub LOG: logical decoding found consistent point at 0/1614EF8
2017-12-29 19:21:42.897 EST [4312] tap_sub DETAIL: There are no running transactions.
2017-12-29 19:21:42.939 EST [11420] tap_sub LOG: statement: BEGIN READ ONLY ISOLATION LEVEL REPEATABLE READ
2017-12-29 19:21:42.939 EST [11420] tap_sub LOG: received replication command: CREATE_REPLICATION_SLOT "tap_sub_16412_sync_16387" TEMPORARY LOGICAL pgoutput USE_SNAPSHOT
2017-12-29 19:21:42.961 EST [11420] tap_sub LOG: logical decoding found consistent point at 0/1614F68
2017-12-29 19:21:42.961 EST [11420] tap_sub DETAIL: There are no running transactions.
2017-12-29 19:21:42.961 EST [11420] tap_sub LOG: statement: SELECT c.oid, c.relreplident FROM pg_catalog.pg_class c INNER JOIN pg_catalog.pg_namespace n ON (c.relnamespace = n.oid) WHERE n.nspname = 'public' AND c.relname = 'tab_ins' AND c.relkind = 'r'
2017-12-29 19:21:42.967 EST [11420] tap_sub LOG: statement: SELECT a.attname, a.atttypid, a.atttypmod, a.attnum = ANY(i.indkey) FROM pg_catalog.pg_attribute a LEFT JOIN pg_catalog.pg_index i ON (i.indexrelid = pg_get_replica_identity_index(16387)) WHERE a.attnum > 0::pg_catalog.int2 AND NOT a.attisdropped AND a.attrelid = 16387 ORDER BY a.attnum
2017-12-29 19:21:42.972 EST [11420] tap_sub LOG: statement: COPY public.tab_ins TO STDOUT
2017-12-29 19:21:42.983 EST [6356] tap_sub LOG: statement: BEGIN READ ONLY ISOLATION LEVEL REPEATABLE READ
2017-12-29 19:21:42.984 EST [6356] tap_sub LOG: received replication command: CREATE_REPLICATION_SLOT "tap_sub_16412_sync_16404" TEMPORARY LOGICAL pgoutput USE_SNAPSHOT
2017-12-29 19:21:42.990 EST [11420] tap_sub LOG: statement: COMMIT
2017-12-29 19:21:43.027 EST [6356] tap_sub LOG: logical decoding found consistent point at 0/1614FA0
2017-12-29 19:21:43.027 EST [6356] tap_sub DETAIL: There are no running transactions.
2017-12-29 19:21:43.027 EST [6356] tap_sub LOG: statement: SELECT c.oid, c.relreplident FROM pg_catalog.pg_class c INNER JOIN pg_catalog.pg_namespace n ON (c.relnamespace = n.oid) WHERE n.nspname = 'public' AND c.relname = 'tab_mixed' AND c.relkind = 'r'
2017-12-29 19:21:43.034 EST [6356] tap_sub LOG: statement: SELECT a.attname, a.atttypid, a.atttypmod, a.attnum = ANY(i.indkey) FROM pg_catalog.pg_attribute a LEFT JOIN pg_catalog.pg_index i ON (i.indexrelid = pg_get_replica_identity_index(16404)) WHERE a.attnum > 0::pg_catalog.int2 AND NOT a.attisdropped AND a.attrelid = 16404 ORDER BY a.attnum
2017-12-29 19:21:43.039 EST [6356] tap_sub LOG: statement: COPY public.tab_mixed TO STDOUT
2017-12-29 19:21:43.041 EST [6356] tap_sub LOG: statement: COMMIT
2017-12-29 19:21:43.065 EST [11620] 001_rep_changes.pl LOG: statement: SELECT pg_current_wal_lsn() <= replay_lsn FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:43.078 EST [12292] tap_sub LOG: statement: BEGIN READ ONLY ISOLATION LEVEL REPEATABLE READ
2017-12-29 19:21:43.079 EST [12292] tap_sub LOG: received replication command: CREATE_REPLICATION_SLOT "tap_sub_16412_sync_16399" TEMPORARY LOGICAL pgoutput USE_SNAPSHOT
2017-12-29 19:21:43.098 EST [12292] tap_sub LOG: logical decoding found consistent point at 0/1614FD8
2017-12-29 19:21:43.098 EST [12292] tap_sub DETAIL: There are no running transactions.
2017-12-29 19:21:43.099 EST [12292] tap_sub LOG: statement: SELECT c.oid, c.relreplident FROM pg_catalog.pg_class c INNER JOIN pg_catalog.pg_namespace n ON (c.relnamespace = n.oid) WHERE n.nspname = 'public' AND c.relname = 'tab_rep' AND c.relkind = 'r'
2017-12-29 19:21:43.104 EST [12292] tap_sub LOG: statement: SELECT a.attname, a.atttypid, a.atttypmod, a.attnum = ANY(i.indkey) FROM pg_catalog.pg_attribute a LEFT JOIN pg_catalog.pg_index i ON (i.indexrelid = pg_get_replica_identity_index(16399)) WHERE a.attnum > 0::pg_catalog.int2 AND NOT a.attisdropped AND a.attrelid = 16399 ORDER BY a.attnum
2017-12-29 19:21:43.112 EST [12292] tap_sub LOG: statement: COPY public.tab_rep TO STDOUT
2017-12-29 19:21:43.113 EST [12292] tap_sub LOG: statement: COMMIT
2017-12-29 19:21:44.159 EST [32] 001_rep_changes.pl LOG: statement: INSERT INTO tab_ins SELECT generate_series(1,50)
2017-12-29 19:21:44.279 EST [9812] 001_rep_changes.pl LOG: statement: DELETE FROM tab_ins WHERE a > 20
2017-12-29 19:21:44.398 EST [11584] 001_rep_changes.pl LOG: statement: UPDATE tab_ins SET a = -a
2017-12-29 19:21:44.507 EST [4448] 001_rep_changes.pl LOG: statement: INSERT INTO tab_rep SELECT generate_series(1,50)
2017-12-29 19:21:44.653 EST [6632] 001_rep_changes.pl LOG: statement: DELETE FROM tab_rep WHERE a > 20
2017-12-29 19:21:44.721 EST [9772] 001_rep_changes.pl LOG: statement: UPDATE tab_rep SET a = -a
2017-12-29 19:21:44.853 EST [6732] 001_rep_changes.pl LOG: statement: INSERT INTO tab_mixed VALUES (2, 'bar')
2017-12-29 19:21:44.955 EST [360] 001_rep_changes.pl LOG: statement: SELECT pg_current_wal_lsn() <= replay_lsn FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:45.563 EST [6984] 001_rep_changes.pl LOG: statement: INSERT INTO tab_full SELECT generate_series(1,10)
2017-12-29 19:21:45.646 EST [1036] 001_rep_changes.pl LOG: statement: ALTER TABLE tab_full REPLICA IDENTITY FULL
2017-12-29 19:21:45.871 EST [8976] 001_rep_changes.pl LOG: statement: ALTER TABLE tab_full2 REPLICA IDENTITY FULL
2017-12-29 19:21:46.047 EST [10220] 001_rep_changes.pl LOG: statement: ALTER TABLE tab_ins REPLICA IDENTITY FULL
2017-12-29 19:21:46.248 EST [4708] 001_rep_changes.pl LOG: statement: UPDATE tab_full SET a = a * a
2017-12-29 19:21:46.479 EST [4928] 001_rep_changes.pl LOG: statement: UPDATE tab_full2 SET x = 'bb' WHERE x = 'b'
2017-12-29 19:21:46.528 EST [3764] 001_rep_changes.pl LOG: statement: SELECT pg_current_wal_lsn() <= replay_lsn FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:47.039 EST [4772] 001_rep_changes.pl LOG: statement: SELECT pid FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:47.294 EST [12484] 001_rep_changes.pl LOG: statement: SELECT pid != 3076 FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:47.528 EST [8700] 001_rep_changes.pl LOG: statement: SELECT pid != 3076 FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:47.951 EST [9256] tap_sub LOG: received replication command: IDENTIFY_SYSTEM
2017-12-29 19:21:47.951 EST [9256] tap_sub LOG: received replication command: START_REPLICATION SLOT "tap_sub" LOGICAL 0/1628A00 (proto_version '1', publication_names '"tap_pub","tap_pub_ins_only"')
2017-12-29 19:21:47.952 EST [9256] tap_sub LOG: starting logical decoding for slot "tap_sub"
2017-12-29 19:21:47.952 EST [9256] tap_sub DETAIL: streaming transactions committing after 0/1628A00, reading WAL from 0/1614FD8
2017-12-29 19:21:47.952 EST [9256] tap_sub LOG: logical decoding found consistent point at 0/1614FD8
2017-12-29 19:21:47.952 EST [9256] tap_sub DETAIL: There are no running transactions.
2017-12-29 19:21:47.980 EST [6572] 001_rep_changes.pl LOG: statement: SELECT pid != 3076 FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:48.117 EST [1228] 001_rep_changes.pl LOG: statement: SELECT pid FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:48.267 EST [9060] tap_sub LOG: statement: SELECT DISTINCT t.schemaname, t.tablename
FROM pg_catalog.pg_publication_tables t
WHERE t.pubname IN ('tap_pub_ins_only')
2017-12-29 19:21:48.342 EST [1700] 001_rep_changes.pl LOG: statement: SELECT pid != 9256 FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:48.558 EST [12692] 001_rep_changes.pl LOG: statement: SELECT pid != 9256 FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:48.762 EST [4216] 001_rep_changes.pl LOG: statement: SELECT pid != 9256 FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:49.000 EST [8256] 001_rep_changes.pl LOG: statement: SELECT pid != 9256 FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:49.010 EST [12368] tap_sub LOG: received replication command: IDENTIFY_SYSTEM
2017-12-29 19:21:49.010 EST [12368] tap_sub LOG: received replication command: START_REPLICATION SLOT "tap_sub" LOGICAL 0/1628A00 (proto_version '1', publication_names '"tap_pub_ins_only"')
2017-12-29 19:21:49.011 EST [12368] tap_sub LOG: starting logical decoding for slot "tap_sub"
2017-12-29 19:21:49.011 EST [12368] tap_sub DETAIL: streaming transactions committing after 0/1628A00, reading WAL from 0/1614FD8
2017-12-29 19:21:49.011 EST [12368] tap_sub LOG: logical decoding found consistent point at 0/1614FD8
2017-12-29 19:21:49.011 EST [12368] tap_sub DETAIL: There are no running transactions.
2017-12-29 19:21:49.168 EST [4664] 001_rep_changes.pl LOG: statement: SELECT pid != 9256 FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:49.315 EST [12384] 001_rep_changes.pl LOG: statement: INSERT INTO tab_ins SELECT generate_series(1001,1100)
2017-12-29 19:21:49.448 EST [11404] 001_rep_changes.pl LOG: statement: DELETE FROM tab_rep
2017-12-29 19:21:49.498 EST [420] 001_rep_changes.pl LOG: statement: SELECT pg_current_wal_lsn() <= replay_lsn FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:49.740 EST [11164] 001_rep_changes.pl LOG: statement: SELECT pg_current_wal_lsn() <= replay_lsn FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:50.143 EST [11000] 001_rep_changes.pl LOG: statement: ALTER PUBLICATION tap_pub_ins_only SET (publish = 'insert, delete')
2017-12-29 19:21:50.224 EST [10984] 001_rep_changes.pl LOG: statement: ALTER PUBLICATION tap_pub_ins_only ADD TABLE tab_full
2017-12-29 19:21:50.383 EST [11252] 001_rep_changes.pl LOG: statement: DELETE FROM tab_ins WHERE a > 0
2017-12-29 19:21:50.479 EST [10228] tap_sub LOG: statement: SELECT DISTINCT t.schemaname, t.tablename
FROM pg_catalog.pg_publication_tables t
WHERE t.pubname IN ('tap_pub_ins_only')
2017-12-29 19:21:50.581 EST [12476] 001_rep_changes.pl LOG: statement: INSERT INTO tab_full VALUES(0)
2017-12-29 19:21:50.638 EST [2540] 001_rep_changes.pl LOG: statement: SELECT pg_current_wal_lsn() <= replay_lsn FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:51.088 EST [7112] 001_rep_changes.pl LOG: statement: SELECT pid FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:51.344 EST [8296] 001_rep_changes.pl LOG: statement: SELECT pid != 12368 FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:51.577 EST [12316] 001_rep_changes.pl LOG: statement: SELECT pid != 12368 FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:51.873 EST [4488] 001_rep_changes.pl LOG: statement: SELECT pid != 12368 FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:52.033 EST [7872] tap_sub LOG: received replication command: IDENTIFY_SYSTEM
2017-12-29 19:21:52.033 EST [7872] tap_sub LOG: received replication command: START_REPLICATION SLOT "tap_sub" LOGICAL 0/162C8B0 (proto_version '1', publication_names '"tap_pub_ins_only"')
2017-12-29 19:21:52.034 EST [7872] tap_sub LOG: starting logical decoding for slot "tap_sub"
2017-12-29 19:21:52.034 EST [7872] tap_sub DETAIL: streaming transactions committing after 0/162C8B0, reading WAL from 0/1614FD8
2017-12-29 19:21:52.034 EST [7872] tap_sub LOG: logical decoding found consistent point at 0/1614FD8
2017-12-29 19:21:52.034 EST [7872] tap_sub DETAIL: There are no running transactions.
2017-12-29 19:21:52.075 EST [1324] 001_rep_changes.pl LOG: statement: SELECT pid != 12368 FROM pg_stat_replication WHERE application_name = 'tap_sub';
2017-12-29 19:21:52.282 EST [8016] tap_sub LOG: received replication command: DROP_REPLICATION_SLOT tap_sub WAIT
2017-12-29 19:21:52.805 EST [10156] 001_rep_changes.pl LOG: statement: SELECT count(*) FROM pg_replication_slots
2017-12-29 19:21:53.373 EST [7892] 001_rep_changes.pl LOG: statement: SELECT count(*) FROM pg_replication_slots
2017-12-29 19:21:53.724 EST [1576] LOG: received immediate shutdown request
2017-12-29 19:21:53.727 EST [7524] WARNING: terminating connection because of crash of another server process
2017-12-29 19:21:53.727 EST [7524] DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2017-12-29 19:21:53.727 EST [7524] HINT: In a moment you should be able to reconnect to the database and repeat your command.
2017-12-29 19:21:53.753 EST [1576] LOG: database system is shut down
================== pgsql.build/src/test/subscription/tmp_check/log/001_rep_changes_subscriber.log ===================
2017-12-29 19:21:35.827 EST [12948] LOG: listening on IPv4 address "127.0.0.1", port 59752
2017-12-29 19:21:35.844 EST [12948] LOG: could not open directory "base/pgsql_tmp": No such file or directory
2017-12-29 19:21:35.846 EST [12948] LOG: could not open directory "pgsql_tmp": No such file or directory
2017-12-29 19:21:35.866 EST [656] LOG: database system was shut down at 2017-12-29 19:21:35 EST
2017-12-29 19:21:35.898 EST [12948] LOG: database system is ready to accept connections
2017-12-29 19:21:38.819 EST [6764] 001_rep_changes.pl LOG: statement: CREATE TABLE tab_notrep (a int)
2017-12-29 19:21:39.136 EST [1032] 001_rep_changes.pl LOG: statement: CREATE TABLE tab_ins (a int)
2017-12-29 19:21:39.223 EST [2904] 001_rep_changes.pl LOG: statement: CREATE TABLE tab_full (a int)
2017-12-29 19:21:39.299 EST [9364] 001_rep_changes.pl LOG: statement: CREATE TABLE tab_full2 (x text)
2017-12-29 19:21:39.728 EST [11048] 001_rep_changes.pl LOG: statement: CREATE TABLE tab_rep (a int primary key)
2017-12-29 19:21:39.838 EST [10660] 001_rep_changes.pl LOG: statement: CREATE TABLE tab_mixed (c text, b text, a int primary key)
2017-12-29 19:21:40.474 EST [10044] 001_rep_changes.pl LOG: statement: CREATE SUBSCRIPTION tap_sub CONNECTION 'port=59751 host=127.0.0.1 dbname=postgres application_name=tap_sub' PUBLICATION tap_pub, tap_pub_ins_only
2017-12-29 19:21:42.508 EST [9780] LOG: logical replication apply worker for subscription "tap_sub" has started
2017-12-29 19:21:42.632 EST [11248] LOG: logical replication table synchronization worker for subscription "tap_sub", table "tab_full" has started
2017-12-29 19:21:42.650 EST [5808] LOG: logical replication table synchronization worker for subscription "tap_sub", table "tab_full2" has started
2017-12-29 19:21:42.863 EST [5808] LOG: logical replication table synchronization worker for subscription "tap_sub", table "tab_full2" has finished
2017-12-29 19:21:42.899 EST [9420] LOG: logical replication table synchronization worker for subscription "tap_sub", table "tab_ins" has started
2017-12-29 19:21:42.906 EST [11248] LOG: logical replication table synchronization worker for subscription "tap_sub", table "tab_full" has finished
2017-12-29 19:21:42.946 EST [9264] LOG: logical replication table synchronization worker for subscription "tap_sub", table "tab_mixed" has started
2017-12-29 19:21:42.993 EST [9420] LOG: logical replication table synchronization worker for subscription "tap_sub", table "tab_ins" has finished
2017-12-29 19:21:43.041 EST [8724] LOG: logical replication table synchronization worker for subscription "tap_sub", table "tab_rep" has started
2017-12-29 19:21:43.048 EST [9264] LOG: logical replication table synchronization worker for subscription "tap_sub", table "tab_mixed" has finished
2017-12-29 19:21:43.118 EST [8724] LOG: logical replication table synchronization worker for subscription "tap_sub", table "tab_rep" has finished
2017-12-29 19:21:43.155 EST [12896] 001_rep_changes.pl LOG: statement: SELECT count(1) = 0 FROM pg_subscription_rel WHERE srsubstate NOT IN ('r', 's');
2017-12-29 19:21:43.874 EST [3700] 001_rep_changes.pl LOG: statement: SELECT count(*) FROM tab_notrep
2017-12-29 19:21:44.003 EST [7128] 001_rep_changes.pl LOG: statement: SELECT count(*) FROM tab_ins
2017-12-29 19:21:45.107 EST [12276] 001_rep_changes.pl LOG: statement: SELECT count(*), min(a), max(a) FROM tab_ins
2017-12-29 19:21:45.329 EST [7972] 001_rep_changes.pl LOG: statement: SELECT count(*), min(a), max(a) FROM tab_rep
2017-12-29 19:21:45.441 EST [748] 001_rep_changes.pl LOG: statement: SELECT c, b, a FROM tab_mixed
2017-12-29 19:21:45.759 EST [9476] 001_rep_changes.pl LOG: statement: ALTER TABLE tab_full REPLICA IDENTITY FULL
2017-12-29 19:21:45.976 EST [10664] 001_rep_changes.pl LOG: statement: ALTER TABLE tab_full2 REPLICA IDENTITY FULL
2017-12-29 19:21:46.136 EST [7004] 001_rep_changes.pl LOG: statement: ALTER TABLE tab_ins REPLICA IDENTITY FULL
2017-12-29 19:21:46.688 EST [448] 001_rep_changes.pl LOG: statement: SELECT count(*), min(a), max(a) FROM tab_full
2017-12-29 19:21:46.828 EST [9628] 001_rep_changes.pl LOG: statement: SELECT x FROM tab_full2 ORDER BY 1
2017-12-29 19:21:47.201 EST [6512] 001_rep_changes.pl LOG: statement: ALTER SUBSCRIPTION tap_sub CONNECTION 'application_name=tap_sub port=59751 host=127.0.0.1 dbname=postgres'
2017-12-29 19:21:47.881 EST [9780] LOG: logical replication apply worker for subscription "tap_sub" will restart because the connection information was changed
2017-12-29 19:21:47.924 EST [6676] LOG: logical replication apply worker for subscription "tap_sub" has started
2017-12-29 19:21:48.242 EST [11052] 001_rep_changes.pl LOG: statement: ALTER SUBSCRIPTION tap_sub SET PUBLICATION tap_pub_ins_only WITH (copy_data = false)
2017-12-29 19:21:48.944 EST [6676] LOG: logical replication apply worker for subscription "tap_sub" will restart because subscription's publications were changed
2017-12-29 19:21:48.985 EST [10188] LOG: logical replication apply worker for subscription "tap_sub" has started
2017-12-29 19:21:49.891 EST [3084] 001_rep_changes.pl LOG: statement: SELECT count(*), min(a), max(a) FROM tab_ins
2017-12-29 19:21:50.007 EST [4460] 001_rep_changes.pl LOG: statement: SELECT count(*), min(a), max(a) FROM tab_rep
2017-12-29 19:21:50.455 EST [10140] 001_rep_changes.pl LOG: statement: ALTER SUBSCRIPTION tap_sub REFRESH PUBLICATION WITH (copy_data = false)
2017-12-29 19:21:50.781 EST [5872] 001_rep_changes.pl LOG: statement: SELECT count(*), min(a), max(a) FROM tab_ins
2017-12-29 19:21:50.921 EST [1784] 001_rep_changes.pl LOG: statement: SELECT count(*), min(a), max(a) FROM tab_full
2017-12-29 19:21:51.246 EST [11652] 001_rep_changes.pl LOG: statement: ALTER SUBSCRIPTION tap_sub RENAME TO tap_sub_renamed
2017-12-29 19:21:51.975 EST [10188] LOG: logical replication apply worker for subscription "tap_sub" will restart because subscription was renamed
2017-12-29 19:21:52.012 EST [11820] LOG: logical replication apply worker for subscription "tap_sub_renamed" has started
2017-12-29 19:21:52.196 EST [7256] 001_rep_changes.pl LOG: statement: DROP SUBSCRIPTION tap_sub_renamed
2017-12-29 19:21:52.197 EST [11820] FATAL: terminating logical replication worker due to administrator command
2017-12-29 19:21:52.200 EST [12948] LOG: background worker "logical replication worker" (PID 11820) exited with exit code 1
2017-12-29 19:21:52.582 EST [8468] 001_rep_changes.pl LOG: statement: SELECT count(*) FROM pg_subscription
2017-12-29 19:21:53.228 EST [10780] 001_rep_changes.pl LOG: statement: SELECT count(*) FROM pg_subscription_rel
2017-12-29 19:21:53.526 EST [404] 001_rep_changes.pl LOG: statement: SELECT count(*) FROM pg_replication_origin
2017-12-29 19:21:53.598 EST [12948] LOG: received fast shutdown request
2017-12-29 19:21:53.602 EST [12948] LOG: aborting any active transactions
2017-12-29 19:21:53.605 EST [12948] LOG: background worker "logical replication launcher" (PID 7996) exited with exit code 1
2017-12-29 19:21:53.635 EST [8472] LOG: shutting down
2017-12-29 19:21:53.711 EST [12948] LOG: database system is shut down
================== pgsql.build/src/test/subscription/tmp_check/log/regress_log_001_rep_changes ===================
# Checking port 59751
# Found free port 59751
Name: publisher
Data directory: c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_publisher_data/pgdata
Backup directory: c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_publisher_data/backup
Archive directory: c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_publisher_data/archives
Connection string: port=59751 host=127.0.0.1
Log file: c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/log/001_rep_changes_publisher.log
# Running: initdb -D c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_publisher_data/pgdata -A trust -N
The files belonging to this database system will be owned by user "pgrunner".
This user must also own the server process.
The database cluster will be initialized with locale "English_United States.1252".
The default database encoding has accordingly been set to "WIN1252".
The default text search configuration will be set to "english".
Data page checksums are disabled.
creating directory c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_publisher_data/pgdata ... ok
creating subdirectories ... ok
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting dynamic shared memory implementation ... windows
creating configuration files ... ok
running bootstrap script ... ok
performing post-bootstrap initialization ... ok
Sync to disk skipped.
The data directory might become corrupt if the operating system crashes.
Success. You can now start the database server using:
pg_ctl -D c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_publisher_data/pgdata -l logfile start
# Running: c:/prog/bf/root/HEAD/pgsql.build/Release/pg_regress/pg_regress --config-auth c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_publisher_data/pgdata
### Starting node "publisher"
# Running: pg_ctl -D c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_publisher_data/pgdata -l c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/log/001_rep_changes_publisher.log start
waiting for server to start.... done
server started
# Postmaster PID for node "publisher" is 1576
# Checking port 59752
# Found free port 59752
Name: subscriber
Data directory: c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_subscriber_data/pgdata
Backup directory: c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_subscriber_data/backup
Archive directory: c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_subscriber_data/archives
Connection string: port=59752 host=127.0.0.1
Log file: c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/log/001_rep_changes_subscriber.log
# Running: initdb -D c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_subscriber_data/pgdata -A trust -N
The files belonging to this database system will be owned by user "pgrunner".
This user must also own the server process.
The database cluster will be initialized with locale "English_United States.1252".
The default database encoding has accordingly been set to "WIN1252".
The default text search configuration will be set to "english".
Data page checksums are disabled.
creating directory c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_subscriber_data/pgdata ... ok
creating subdirectories ... ok
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting dynamic shared memory implementation ... windows
creating configuration files ... ok
running bootstrap script ... ok
performing post-bootstrap initialization ... ok
Sync to disk skipped.
The data directory might become corrupt if the operating system crashes.
Success. You can now start the database server using:
pg_ctl -D c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_subscriber_data/pgdata -l logfile start
# Running: c:/prog/bf/root/HEAD/pgsql.build/Release/pg_regress/pg_regress --config-auth c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_subscriber_data/pgdata
### Starting node "subscriber"
# Running: pg_ctl -D c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_subscriber_data/pgdata -l c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/log/001_rep_changes_subscriber.log start
waiting for server to start.... done
server started
# Postmaster PID for node "subscriber" is 12948
#### Begin standard error
psql:<stdin>:1: NOTICE: created replication slot "tap_sub" on publisher
#### End standard error
ok 1 - check non-replicated table is empty on subscriber
ok 2 - check initial data was copied to subscriber
ok 3 - check replicated inserts on subscriber
ok 4 - check replicated changes on subscriber
ok 5 - check replicated changes with different column order
ok 6 - update works with REPLICA IDENTITY FULL and duplicate tuples
ok 7 - update works with REPLICA IDENTITY FULL and text datums
ok 8 - check replicated inserts after subscription publication change
ok 9 - check changes skipped after subscription publication change
ok 10 - check replicated deletes after alter publication
ok 11 - check replicated insert after alter publication
#### Begin standard error
psql:<stdin>:1: NOTICE: dropped replication slot "tap_sub" on publisher
#### End standard error
ok 12 - check subscription was dropped on subscriber
ok 13 - check replication slot was dropped on publisher
ok 14 - check subscription relation status was dropped on subscriber
ok 15 - check replication slot was dropped on publisher
ok 16 - check replication origin was dropped on subscriber
### Stopping node "subscriber" using mode fast
# Running: pg_ctl -D c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_subscriber_data/pgdata -m fast stop
waiting for server to shut down....pg_ctl: could not open PID file "c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_subscriber_data/pgdata/postmaster.pid": Permission denied
Bail out! system pg_ctl failed
### Stopping node "publisher" using mode immediate
# Running: pg_ctl -D c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_publisher_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "publisher"
### Stopping node "subscriber" using mode immediate
# Running: pg_ctl -D c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_subscriber_data/pgdata -m immediate stop
pg_ctl: PID file "c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_subscriber_data/pgdata/postmaster.pid" does not exist
Is server running?
Bail out! system pg_ctl failed
