{"action":"created","issue":{"url":"https://api.github.com/repos/rails/rails/issues/12330","repository_url":"https://api.github.com/repos/rails/rails","labels_url":"https://api.github.com/repos/rails/rails/issues/12330/labels{/name}","comments_url":"https://api.github.com/repos/rails/rails/issues/12330/comments","events_url":"https://api.github.com/repos/rails/rails/issues/12330/events","html_url":"https://github.com/rails/rails/issues/12330","id":19951856,"number":12330,"title":"PostgreSQL prepared statement failure inside transaction results in a permanently cached prepared statement that's never cleaned up.","user":{"login":"nixme","id":4344,"avatar_url":"https://avatars.githubusercontent.com/u/4344?v=3","gravatar_id":"","url":"https://api.github.com/users/nixme","html_url":"https://github.com/nixme","followers_url":"https://api.github.com/users/nixme/followers","following_url":"https://api.github.com/users/nixme/following{/other_user}","gists_url":"https://api.github.com/users/nixme/gists{/gist_id}","starred_url":"https://api.github.com/users/nixme/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/nixme/subscriptions","organizations_url":"https://api.github.com/users/nixme/orgs","repos_url":"https://api.github.com/users/nixme/repos","events_url":"https://api.github.com/users/nixme/events{/privacy}","received_events_url":"https://api.github.com/users/nixme/received_events","type":"User","site_admin":false},"labels":[{"url":"https://api.github.com/repos/rails/rails/labels/activerecord","name":"activerecord","color":"0b02e1"},{"url":"https://api.github.com/repos/rails/rails/labels/PostgreSQL","name":"PostgreSQL","color":"fbca04"}],"state":"closed","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":65,"created_at":"2013-09-24T01:30:12Z","updated_at":"2016-09-06T12:10:39Z","closed_at":"2016-04-27T23:00:53Z","body":"*ActiveRecord 4.0. Verified with PostgreSQL 9.2 and 9.3 and pg gem 0.16 and 0.17*\r\n\r\nAssume you have some basic table, `User` for this example's purposes.\r\n\r\nIn a Rails console:\r\n\r\n```ruby\r\nUser.find(1)\r\n=> .....\r\n```\r\n\r\nAt this point, the PostgreSQL adapter has created a prepared statement for selecting a User by ID and cached it in the connection. To verify:\r\n\r\n```ruby\r\nActiveRecord::Base.connection.instance_variable_get(:@statements).to_a\r\n=> [\r\n  [0] [\r\n    [0] \"\\\"$user\\\",public-SELECT  \\\"users\\\".* FROM \\\"users\\\"  WHERE \\\"users\\\".\\\"id\\\" = $1 LIMIT 1\",\r\n    [1] \"a1\"\r\n  ]\r\n]\r\n```\r\n\r\nNow from a separate session, let's modify the schema for the User table. The use case here is adding a column to a live system without causing downtime to users:\r\n\r\n```sql\r\nALTER TABLE users ADD new_metric_column integer;\r\n```\r\n\r\nBack in the previous Rails console, we then run this:\r\n\r\n```ruby\r\nUser.transaction { User.find(1) }\r\n=> [2013-09-23 17:53:03] DEBUG ActiveRecord::Base        :    (0.2ms)  BEGIN\r\n[2013-09-23 17:53:03] DEBUG ActiveRecord::Base        :   User Load (0.6ms)  SELECT \"users\".* FROM \"users\" WHERE \"users\".\"id\" = $1 LIMIT 1  [[\"id\", 1]]\r\n[2013-09-23 17:53:03] ERROR ActiveRecord::Base        : PG::InFailedSqlTransaction: ERROR:  current transaction is aborted, commands ignored until end of transaction block\r\n: SELECT  \"users\".* FROM \"users\"  WHERE \"users\".\"id\" = $1 LIMIT 1\r\n[2013-09-23 17:53:03] DEBUG ActiveRecord::Base        :    (0.5ms)  ROLLBACK\r\nActiveRecord::StatementInvalid: PG::InFailedSqlTransaction: ERROR:  current transaction is aborted, commands ignored until end of transaction block\r\n: SELECT  \"users\".* FROM \"users\"  WHERE \"users\".\"id\" = $1 LIMIT 1\r\nfrom /Users/nixme/Projects/ML/flabongo/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.0/lib/active_record/connection_adapters/postgresql_adapter.rb:512:in `exec'\r\n```\r\n\r\nWhat's happening is that since the shape of users has changed, the `a1` prepared statement is no longer valid. The AR PostgreSQL adapter correctly sees this and tries to run `DEALLOCATE a1`. But the transaction's already invalid at that point, and so even the `DEALLOCATE` fails, leaving that connection's `@statements` pool with a permanently bad prepared statement. \r\n\r\nFor reference, on the PostgreSQL side, the logs show:\r\n\r\n```\r\nERROR:  cached plan must not change result type\r\nSTATEMENT:  SELECT  \"users\".* FROM \"users\"  WHERE \"users\".\"id\" = $1 LIMIT 1\r\nERROR:  current transaction is aborted, commands ignored until end of transaction block\r\nSTATEMENT:  DEALLOCATE a1\r\n```\r\n\r\nNow that might seem like an arbitrary transaction, but all AR `save`s wrap in a transactions, so a validation or callback might be selecting a User. Imagine in a production system, all old app servers are now permanently broken without a restart. This makes live migrations without downtime basically impossible, unless I'm missing something.\r\n\r\nI think ideally, the transaction is aborted, then `DEALLOCATE` is run *outside* a transaction and thus successfully removes that prepared statement for the connection. Then the original transaction is retried automatically and the necessary prepared statements are re-created automatically.\r\n\r\nAnother option is just to blow up this one transaction, but at the very least get that DEALLOCATE to succeed. So that any follow-up transactions will work and fail the least number of requests.\r\n\r\nFor now, we've disabled prepared_statements after monkey-patching some fixes from 4-0-STABLE (see #12023)\r\n\r\n/cc @tenderlove since I *think* you've done some of the PG prepared statement support?"},"comment":{"url":"https://api.github.com/repos/rails/rails/issues/comments/244930976","html_url":"https://github.com/rails/rails/issues/12330#issuecomment-244930976","issue_url":"https://api.github.com/repos/rails/rails/issues/12330","id":244930976,"user":{"login":"henrik","id":216,"avatar_url":"https://avatars.githubusercontent.com/u/216?v=3","gravatar_id":"","url":"https://api.github.com/users/henrik","html_url":"https://github.com/henrik","followers_url":"https://api.github.com/users/henrik/followers","following_url":"https://api.github.com/users/henrik/following{/other_user}","gists_url":"https://api.github.com/users/henrik/gists{/gist_id}","starred_url":"https://api.github.com/users/henrik/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/henrik/subscriptions","organizations_url":"https://api.github.com/users/henrik/orgs","repos_url":"https://api.github.com/users/henrik/repos","events_url":"https://api.github.com/users/henrik/events{/privacy}","received_events_url":"https://api.github.com/users/henrik/received_events","type":"User","site_admin":false},"created_at":"2016-09-06T12:10:39Z","updated_at":"2016-09-06T12:10:39Z","body":"Thanks for the backport, @HoyaBoya! Took me a while to figure out how to plug it in.\r\n\r\nI ended up sticking this in `config/initializers/rails_recoverable_transactions.rb`:\r\n\r\n``` ruby\r\n# https://github.com/rails/rails/issues/12330#issuecomment-215203613\r\n\r\nmodule TransactionRecoverable\r\n  module ClassMethods\r\n    raise \"We may no longer need the monkeypatch #{__FILE__}!\" if Rails::VERSION::MAJOR > 4\r\n\r\n    def transaction(*args)\r\n      super(*args) do\r\n        yield\r\n      end\r\n    rescue PG::InFailedSqlTransaction => e\r\n      connection.rollback_db_transaction\r\n      connection.clear_cache!\r\n\r\n      super(*args) do\r\n        yield\r\n      end\r\n    end\r\n  end\r\nend\r\n\r\nclass << ActiveRecord::Base\r\n  prepend TransactionRecoverable::ClassMethods\r\nend\r\n```\r\n\r\nIf you want to verify that it's plugged in correctly:\r\n\r\nAdd `puts \"hello\"` on the line before the first `super(*args) do`.\r\n\r\nRun something like this in a console (replacing `Item` with some model in your app):\r\n\r\n    rails runner  'Item.transaction { puts Item.count }'\r\n\r\nMake sure it outputs \"hello\".\r\n\r\nThen make sure to remove your `puts \"hello\"` line again."}}
{"actor":{"display_login":"henrik"}}