Transaction rollback fails with "use_output_insert == false" if a SQL error happened during the transaction

[naag]

We're running a Rails 4.2.0 app with activerecord-sqlserver-adapter 4.2.2 and SQL Server 2012 and have run into an issue with both emoji encoding and transaction rollback in that scenario. Trying to create a simple record with an emoji fails due to TinyTDS character conversion, but the transaction rollback also fails when using ActiveRecord::ConnectionAdapters::SQLServerAdapter.use_output_inserted = false .

Example:

ActiveRecord::ConnectionAdapters::SQLServerAdapter.use_output_inserted = false
Emoji.create!(text: "😢")

This fails with these error messages:

Started GET "/encoding/really_bad" for 172.17.42.1 at 2015-02-16 15:37:49 +0000
Processing by EncodingController#really_bad as */*
  SQL (1.4ms)  BEGIN TRANSACTION
  SQL (0.3ms)  EXEC sp_executesql N'INSERT INTO [emojis] ([text]) VALUES (@0); SELECT CAST(SCOPE_IDENTITY() AS bigint) AS Ident', N'@0 nvarchar(4000)', @0 = N'😢'  [["text", "😢"]]
TinyTds::Error: Error converting characters into server's character set. Some character(s) could not be converted: EXEC sp_executesql N'INSERT INTO [emojis] ([text]) VALUES (@0); SELECT CAST(SCOPE_IDENTITY() AS bigint) AS Ident', N'@0 nvarchar(4000)', @0 = N'😢'
  SQL (3.3ms)  ROLLBACK TRANSACTION
TinyTds::Error: Unclosed quotation mark after the character string '@0 nvarcharROLLBACK TRANSACTION'.: ROLLBACK TRANSACTION
Completed 500 Internal Server Error in 31ms

ActiveRecord::StatementInvalid (TinyTds::Error: Unclosed quotation mark after the character string '@0 nvarcharROLLBACK TRANSACTION'.: ROLLBACK TRANSACTION)

but unfortunately we have some insert triggers on the database and thus cannot change the insert mode.

We've created a sample Rails application which shows this behaviour at https://github.com/naag/sqlserver-encoding. Just run it with rails s and curl http://127.0.0.1:3003/encoding/good, curl http://127.0.0.1:3003/encoding/bad, curl http://127.0.0.1:3003/encoding/really_bad. They demonstrate the three cases (no emoji, emoji with use_output_inserted = true and use_output_inserted = false).

Any help is really appreciated!

[metaskills]

There are two things happening here that are un-related.

First, your setup is throwing errors when inserting 4-byte chars. This does not happen for me, see here. This could be related to my 2014 collation or some setting in TinyTDS or even that I am using TinyTDS master, likely an upcoming 0.7 release. All moot tho.

The second and important issue has nothing to do with the one above or even anything to do with the use_output_inserted config. Instead, what is happening is that SQL Server has implicit transaction rollbacks when errors happen. So when we issue the rollback, it errors. This was a breaking change introduced in eee322a and the fix is to make the rollback transaction count aware. Basically IF @@TRANCOUNT > 0 ROLLBACK TRANSACTION. Patched in master.

[metaskills]

http://www.sommarskog.se/error-handling-I.html

[metaskills]

I just released the v4.2.3 version of the gem with the rollback fix too. Cheers.

[naag]

Thanks for the quick help so far! Unfortunately, we still get the same kind of error with 4.2.3 and TinyTDS master, except now SQL Server complains about:

Started GET "/encoding/really_bad" for 172.17.42.1 at 2015-02-18 10:19:29 +0000
Processing by EncodingController#really_bad as */*
  SQL (1.6ms)  BEGIN TRANSACTION
  SQL (0.6ms)  EXEC sp_executesql N'INSERT INTO [emojis] ([text]) VALUES (@0); SELECT CAST(SCOPE_IDENTITY() AS bigint) AS Ident', N'@0 nvarchar(4000)', @0 = N'😢'  [["text", "😢"]]
TinyTds::Error: Error converting characters into server's character set. Some character(s) could not be converted: EXEC sp_executesql N'INSERT INTO [emojis] ([text]) VALUES (@0); SELECT CAST(SCOPE_IDENTITY() AS bigint) AS Ident', N'@0 nvarchar(4000)', @0 = N'😢'
  SQL (3.7ms)  IF @@TRANCOUNT > 0 ROLLBACK TRANSACTION
TinyTds::Error: Unclosed quotation mark after the character string '@0 nvarcharIF @@TRANCOUNT > 0 ROLLBACK TRANSACTION'.: IF @@TRANCOUNT > 0 ROLLBACK TRANSACTION
Completed 500 Internal Server Error in 9ms

