DASSL / ClassDB

An open-source system to let students experiment with relational data
https://dassl.github.io/ClassDB/
Other
8 stars 2 forks source link

DDL activity logging inserts a duplicate entry for some ALTER TABLE statments (WE) #264

Open afig opened 6 years ago

afig commented 6 years ago

As stated by Postgres' event trigger firing matrix both ddl_command_end and sql_drop is triggered for ALTER TABLE and ALTER FOREIGN TABLE statements, further analysis shows that sql_drop is only fired for certain drop-related table alterations (ALTER TABLE ... DROP COLUMN..., ALTER TABLE ... DROP CONSTRAINT..., possibly others). Due to how ClassDB processes these events, these drop-related table alterations result in duplicate log entries when ClassDB is run on Postgres versions >9.4 (they are not added for versions below 9.5 because all sql_drop events are ignored in versions <9.5).

Given that other drop events do not result in duplicate entries, it seems that pg_event_trigger_ddl_commands().object_identity is not NULL for any ALTER TABLE / ALTER FOREIGN TABLE events, even if they are drop-related and therefore sql_drop was fired just before.

Here is a sequence of events and SELECTS from myddlactivity that show duplicate entries for the statement ALTER TABLE testtable DROP COLUMN col2; in pg9.6:

classdb=> CREATE TABLE testtable (col1 VARCHAR);
CREATE TABLE
classdb=> SELECT * FROM myddlactivity;
     statementstartedat     |   sessionid   | ddloperation |   ddlobject
----------------------------+---------------+--------------+---------------
 2018-08-15 13:37:10.205201 | 5b7464b8.32b0 | CREATE TABLE | ins.testtable

classdb=> ALTER TABLE testtable ADD COLUMN col2 VARCHAR;
ALTER TABLE
classdb=> SELECT * FROM myddlactivity;
     statementstartedat     |   sessionid   | ddloperation |   ddlobject
----------------------------+---------------+--------------+---------------
 2018-08-15 13:37:32.391041 | 5b7464b8.32b0 | ALTER TABLE  | ins.testtable
 2018-08-15 13:37:10.205201 | 5b7464b8.32b0 | CREATE TABLE | ins.testtable

classdb=> ALTER TABLE testtable DROP COLUMN col2;
ALTER TABLE
classdb=> SELECT * FROM myddlactivity;
     statementstartedat     |   sessionid   | ddloperation |     ddlobject
----------------------------+---------------+--------------+--------------------
 2018-08-15 13:37:46.749256 | 5b7464b8.32b0 | ALTER TABLE  | ins.testtable.col2
 2018-08-15 13:37:46.749256 | 5b7464b8.32b0 | ALTER TABLE  | ins.testtable
 2018-08-15 13:37:32.391041 | 5b7464b8.32b0 | ALTER TABLE  | ins.testtable
 2018-08-15 13:37:10.205201 | 5b7464b8.32b0 | CREATE TABLE | ins.testtable

classdb=> DROP TABLE testtable;
DROP TABLE
classdb=> SELECT * FROM myddlactivity;
     statementstartedat     |   sessionid   | ddloperation |     ddlobject
----------------------------+---------------+--------------+--------------------
 2018-08-15 13:37:56.992294 | 5b7464b8.32b0 | DROP TABLE   | ins.testtable
 2018-08-15 13:37:46.749256 | 5b7464b8.32b0 | ALTER TABLE  | ins.testtable.col2
 2018-08-15 13:37:46.749256 | 5b7464b8.32b0 | ALTER TABLE  | ins.testtable
 2018-08-15 13:37:32.391041 | 5b7464b8.32b0 | ALTER TABLE  | ins.testtable
 2018-08-15 13:37:10.205201 | 5b7464b8.32b0 | CREATE TABLE | ins.testtable