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:
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:
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:
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:
StartTransactionCommand
2012-04-18 00:06:27.452 EDT|postgres|mcp_production|STATEMENT: SELECT id
FROM greetings WHERE user_id=284 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:
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:
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=4626 socket=8
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:
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:
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:
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, 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 sameThat 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?
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).
regards, tom lane
Thanks for the response and insight!