Strange error: OCIError: ORA-01008: not all variables bound

[net1957]

Steps to reproduce

first request after application start or restart.

Expected behavior

After migrating the application from Rails 6.1 to 7 I get this error

Actual behavior

The application use a legacy DB, so Arel is used most time to do complex SQL queries.
If the first query after start is a query with UNION ALL, this query fail. If before that you run a simpler one, all is working as expected.

example of query (use ArelHelpers::QueryBuilder):

    def cdpcomponents(neturef = nil, nveretu = nil, start_datetime = nil, include_transferred = nil, nhut = nil)
      left_query = cdp_components1(neturef, nveretu, start_datetime, include_transferred, nhut)
      right_query = cdp_components2(neturef, nveretu, start_datetime, include_transferred, nhut)
      # crete a new relation
      ::Cmdmary::Etudprix.all.select(Arel.star)
                         .from("(#{left_query.query.to_sql} UNION ALL #{right_query.query.to_sql})")
                         .order('nhut, cmat')
    end

it fail with:

OCIError: ORA-01008: not all variables bound
Array (163 elements)
stmt.c:265:in oci8lib_300.so
D:/program/dvlt/ruby/Ruby30-x64/lib/ruby/gems/3.0.0/gems/ruby-oci8-2.2.11-x64-mingw32/lib/oci8/cursor.rb:131:in `exec'
D:/program/dvlt/ruby/Ruby30-x64/lib/ruby/gems/3.0.0/gems/activerecord-oracle_enhanced-adapter-7.0.2/lib/active_record/connection_adapters/oracle_enhanced/oci_connection.rb:146:in `exec'
D:/program/dvlt/ruby/Ruby30-x64/lib/ruby/gems/3.0.0/gems/activerecord-oracle_enhanced-adapter-7.0.2/lib/active_record/connection_adapters/oracle_enhanced/database_statements.rb:41:in `block (2 levels) in exec_query'
D:/program/dvlt/ruby/Ruby30-x64/lib/ruby/gems/3.0.0/gems/activerecord-oracle_enhanced-adapter-7.0.2/lib/active_record/connection_adapters/oracle_enhanced/database_statements.rb:276:in `block in with_retry'
D:/program/dvlt/ruby/Ruby30-x64/lib/ruby/gems/3.0.0/gems/activerecord-oracle_enhanced-adapter-7.0.2/lib/active_record/connection_adapters/oracle_enhanced/oci_connection.rb:433:in `with_retry'
D:/program/dvlt/ruby/Ruby30-x64/lib/ruby/gems/3.0.0/gems/activerecord-oracle_enhanced-adapter-7.0.2/lib/active_record/connection_adapters/oracle_enhanced/oci_connection.rb:101:in `with_retry'
D:/program/dvlt/ruby/Ruby30-x64/lib/ruby/gems/3.0.0/gems/activerecord-oracle_enhanced-adapter-7.0.2/lib/active_record/connection_adapters/oracle_enhanced/database_statements.rb:275:in `with_retry'
D:/program/dvlt/ruby/Ruby30-x64/lib/ruby/gems/3.0.0/gems/activerecord-oracle_enhanced-adapter-7.0.2/lib/active_record/connection_adapters/oracle_enhanced/database_statements.rb:26:in `block in exec_query'

During debuging, the 'left_query.query.to_sql' generate this error and the SQL string in the error is:

SELECT /*+ OPTIMIZER_FEATURES_ENABLE('11.2.0.2') */ cols.column_name AS name,
 cols.data_type AS sql_type,
 cols.data_default,
 cols.nullable,
 cols.virtual_column,
 cols.hidden_column,
 cols.data_type_owner AS sql_type_owner,
 DECODE(cols.data_type, 'NUMBER', data_precision, 'FLOAT', data_precision, 'VARCHAR2', DECODE(char_used, 'C', char_length, data_length), 'RAW', DECODE(char_used, 'C', char_length, data_length), 'CHAR', DECODE(char_used, 'C', char_length, data_length), NULL) AS limit,
 DECODE(data_type, 'NUMBER', data_scale, NULL) AS scale,
 comments.comments as column_comment
 FROM all_tab_cols cols,
 all_col_comments comments
 WHERE cols.owner = :owner
 AND cols.table_name = :table_name
 AND cols.hidden_column = 'NO' 
 AND cols.owner = comments.owner 
 AND cols.table_name = comments.table_name 
 AND cols.column_name = comments.column_name
 ORDER BY cols.column_id