ActiveRecord::StatementInvalid (TinyTds::Error: Unclosed quotation mark after the character string '@0 nvarcharIF @@TRANCOUNT > 0 ROLLBACK TRANSACTION'.: IF @@TRANCOUNT > 0 ROLLBACK TRANSACTION)

Our system information (bundle list, ruby --version, ...): https://gist.github.com/naag/13b85839fe978d92e71a.

We understand what you're saying about 4-byte chars. However we don't understand why the SQL query sent to SQL Server is actually wrong ("Unclosed quotation mark..."). We also watched the traffic on the wire via Wireshark and could observe that the SQL query is indeed wrongly formatted. This also messes up the exception that is thrown by the application.

Any idea on that?

[metaskills]

we don't understand why the SQL query sent to SQL Server is actually wrong

Indeed that is odd. This looks fine to me?

EXEC sp_executesql N'
INSERT INTO emojis VALUES (@0);
SELECT CAST(SCOPE_IDENTITY() AS bigint) AS Ident',
N'@0 nvarchar(4000)',
@0 = N'😢'

However, this '@0 nvarcharIF @@TRANCOUNT... looks whack! You know what, you need to explore what is happening with your FreeTDS setup most likely and please find out and report back. Do things like tsql -C to see how things are configured. Maybe even ditch the Ubuntu packaged FreeTDS, I have heard previous reports of that one. Check your cont files... anything... something is wrong.

BTW, remember how I said I could not fail when I tested that (link to source above)? Maybe there is a clue there. Like what is your collation, maybe you have a setting turned on via the server that raises exceptions for bad bytes. Maybe your FreeTDS/libiconv is not good. Please do investigate, this has something to do with your local setup. Ping me if needed.

[metaskills]

Another thought. The @0 nvarchar bind param could come from some Arel or gem hack? But I see a slim gem install/bundle in your list. Have you tried debugging in the adapter? $ bundle open activerecord-sqlserver-adapter, put some binding.pry in the lines just before the sql is sent, etc.

[naag]

Thanks again for the great help you've provided! By ditching Ubuntu's FreeTDS and replacing it with FreeTDS-0.92.891 from ftp://ftp.freetds.org/pub/freetds/current/freetds-current.tgz, we could solve the issue of the messed up SQL rollback statement :-)

apt-get purge freetds-dev freetds-common
wget ftp://ftp.freetds.org/pub/freetds/current/freetds-current.tgz
tar xzf freetds-current.tgz
cd freetds-dev.0.92.891
./configure
make
sudo make install

Digging into freetds.log activated through freetds.conf also indicated that indeed (our) SQL Server 2012 only supports UCS-2LE encoding. But UCS-2LE does not support our Emoji (UCS-4LE does):

$ echo 😢 | iconv -f UTF-8 -t UCS-2LE
iconv: illegal input sequence at position 0

$ echo 😢 | iconv -f UTF-8 -t UCS-4LE
"��

So consider this issue closed through upgrading FreeTDS and hopefully we'll get the SQL Server 2014 update soon ;-)

[faisalmansoor]

Ran into the same problem on ubuntu box, it looks like that Ubuntu libiconv does not gracefully handle characters not supported by UCS-2, GNU libiconv returns invalid unicode character if a mapping does not exist.

user@box:/usr/local/libiconv/bin$ iconv --version
iconv (Ubuntu EGLIBC 2.19-0ubuntu6) 2.19
Copyright (C) 2014 Free Software Foundation, Inc.
This is free software; see the source for copying conditions.  There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
Written by Ulrich Drepper.

user@box:/usr/local/libiconv/bin$ echo $'\xF0\x9F\x98\x81' | iconv -f UTF-8 -t UCS-2LE | xxd
iconv: illegal input sequence at position 0


user@box:/usr/local/libiconv/bin$ ./iconv --version
iconv (GNU libiconv 1.11)
Copyright (C) 2000-2006 Free Software Foundation, Inc.
This is free software; see the source for copying conditions.  There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
Written by Bruno Haible.

user@box:/usr/local/libiconv/bin$ echo $'\xF0\x9F\x98\x81' | ./iconv -f UTF-8 -t UCS-2LE | xxd
0000000: fdff 0a00                                ....

So the best solution to the problem would be to use FreeTDS compiled with GNU libiconv.

[metaskills]

I have a commit in the TinyTDS/FreeTDS 1.0 branch that takes about how Emoji support work in 0.95 and upward. Hope this helps! rails-sqlserver/tiny_tds@a943769