Mysql dapter reporting Duplicate Entry mystery

I have an application (Rails 2.3.10) that is bombing out with the
following message:

A ActiveRecord::StatementInvalid occurred in confirmation#create:

Mysql::Error: Duplicate entry ‘185’ for key 1: INSERT INTO
confirmations (flags, quote_id, created_at, updated_at,
id, serialnum) VALUES(31, 185, ‘2011-04-27 20:32:04’, ‘2011-04-27
20:32:04’, 185, ‘lxpxno20500232dba41601’)
/usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/
connection_adapters/abstract_adapter.rb:227:in `log’

schema.rb shows:
create_table “confirmations”, :force => true do |t|
t.integer “quote_id”
t.integer “flags”
t.datetime “created_at”
t.datetime “updated_at”
t.string “serialnum”
end

add_index “confirmations”, [“quote_id”], :name =>
“index_confirmations_on_quote_id”
add_index “confirmations”, [“serialnum”], :name =>
“index_confirmations_on_serialnum”, :unique => true

the production database is mysql and on interrogation:

mysql> show index from confirmations;
±--------------±-----------±---------------------------------
±-------------±------------±----------±------------±---------
±-------±-----±-----------±--------+
| Table | Non_unique | Key_name |
Seq_in_index | Column_name | Collation | Cardinality | Sub_part |
Packed | Null | Index_type | Comment |
±--------------±-----------±---------------------------------
±-------------±------------±----------±------------±---------
±-------±-----±-----------±--------+
| confirmations | 0 | PRIMARY
| 1 | id | A | 26 | NULL |
NULL | | BTREE | |
| confirmations | 0 | index_confirmations_on_serialnum
| 1 | serialnum | A | 26 | NULL |
NULL | YES | BTREE | |
| confirmations | 1 | index_confirmations_on_quote_id
| 1 | quote_id | A | 26 | NULL |
NULL | YES | BTREE | |
±--------------±-----------±---------------------------------
±-------------±------------±----------±------------±---------
±-------±-----±-----------±--------+
3 rows in set (0.00 sec)

mysql>

Then when I mysqldump the table definition:


– Table structure for table confirmations

CREATE TABLE confirmations (
id int(11) NOT NULL auto_increment,
quote_id int(11) default NULL,
flags int(11) default NULL,
created_at datetime default NULL,
updated_at datetime default NULL,
serialnum varchar(255) collate utf8_unicode_ci default NULL,
PRIMARY KEY (id),
UNIQUE KEY index_confirmations_on_serialnum (serialnum),
KEY index_confirmations_on_quote_id (quote_id)
) ENGINE=InnoDB AUTO_INCREMENT=189 DEFAULT CHARSET=utf8
COLLATE=utf8_unicode_ci;
SET character_set_client = @saved_cs_client;

Then when I go onto the mysql database I can do this:

mysql> insert into confirmations (quote_id) values(188);
Query OK, 1 row affected (0.01 sec)

mysql> select * from confirmations where quote_id = 188;
±----±---------±------±--------------------±--------------------
±----------+
| id | quote_id | flags | created_at | updated_at |
serialnum |
±----±---------±------±--------------------±--------------------
±----------+
| 188 | 188 | 4 | 2011-04-28 10:41:32 | 2011-04-28 10:41:32 |
10195323 |
| 189 | 188 | NULL | NULL | NULL |
NULL |
±----±---------±------±--------------------±--------------------
±----------+
2 rows in set (0.00 sec)

So in some way the mysql adapter is reporting a statement invalid when
it shouldn’t as far as I can tell.

Any ideas on where to start looking would be a great help.

O.

On Apr 28, 12:53pm, Owain [email protected] wrote:

mysql> insert into confirmations (quote_id) values(188);
Query OK, 1 row affected (0.01 sec)

mysql> select * from confirmations where quote_id = 188;

Why are you filtering by quote_id here?

Fred

On Apr 28, 12:57pm, Frederick C. [email protected]
wrote:

mysql> insert into confirmations (quote_id) values(188);
Query OK, 1 row affected (0.01 sec)

mysql> select * from confirmations where quote_id = 188;

Why are you filtering by quote_id here?

Fred,

Just to show that the mysql CLI client allowed me to manually add
another row with the same quote_id of 188. So it is not mysql server
that is reporting the Duplicate Entry/Statement invalid. It is being
reported by the mysql adapter of ActiveRecord.

Here is more of the backtrace which I omitted earlier.

/usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/
connection_adapters/abstract_adapter.rb:227:in log' /usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/ connection_adapters/mysql_adapter.rb:324:in execute’
/usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/
connection_adapters/abstract/database_statements.rb:259:in
insert_sql' /usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/ connection_adapters/mysql_adapter.rb:334:in insert_sql’
/usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/
connection_adapters/abstract/database_statements.rb:44:in
insert_without_query_dirty' /usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/ connection_adapters/abstract/query_cache.rb:19:in insert’
/usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/
base.rb:2961:in create_without_timestamps' /usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/ timestamp.rb:53:in create_without_callbacks’
/usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/
callbacks.rb:266:in create' /usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/ base.rb:2927:in create_or_update_without_callbacks’
/usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/
callbacks.rb:250:in create_or_update' /usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/ base.rb:2577:in save_without_validation’
/usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/
validations.rb:1090:in save_without_dirty' /usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/ dirty.rb:79:in save_without_transactions’
/usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/
transactions.rb:229:in send' /usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/ transactions.rb:229:in with_transaction_returning_status’
/usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/
connection_adapters/abstract/database_statements.rb:136:in
transaction' /usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/ transactions.rb:182:in transaction’
/usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/
transactions.rb:228:in with_transaction_returning_status' /usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/ transactions.rb:196:in save’
/usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/
transactions.rb:208:in rollback_active_record_state!' /usr/lib64/ruby/gems/1.8/gems/activerecord-2.3.10/lib/active_record/ transactions.rb:196:in save’
[RAILS_ROOT]/app/controllers/confirmation_controller.rb:17:in
`create’

The thing is that the SQL being reported looks completely correct and
should not fail.

Any ideas?

O.

On 28 Apr 2011, at 13:13, Owain [email protected] wrote:

Fred,

Just to show that the mysql CLI client allowed me to manually add
another row with the same quote_id of 188. So it is not mysql server
that is reporting the Duplicate Entry/Statement invalid. It is being
reported by the mysql adapter of ActiveRecord.

On closer inspection it may be that the duplicate entry error is coming
from the primary key (your insert was explicitly setting the id to 185)

Fred

On Apr 28, 1:18pm, Frederick C. [email protected]
wrote:

Query OK, 1 row affected (0.01 sec)
reported by the mysql adapter of ActiveRecord.

On closer inspection it may be that the duplicate entry error is coming from the
primary key (your insert was explicitly setting the id to 185)

Fred

Fred,

You are absolutely correct. It should be auto_increment but I have
set it explicitly in my code.

Thank you very much for your help. You do a grand job on this list.

O.