and the binds Array is correctly populated.

The log contain

Cmdmary::Etudprix Load (2.4ms)  SELECT "ETUDPRIX".* FROM "ETUDPRIX" WHERE ROWNUM <= :a1 /* loading for inspect */   [["LIMIT", 11]]
  ↳ (eval):5:in `block in print_variable'

repeated 4 or more time.

The strangest thing:
With rubymine if I put a breakpoint on the ::Cmdmary::Etudprix.all.select(Arel.star) .... line,

• left_query.query.to_sql fail with the error but
• left_query.query don't fail and after that
• left_query.query.to_sql return the correct sql! and the application work correctly until restart

If the first DB request is a more simpler SQL it also work and the fulll application is working as expected.

** the request use a connection to a shard (implemented wit a around_action block)

If i revert back to

rails (6.1.4.4)
activerecord-oracle_enhanced-adapter (6.1.5)
composite_primary_keys (13.0.3)
ruby-oci8 (2.2.10)

it's working.

I don't known how to continue to try to resolve this, so I request some help about this problem.

System configuration

Rails version: rails 7.0.2.3

Oracle enhanced adapter version: 7.0.2

Ruby version: ruby 3.0.3

Oracle Database version: oracle 10.2.0.1.0, instanclient 10.2.0.1
** and arel-helpers (2.14.0), composite_primary_keys (14.0.4)

[ioev]

I just encountered the same problem, rails 7.0.2.3, ruby 3.10, when trying to use the deep_pluck/pluck_all gems. It was doing a query that looks like: User.where(nil).select(:id).to_sql

I was able to reproduce easily with a base project from rails new oracle_test, adding the rails 7 compatible oracle adapter, creating a single User model and then running:
User.select(:id).to_sql

It's almost as if it fails until the schema is loaded for the table (or the schema query IS the problem, as net1957 noted), because after running something simple like User.first, then the previous query will work.

[net1957]

In my case, I resolved it by replacing
.from("(#{left_query.query.to_sql} UNION ALL #{right_query.query.to_sql})")
with
.from(Arel::Nodes::UnionAll.new(left_query.query.arel, right_query.query.arel))

I imagine that Arel do correctly load the schema

found some nice examples at https://martinskruze.com/does_arel_work_in_rails_7

    def cdpcomponents(neturef = nil, nveretu = nil, start_datetime = nil, include_transferred = nil, nhut = nil)
      left_query = cdp_components1(neturef, nveretu, start_datetime, include_transferred, nhut)
      right_query = cdp_components2(neturef, nveretu, start_datetime, include_transferred, nhut)
      # create a new relation
      ::Cmdmary::Etudprix.all.select(Arel.star)
                         .from(Arel::Nodes::UnionAll.new(left_query.query.arel, right_query.query.arel))
                         .order('nhut, cmat')
    end

[ioev]

I traced this problem a little deeper, and it seems like it could be considered a bug in ActiveRecord:

When you call something like User.select(:id).to_sql, you end up through:

activerecord-7.0.4.3/lib/active_record/relation.rb:724

def to_sql
  @to_sql ||= if eager_loading?
    apply_join_dependency do |relation, join_dependency|
      relation = join_dependency.apply_column_aliases(relation)
      relation.to_sql
    end
  else
    conn = klass.connection
    conn.unprepared_statement { conn.to_sql(arel) } # <-- HERE
  end
end

This wraps the connection in a block via unprepared_statement:

activerecord-7.0.4.3/lib/active_record/connection_adapters/abstract_adapter.rb:284

def unprepared_statement
  cache = prepared_statements_disabled_cache.add?(object_id) if @prepared_statements
  yield
ensure
  cache&.delete(object_id)
end

And then this bit of code executes within this block:

activerecord-oracle_enhanced-adapter-7.0.2/lib/active_record/connection_adapters/oracle_enhanced/database_statements.rb:26

with_retry do
  if without_prepared_statement?(binds)
    cursor = @connection.prepare(sql)
  else
    unless @statements.key? sql
      @statements[sql] = @connection.prepare(sql)
    end

    cursor = @statements[sql]

    cursor.bind_params(type_casted_binds)

    cached = true
  end

  byebug
  cursor.exec
end

Because the way the code is structured, the schema loading code that must run is captured inside of this "no prepared statements" block, and causes the line if without_prepared_statement?(binds) to return true, and the schema query running in this same context is prepared without binds and fails.

[ioev]

I was surprised to find that there already exists a cache busting method in the schema loading code: select_values_forcing_binds(arel, name, binds).

A fix for this (in our case) was to just add one for select_all as well:

module ActiveRecord
  module ConnectionAdapters
    class OracleEnhancedAdapter
      def column_definitions(table_name)
        (owner, desc_table_name) = @connection.describe(table_name)

        select_all_forcing_binds(<<~SQL.squish, "SCHEMA", [bind_string("owner", owner), bind_string("table_name", desc_table_name)])
          SELECT /*+ OPTIMIZER_FEATURES_ENABLE('11.2.0.2') */ cols.column_name AS name, cols.data_type AS sql_type,
                 cols.data_default, cols.nullable, cols.virtual_column, cols.hidden_column,
                 cols.data_type_owner AS sql_type_owner,
                 DECODE(cols.data_type, 'NUMBER', data_precision,
                                   'FLOAT', data_precision,
                                   'VARCHAR2', DECODE(char_used, 'C', char_length, data_length),
                                   'RAW', DECODE(char_used, 'C', char_length, data_length),
                                   'CHAR', DECODE(char_used, 'C', char_length, data_length),
                                    NULL) AS limit,
                 DECODE(data_type, 'NUMBER', data_scale, NULL) AS scale,
                 comments.comments as column_comment
            FROM all_tab_cols cols, all_col_comments comments
           WHERE cols.owner      = :owner
             AND cols.table_name = :table_name
             AND cols.hidden_column = 'NO'
             AND cols.owner = comments.owner
             AND cols.table_name = comments.table_name
             AND cols.column_name = comments.column_name
           ORDER BY cols.column_id
        SQL
      end

      def select_all_forcing_binds(arel, name, binds)
        deleted_object_id = prepared_statements_disabled_cache.delete(object_id)
        select_all(arel, name, binds)
      ensure
        prepared_statements_disabled_cache.add(deleted_object_id) if deleted_object_id
      end
    end
  end
end

[davue]

We fixed it using this monkey patch:

module ArelSqlPatch
  def to_sql
    arel # <= This is the workaround, we prebuild arel before using it in unprepared_statement
    super
  end
end

ActiveRecord::Relation.prepend ArelSqlPatch

arel would have been called anyways later on and is cached in @arel so there is no performance loss.

[akostadinov]

@ioev , great find! It fixes the issue that I see. Maybe file a pull request?

I actually simplified a little bit the monkey patch to avoid pasting the whole method. But in a PR of course should be done as in the original comment.

    module OracleEnhancedAdapterSchemaIssue2276
      def column_definitions(table_name)
        deleted_object_id = prepared_statements_disabled_cache.delete(object_id)
        super
      ensure
        prepared_statements_disabled_cache.add(deleted_object_id) if deleted_object_id
      end
    end

    ActiveRecord::ConnectionAdapters::OracleEnhancedAdapter.prepend OracleEnhancedAdapterSchemaIssue2276

@davue , FYI your workaround doesn't seem to work here.