R
R
Roman Mirilaczvili2016-12-01 18:37:06
ruby
Roman Mirilaczvili, 2016-12-01 18:37:06

Why is working with SQL Server through gem activerecord-sqlserver-adapter so slow?

Ruby project needs to use SQL Server 2008 :-/
Activerecord -sqlserver-adapter version 4.1.4 is used (relatively new).
Unlike the mysql2 driver, everything is terribly slow, even though SQL Server is on the same subnet. Where is it seen that a normal INSERT was completed in a total of 600 ms?
Although I have some suspicion. Does anyone know why each INSERT is executed through "EXEC sp_executesql", and even wrapped in a transaction, although I did not ask for this in the code?
Maybe some debugging flag is enabled by default that slows things down?

D, [2016-12-01T17:08:02.700498 #10570] DEBUG -- :   SQL (202.0ms)  BEGIN TRANSACTION
D, [2016-12-01T17:08:02.903759 #10570] DEBUG -- :   SQL (200.8ms)  EXEC sp_executesql N'INSERT INTO [dbo].[channels_mappings] ([channel_id], [project_id], [site_id]) OUTPUT inserted.id VALUES (@0, @1, @2)', N'@0 nvarchar(30), @1 nvarchar(30), @2 nvarchar(30)', @0 = N'212', @1 = N'34', @2 = N'97'  
D, [2016-12-01T17:08:03.106695 #10570] DEBUG -- :   SQL (202.1ms)  COMMIT TRANSACTION
D, [2016-12-01T17:08:03.206572 #10570] DEBUG -- :   ChannelsMapping Load (98.2ms)  EXEC sp_executesql N'SELECT TOP (1) [dbo].[channels_mappings].* FROM [dbo].[channels_mappings] WHERE [dbo].[channels_mappings].[channel_id] = 213'
D, [2016-12-01T17:08:03.309404 #10570] DEBUG -- :   SQL (101.8ms)  BEGIN TRANSACTION
D, [2016-12-01T17:08:03.457383 #10570] DEBUG -- :   SQL (147.1ms)  EXEC sp_executesql N'INSERT INTO [dbo].[channels_mappings] ([channel_id], [project_id], [site_id]) OUTPUT inserted.id VALUES (@0, @1, @2)', N'@0 nvarchar(30), @1 nvarchar(30), @2 nvarchar(30)', @0 = N'213', @1 = N'34', @2 = N'97'  
D, [2016-12-01T17:08:03.519507 #10570] DEBUG -- :   SQL (61.3ms)  COMMIT TRANSACTION
D, [2016-12-01T17:08:03.730075 #10570] DEBUG -- :   ChannelsMapping Load (209.3ms)  EXEC sp_executesql N'SELECT TOP (1) [dbo].[channels_mappings].* FROM [dbo].[channels_mappings] WHERE [dbo].[channels_mappings].[channel_id] = 214'
D, [2016-12-01T17:08:03.933089 #10570] DEBUG -- :   SQL (201.8ms)  BEGIN TRANSACTION
D, [2016-12-01T17:08:04.136342 #10570] DEBUG -- :   SQL (200.7ms)  EXEC sp_executesql N'INSERT INTO [dbo].[channels_mappings] ([channel_id], [project_id], [site_id]) OUTPUT inserted.id VALUES (@0, @1, @2)', N'@0 nvarchar(30), @1 nvarchar(30), @2 nvarchar(30)', @0 = N'214', @1 = N'34', @2 = N'97'  
D, [2016-12-01T17:08:04.350719 #10570] DEBUG -- :   SQL (213.5ms)  COMMIT TRANSACTION

Added
require 'tiny_tds'

c = TinyTds::Client.new(
 # ...
)

t = DateTime.now
puts "Started at #{t.to_s}"
puts c.execute("SELECT 1 AS [one]").each
puts "Ended in #{ (DateTime.now - t)*1000.0 }"
c.close

Ended in 0.002353889513888889

Answer the question

In order to leave comments, you need to log in

2 answer(s)
E
Edward, 2016-12-01
@edb

sp_executesql is needed to use parameters in a query. thus, for each request, a new plan will not be generated, but an existing one will be used. But in any case, the beginning of the transaction cannot last 200ms,
try to go to the server and from the management studio execute the following:

set statistics io, time on;
begin transaction

look at the messages tab how long it took. This should help identify the problem.

V
vsuhachev, 2016-12-01
@vsuhachev

у них в TODO что-то написано про это
Еще как вариант посмотрите на sequel

Didn't find what you were looking for?

Ask your question

Ask a Question

731 491 924 answers to any question