Thread: BUG #6601: Inconsistent behavior of ALTER TABLE ADD COLUMN
The following bug has been logged on the website: Bug reference: 6601 Logged by: jon Email address: jon.plotky@gmail.com PostgreSQL version: 8.4.7 Operating system: RedHat Enterprise Linux 6.2 (Linux version 2.6.32) Description:=20=20=20=20=20=20=20=20 Not sure if this is a bug or not. Would like to know what (if any) behavior is guaranteed about updates to the pg_attribute catalog table. Issue: After adding one new column to each of two different tables, querying pg_attribute shows the new column in one table but not the other. This is a problem for ActiveRecord, which tries to maintain its table model based on querying pg_attribute. Facts: - Behavior is repeatable on different servers/databases - After a commit the pg_attribute table shows the new column in both tables - Postgresql log shows difference after the two ALTER TABLE statements (see below), with a "forked new backend" message always following the ALTER TABLE that does not update pg_attribute. Don't know if this has anything to do with anything, but the log messages are always the same - No difference after adding "nop" ALTER TABLE to cause a "table rewrite" as mentioned at http://www.postgresql.org/docs/8.4/static/sql-altertable.html Postgresql log of ALTER TABLE that immediately updates pg_attribute: 2012-04-18 00:06:27.449 EDT|postgres|mcp_production|DEBUG:=20 StartTransactionCommand 2012-04-18 00:06:27.449 EDT|postgres|mcp_production|STATEMENT: ALTER TABLE "users" ADD COLUMN "fo_mapping_id" integer 2012-04-18 00:06:27.450 EDT|postgres|mcp_production|LOG: statement: ALTER TABLE "users" ADD COLUMN "fo_mapping_id" integer 2012-04-18 00:06:27.450 EDT|postgres|mcp_production|DEBUG: ProcessUtility 2012-04-18 00:06:27.450 EDT|postgres|mcp_production|STATEMENT: ALTER TABLE "users" ADD COLUMN "fo_mapping_id" integer 2012-04-18 00:06:27.450 EDT|postgres|mcp_production|DEBUG:=20 CommitTransactionCommand 2012-04-18 00:06:27.450 EDT|postgres|mcp_production|STATEMENT: ALTER TABLE "users" ADD COLUMN "fo_mapping_id" integer 2012-04-18 00:06:27.452 EDT|postgres|mcp_production|DEBUG:=20 StartTransactionCommand 2012-04-18 00:06:27.452 EDT|postgres|mcp_production|STATEMENT: SELECT id FROM greetings WHERE user_id=3D284 limit 1 Postgresql log of ALTER TABLE that does not update pg_attribute: 2012-04-18 00:06:27.558 EDT|postgres|mcp_production|DEBUG:=20 StartTransactionCommand 2012-04-18 00:06:27.558 EDT|postgres|mcp_production|STATEMENT: ALTER TABLE "organizations" ADD COLUMN "default_foid" integer 2012-04-18 00:06:27.558 EDT|postgres|mcp_production|LOG: statement: ALTER TABLE "organizations" ADD COLUMN "default_foid" integer 2012-04-18 00:06:27.558 EDT|postgres|mcp_production|DEBUG: ProcessUtility 2012-04-18 00:06:27.558 EDT|postgres|mcp_production|STATEMENT: ALTER TABLE "organizations" ADD COLUMN "default_foid" integer 2012-04-18 00:06:27.558 EDT|postgres|mcp_production|DEBUG:=20 CommitTransactionCommand 2012-04-18 00:06:27.558 EDT|postgres|mcp_production|STATEMENT: ALTER TABLE "organizations" ADD COLUMN "default_foid" integer 2012-04-18 00:06:27.580 EDT|||DEBUG: forked new backend, pid=3D4626 socket= =3D8 2012-04-18 00:06:27.580 EDT|postgres|mcp_production|DEBUG: postgres child[4626]: starting with ( 2012-04-18 00:06:27.580 EDT|postgres|mcp_production|DEBUG: postgres 2012-04-18 00:06:27.580 EDT|postgres|mcp_production|DEBUG: -v196608 2012-04-18 00:06:27.580 EDT|postgres|mcp_production|DEBUG: -y 2012-04-18 00:06:27.580 EDT|postgres|mcp_production|DEBUG:=20=20=20=20=20 mcp_production 2012-04-18 00:06:27.580 EDT|postgres|mcp_production|DEBUG: ) 2012-04-18 00:06:27.580 EDT|postgres|mcp_production|DEBUG: InitPostgres 2012-04-18 00:06:27.580 EDT|postgres|mcp_production|DEBUG: my backend id is 49 2012-04-18 00:06:27.581 EDT|postgres|mcp_production|DEBUG:=20 StartTransaction 2012-04-18 00:06:27.581 EDT|postgres|mcp_production|DEBUG: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children: 2012-04-18 00:06:27.582 EDT|postgres|mcp_production|DEBUG:=20 CommitTransaction 2012-04-18 00:06:27.582 EDT|postgres|mcp_production|DEBUG: name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
jon.plotky@gmail.com writes: > Issue: After adding one new column to each of two different tables, querying > pg_attribute shows the new column in one table but not the other. This is a bit hard to believe, and your log extract certainly doesn't provide any evidence to support the statement. Could we see a complete self-contained test case? > - Postgresql log shows difference after the two ALTER TABLE statements (see > below), with a "forked new backend" message always following the ALTER TABLE > that does not update pg_attribute. Don't know if this has anything to do > with anything, but the log messages are always the same That only suggests a new incoming connection, which seems probably unrelated. However, if that new connection is what's going to examine pg_attribute, maybe the issue is that it's looking before the ALTER has committed? regards, tom lane
On Wed, Apr 18, 2012 at 7:44 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote: > > jon.plotky@gmail.com writes: > > Issue: After adding one new column to each of two different tables, que= rying > > pg_attribute shows the new column in one table but not the other. > > This is a bit hard to believe, and your log extract certainly doesn't > provide any evidence to support the statement. =A0Could we see a complete > self-contained test case? > > > - Postgresql log shows difference after the two ALTER TABLE statements = (see > > below), with a "forked new backend" message always following the ALTER = TABLE > > that does not update pg_attribute. Don't know if this has anything to do > > with anything, but the log messages are always the same > > That only suggests a new incoming connection, which seems probably > unrelated. =A0However, if that new connection is what's going to examine > pg_attribute, maybe the issue is that it's looking before the ALTER has > committed? This is what's happening. The stack is Rails, ActiveRecord, connection pooler pgbouncer, and Postgresql. The ActiveRecord class that doesn't see the column update uses a specific connection pool. Unfortunately ActiveRecord uses the default pool connection to alter the table associated with that class, then tries to update the class attributes by querying pg_attribute using the class specific connection pool (generating the new connection in the log). > > =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0regards, tom lane Thanks for the response and insight!