On Tue, 15 Jan 2013, Andres Freund wrote:
Any chance you could run make check again but with log_statement=all and
log_min_messages=debug2? That might tell us a bit more, whether the
dependency code doesn't work right or whether the checkpoint is doing
strange things.
Here it is :
2013-01-15 23:06:18 MSK [50f5a8aa.1162:1] DEBUG: SlruScanDirectory invoking
callback on pg_notify/0000
2013-01-15 23:06:18 MSK [50f5a8aa.1162:2] DEBUG: removing file "pg_notify/0000"
2013-01-15 23:06:18 MSK [50f5a8aa.1162:3] DEBUG: max_safe_fds = 985,
usable_fds = 1000, already_open = 5
2013-01-15 23:06:18 MSK [50f5a8aa.1167:1] LOG: database system was shut down
at 2013-01-15 23:06:18 MSK
2013-01-15 23:06:18 MSK [50f5a8aa.1167:2] DEBUG: checkpoint record is at
0/17700E0
2013-01-15 23:06:18 MSK [50f5a8aa.1167:3] DEBUG: redo record is at 0/17700E0;
shutdown TRUE
2013-01-15 23:06:18 MSK [50f5a8aa.1167:4] DEBUG: next transaction ID: 0/686;
next OID: 12031
2013-01-15 23:06:18 MSK [50f5a8aa.1167:5] DEBUG: next MultiXactId: 1; next
MultiXactOffset: 0
2013-01-15 23:06:18 MSK [50f5a8aa.1167:6] DEBUG: oldest unfrozen transaction
ID: 676, in database 1
2013-01-15 23:06:18 MSK [50f5a8aa.1167:7] DEBUG: transaction ID wrap limit is
2147484323, limited by database with OID 1
2013-01-15 23:06:18 MSK [50f5a8aa.1168:1] DEBUG: checkpointer updated shared
memory configuration values
2013-01-15 23:06:18 MSK [50f5a8aa.116b:1] LOG: autovacuum launcher started
2013-01-15 23:06:18 MSK [50f5a8aa.1162:4] LOG: database system is ready to
accept connections
2013-01-15 23:06:19 MSK [50f5a8aa.1162:5] DEBUG: forked new backend, pid=4463
socket=8
2013-01-15 23:06:19 MSK [50f5a8aa.1162:6] DEBUG: server process (PID 4463)
exited with exit code 0
2013-01-15 23:06:19 MSK [50f5a8aa.1162:7] DEBUG: forked new backend, pid=4465
socket=8
2013-01-15 23:06:19 MSK [50f5a8ab.1171:1] LOG: statement: CREATE DATABASE
"regression" TEMPLATE=template0
2013-01-15 23:06:19 MSK [50f5a8aa.1168:2] LOG: checkpoint starting: immediate
force wait
2013-01-15 23:06:19 MSK [50f5a8aa.1168:3] DEBUG: SlruScanDirectory invoking
callback on pg_multixact/offsets/0000
2013-01-15 23:06:19 MSK [50f5a8aa.1168:4] DEBUG: SlruScanDirectory invoking
callback on pg_multixact/members/0000
2013-01-15 23:06:19 MSK [50f5a8aa.1168:5] DEBUG: attempting to remove WAL
segments older than log file 000000000000000000000000
2013-01-15 23:06:19 MSK [50f5a8aa.1168:6] DEBUG: SlruScanDirectory invoking
callback on pg_subtrans/0000
2013-01-15 23:06:19 MSK [50f5a8aa.1168:7] LOG: checkpoint complete: wrote 3
buffers (0.0%); 0 transaction log file(s) added, 0 removed, 0 recycled;
write=0.001 s, sync=0.000 s, total=0.001 s; sync files=0, longest=0.000 s,
average=0.000 s
2013-01-15 23:06:19 MSK [50f5a8aa.1168:8] LOG: checkpoint starting: immediate
force wait
2013-01-15 23:06:19 MSK [50f5a8aa.1168:9] DEBUG: attempting to remove WAL
segments older than log file 000000000000000000000000
2013-01-15 23:06:19 MSK [50f5a8aa.1168:10] DEBUG: SlruScanDirectory invoking
callback on pg_subtrans/0000
2013-01-15 23:06:19 MSK [50f5a8aa.1168:11] LOG: checkpoint complete: wrote 0
buffers (0.0%); 0 transaction log file(s) added, 0 removed, 0 recycled;
write=0.001 s, sync=0.000 s, total=0.001 s; sync files=0, longest=0.000 s,
average=0.000 s
2013-01-15 23:06:19 MSK [50f5a8aa.1162:8] DEBUG: server process (PID 4465)
exited with exit code 0
2013-01-15 23:06:19 MSK [50f5a8aa.1162:9] DEBUG: forked new backend, pid=4467
socket=8
2013-01-15 23:06:19 MSK [50f5a8ab.1173:1] LOG: statement: ALTER DATABASE "regression" SET lc_messages TO 'C';ALTER
DATABASE "regression" SET lc_monetary TO 'C';ALTER DATABASE "regression" SET lc_numeric TO 'C';ALTER DATABASE
"regression" SET lc_time TO 'C';ALTER DATABASE "regression" SET timezone_abbreviations TO 'Default';
2013-01-15 23:06:19 MSK [50f5a8aa.1162:10] DEBUG: server process (PID 4467)
exited with exit code 0
2013-01-15 23:06:19 MSK [50f5a8aa.1162:11] DEBUG: forked new backend, pid=4469
socket=8
2013-01-15 23:06:19 MSK [50f5a8ab.1175:1] LOG: statement: CREATE TABLESPACE
testspace LOCATION '/home/math/pg_git/src/test/regress/testtablespace';
2013-01-15 23:06:19 MSK [50f5a8ab.1175:2] LOG: statement: ALTER TABLESPACE
testspace SET (random_page_cost = 1.0);
2013-01-15 23:06:19 MSK [50f5a8ab.1175:3] LOG: statement: ALTER TABLESPACE
testspace SET (some_nonexistent_parameter = true);
2013-01-15 23:06:19 MSK [50f5a8ab.1175:4] ERROR: unrecognized parameter
"some_nonexistent_parameter"
2013-01-15 23:06:19 MSK [50f5a8ab.1175:5] STATEMENT: ALTER TABLESPACE
testspace SET (some_nonexistent_parameter = true);
2013-01-15 23:06:19 MSK [50f5a8ab.1175:6] LOG: statement: ALTER TABLESPACE
testspace RESET (random_page_cost = 2.0);
2013-01-15 23:06:19 MSK [50f5a8ab.1175:7] ERROR: RESET must not include values
for parameters
2013-01-15 23:06:19 MSK [50f5a8ab.1175:8] STATEMENT: ALTER TABLESPACE
testspace RESET (random_page_cost = 2.0);
2013-01-15 23:06:19 MSK [50f5a8ab.1175:9] LOG: statement: ALTER TABLESPACE
testspace RESET (random_page_cost, seq_page_cost);
2013-01-15 23:06:19 MSK [50f5a8ab.1175:10] LOG: statement: CREATE SCHEMA
testschema;
2013-01-15 23:06:19 MSK [50f5a8ab.1175:11] LOG: statement: CREATE TABLE
testschema.foo (i int) TABLESPACE testspace;
2013-01-15 23:06:19 MSK [50f5a8ab.1175:12] LOG: statement: SELECT relname,
spcname FROM pg_catalog.pg_tablespace t, pg_catalog.pg_class c
where c.reltablespace = t.oid AND c.relname = 'foo';
2013-01-15 23:06:19 MSK [50f5a8ab.1175:13] LOG: statement: INSERT INTO
testschema.foo VALUES(1);
2013-01-15 23:06:19 MSK [50f5a8ab.1175:14] LOG: statement: INSERT INTO
testschema.foo VALUES(2);
2013-01-15 23:06:19 MSK [50f5a8ab.1175:15] LOG: statement: CREATE TABLE
testschema.asselect TABLESPACE testspace AS SELECT 1;
2013-01-15 23:06:19 MSK [50f5a8ab.1175:16] LOG: statement: SELECT relname,
spcname FROM pg_catalog.pg_tablespace t, pg_catalog.pg_class c
where c.reltablespace = t.oid AND c.relname = 'asselect';
2013-01-15 23:06:19 MSK [50f5a8ab.1175:17] LOG: statement: PREPARE
selectsource(int) AS SELECT $1;
2013-01-15 23:06:19 MSK [50f5a8ab.1175:18] LOG: statement: CREATE TABLE
testschema.asexecute TABLESPACE testspace
AS EXECUTE selectsource(2);
2013-01-15 23:06:19 MSK [50f5a8ab.1175:19] LOG: statement: SELECT relname,
spcname FROM pg_catalog.pg_tablespace t, pg_catalog.pg_class c
where c.reltablespace = t.oid AND c.relname = 'asexecute';
2013-01-15 23:06:19 MSK [50f5a8ab.1175:20] LOG: statement: CREATE INDEX
foo_idx on testschema.foo(i) TABLESPACE testspace;
2013-01-15 23:06:19 MSK [50f5a8ab.1175:21] DEBUG: building index "foo_idx" on table
"foo"
2013-01-15 23:06:19 MSK [50f5a8ab.1175:22] LOG: statement: SELECT relname,
spcname FROM pg_catalog.pg_tablespace t, pg_catalog.pg_class c
where c.reltablespace = t.oid AND c.relname = 'foo_idx';
2013-01-15 23:06:19 MSK [50f5a8ab.1175:23] LOG: statement: CREATE TABLE
testschema.atable AS VALUES (1), (2);
2013-01-15 23:06:19 MSK [50f5a8ab.1175:24] LOG: statement: CREATE UNIQUE INDEX
anindex ON testschema.atable(column1);
2013-01-15 23:06:19 MSK [50f5a8ab.1175:25] DEBUG: building index "anindex" on table
"atable"
2013-01-15 23:06:19 MSK [50f5a8ab.1175:26] LOG: statement: ALTER TABLE
testschema.atable SET TABLESPACE testspace;
2013-01-15 23:06:19 MSK [50f5a8ab.1175:27] LOG: statement: ALTER INDEX
testschema.anindex SET TABLESPACE testspace;
2013-01-15 23:06:19 MSK [50f5a8ab.1175:28] LOG: statement: INSERT INTO
testschema.atable VALUES(3);
2013-01-15 23:06:19 MSK [50f5a8ab.1175:29] LOG: statement: INSERT INTO
testschema.atable VALUES(1);
2013-01-15 23:06:19 MSK [50f5a8ab.1175:30] ERROR: duplicate key value violates unique
constraint "anindex"
2013-01-15 23:06:19 MSK [50f5a8ab.1175:31] DETAIL: Key (column1)=(1) already
exists.
2013-01-15 23:06:19 MSK [50f5a8ab.1175:32] STATEMENT: INSERT INTO
testschema.atable VALUES(1);
2013-01-15 23:06:19 MSK [50f5a8ab.1175:33] LOG: statement: SELECT COUNT(*)
FROM testschema.atable;
2013-01-15 23:06:19 MSK [50f5a8ab.1175:34] LOG: statement: CREATE TABLESPACE
badspace LOCATION '/no/such/location';
2013-01-15 23:06:19 MSK [50f5a8ab.1175:35] ERROR: directory
"/no/such/location" does not exist
2013-01-15 23:06:19 MSK [50f5a8ab.1175:36] STATEMENT: CREATE TABLESPACE
badspace LOCATION '/no/such/location';
2013-01-15 23:06:19 MSK [50f5a8ab.1175:37] LOG: statement: CREATE TABLE bar (i
int) TABLESPACE nosuchspace;
2013-01-15 23:06:19 MSK [50f5a8ab.1175:38] ERROR: tablespace "nosuchspace"
does not exist
2013-01-15 23:06:19 MSK [50f5a8ab.1175:39] STATEMENT: CREATE TABLE bar (i int)
TABLESPACE nosuchspace;
2013-01-15 23:06:19 MSK [50f5a8ab.1175:40] LOG: statement: DROP TABLESPACE
testspace;
2013-01-15 23:06:19 MSK [50f5a8aa.1168:12] LOG: checkpoint starting: immediate
force wait
2013-01-15 23:06:19 MSK [50f5a8aa.1168:13] DEBUG: attempting to remove WAL
segments older than log file 000000000000000000000000
2013-01-15 23:06:19 MSK [50f5a8aa.1168:14] DEBUG: SlruScanDirectory invoking
callback on pg_subtrans/0000
2013-01-15 23:06:19 MSK [50f5a8aa.1168:15] LOG: checkpoint complete: wrote 37
buffers (0.2%); 0 transaction log file(s) added, 0 removed, 0 recycled;
write=0.000 s, sync=0.000 s, total=0.001 s; sync files=0, longest=0.000 s,
average=0.000 s
2013-01-15 23:06:19 MSK [50f5a8ab.1175:41] ERROR: tablespace "testspace" is
not empty
2013-01-15 23:06:19 MSK [50f5a8ab.1175:42] STATEMENT: DROP TABLESPACE
testspace;
2013-01-15 23:06:19 MSK [50f5a8ab.1175:43] LOG: statement: DROP SCHEMA
testschema CASCADE;
2013-01-15 23:06:19 MSK [50f5a8ab.1175:44] DEBUG: drop auto-cascades to index
testschema.foo_idx
2013-01-15 23:06:19 MSK [50f5a8ab.1175:45] DEBUG: drop auto-cascades to type
testschema.foo
2013-01-15 23:06:19 MSK [50f5a8ab.1175:46] DEBUG: drop auto-cascades to type
testschema.foo[]
2013-01-15 23:06:19 MSK [50f5a8ab.1175:47] DEBUG: drop auto-cascades to type
testschema.asselect
2013-01-15 23:06:19 MSK [50f5a8ab.1175:48] DEBUG: drop auto-cascades to type
testschema.asselect[]
2013-01-15 23:06:19 MSK [50f5a8ab.1175:49] DEBUG: drop auto-cascades to type
testschema.asexecute
2013-01-15 23:06:19 MSK [50f5a8ab.1175:50] DEBUG: drop auto-cascades to type
testschema.asexecute[]
2013-01-15 23:06:19 MSK [50f5a8ab.1175:51] DEBUG: drop auto-cascades to index
testschema.anindex
2013-01-15 23:06:19 MSK [50f5a8ab.1175:52] DEBUG: drop auto-cascades to type
testschema.atable
2013-01-15 23:06:19 MSK [50f5a8ab.1175:53] DEBUG: drop auto-cascades to type
testschema.atable[]
2013-01-15 23:06:19 MSK [50f5a8ab.1175:54] NOTICE: drop cascades to 4 other
objects
2013-01-15 23:06:19 MSK [50f5a8ab.1175:55] DETAIL: drop cascades to table
testschema.foo
drop cascades to table testschema.asselect
drop cascades to table testschema.asexecute
drop cascades to table testschema.atable
2013-01-15 23:06:19 MSK [50f5a8ab.1175:56] LOG: statement: DROP TABLESPACE
testspace;
2013-01-15 23:06:19 MSK [50f5a8aa.1168:16] LOG: checkpoint starting: immediate
force wait
2013-01-15 23:06:19 MSK [50f5a8aa.1168:17] DEBUG: attempting to remove WAL
segments older than log file 000000000000000000000000
2013-01-15 23:06:19 MSK [50f5a8aa.1168:18] DEBUG: SlruScanDirectory invoking
callback on pg_subtrans/0000
2013-01-15 23:06:19 MSK [50f5a8aa.1168:19] LOG: checkpoint complete: wrote 9
buffers (0.1%); 0 transaction log file(s) added, 0 removed, 0 recycled;
write=0.000 s, sync=0.000 s, total=0.000 s; sync files=0, longest=0.000 s,
average=0.000 s
2013-01-15 23:06:19 MSK [50f5a8ab.1175:57] ERROR: tablespace "testspace" is
not empty
2013-01-15 23:06:19 MSK [50f5a8ab.1175:58] STATEMENT: DROP TABLESPACE
testspace;
2013-01-15 23:06:19 MSK [50f5a8aa.1162:12] DEBUG: server process (PID 4469)
exited with exit code 0
Cheers,
S
*****************************************************
Sergey E. Koposov, PhD, Research Associate
Institute of Astronomy, University of Cambridge
Madingley road, CB3 0HA, Cambridge, UK
Tel: +44-1223-337-551 Web: http://www.ast.cam.ac.uk/~koposov/
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
