Executing bcp from within stored proc causes locking/blocking

  • Have a stored proc with following logic:

    - create global temp table

    - insert into temp table a select data from some other tables

    - execute xp_cmdshell to launch bcp to query out the data in temp table

    - drop temp table

    Executing this proc from QA works perfectly nice, but when i try to execute it from code or from within a trigger by issuing an update statement to the trigger table through QA there seems to be a locking problem

    small extract from sp_who2

    54 RUNNABLE  NXPPOR01\Diederik   NXPPOR01 .  master  EXECUTE 7016    1249   SQL Query Analyzer 
    56 sleeping  NT AUTHORITY\SYSTEM NXPPOR01 54 master  EXECUTE 0       0      Microsoft SQL Server
    

    PID 56 is blocked by 54 and the only way to stop QA from executing is by killing the bcp process in task manager. While it is executing the current activity pane in EM doesn't respond at all...

    Executing sp_lock shows following:

    pid 56 is waiting for shared lock on sysobjects table in tempdb:

    56212KEY(980031345a91) SWAIT

    pid 54 is holding several locks on the same table but I guess this is the one that blocks pid 56:

    54212KEY(980031345a91) XGRANT

    Am I overlooking something? Why does pid 56 just doesn't continue? No deadlocks occurr... Any suggestions would be welcome

  • Is this somehow wrapped in some big transaction?  Is the global table accessed by other procedures?

     

    You said, firing from a trigger...is this trigger firing multiple times creating a blocking situation?  As a general comment, I would recommend against this type of functionality in a trigger. 

  • Global table is only accessed by this procedure.

    Fired from trigger with update on only one record so proc would be called only once.

    Am firing from trigger because that is simpler for me to test than starting/debugging .NET app everytime

    It has same blocking/locking behaviour when executing from .NET (commandtype stored proc with one parameter passed in)

    No transaction, default connection settings...

  • Is it possible to post the code?

    It would help to give a little better idea of the exact scenario.

     

  • Doug, this is the code for the procedure (I cut out the select statements since they are very long...)

    SET QUOTED_IDENTIFIER OFF

    GO

    SET ANSI_NULLS OFF

    GO

    if exists (select * from dbo.sysobjects where id = object_id(N'[dbo].[spBcpPrestatie]') and OBJECTPROPERTY(id, N'IsProcedure') = 1)

    drop procedure [dbo].[spBcpPrestatie]

    GO

    CREATE PROCEDURE dbo.spBcpPrestatie

    @TransferToepassingId INT

    AS

    -- No server output messages needed untill we select everything out of our temporary table

    SET NOCOUNT ON

    DECLARE @TransferToepassingTeller INT

    DECLARE @TransferToepassingCodeCHAR(2)

    DECLARE @TransferToepassingJaartalCHAR(2)

    SELECT @TransferToepassingTeller = Teller,

    @TransferToepassingCode = UPPER(Code),

    @TransferToepassingJaartal = Jaartal

    FROM TransferToepassing

    WHERE TransferToepassingId = @TransferToepassingId

    -- Used in conjunction with CONVERT to CHAR(X) to get desired number of white space or zeros

    DECLARE @filler NVARCHAR(300) -- whitespace

    SET @filler = ''

    DECLARE @nfiller NVARCHAR(50) -- numeric filler zeros

    SET @nfiller = REPLICATE('0', 50)

    -- Used to store the number of affected records

    DECLARE @recordCounter INT

    -- Use Global Temporary table

    -- Local temporary table not possible because they are connection specific

    -- and cannot be found by the bcp utility

    -- workaround is creating a global temporary table

    -- TODO: Issue with blocking/locking of this batch

    CREATE TABLE ##t([tKey] INT PRIMARY KEY IDENTITY(2,1), IdmsRec CHAR(278) )

    -- Get Prestaties, format and store in temporary table #t

    INSERT INTO ##t (IdmsRec)

    -- Here fits select from some tables in the current db

    SET @recordCounter = @@ROWCOUNT

    -- If no records where returned add separator

    IF @recordCounter = 0

    INSERT INTO ##t (IdmsRec) VALUES (REPLICATE('0',278))

    -- Add separator PrestatieAlgKost (=layout in nullen of ander)

    INSERT INTO ##t (IdmsRec) VALUES (REPLICATE('0',278))

    -- PrestatieAlgKost

    INSERT INTO ##t (IdmsRec)

    -- Here fits select from some other tables in the current db

    -- Add recordcount PrestatieAlgKost to counter

    SET @recordCounter = @recordCounter + @@ROWCOUNT

    -- Add identifier record on first position

    SET IDENTITY_INSERT ##t ON

    INSERT INTO ##t (tKey, IdmsRec)

    -- Insert idenifier record with @recordcounter value etc...

    SET IDENTITY_INSERT ##t OFF

    SET NOCOUNT OFF

    /* use xp_cmdshell to BCP the data out */

    DECLARE @bcpCmd VARCHAR(1024)

    SET @bcpCmd = 'bcp "SELECT IdmsRec FROM tempdb..##t ORDER BY tKey" queryout '

    SET @bcpCmd = @bcpCmd + '"' + dbo.GetApplicatieParameter('BcpPrestatieOutPath')

    + dbo.GetApplicatieParameter('BcpIDMSZkNr')

    + UPPER(@TransferToepassingCode)

    + @TransferToepassingJaartal

    + STUFF(CONVERT(CHAR(3), @nfiller), 3 - LEN(CONVERT(VARCHAR(3), @TransferToepassingTeller)) + 1, LEN(CONVERT(VARCHAR(3), @TransferToepassingTeller)), CONVERT(VARCHAR(3), @TransferToepassingTeller))

    + 'Bcp.txt" '

    SET @bcpCmd = @bcpCmd + '-e "' + dbo.GetApplicatieParameter('BcpPrestatieErrPath')

    + dbo.GetApplicatieParameter('BcpIDMSZkNr')

    + UPPER(@TransferToepassingCode)

    + @TransferToepassingJaartal

    + STUFF(CONVERT(CHAR(3), @nfiller), 3 - LEN(CONVERT(VARCHAR(3), @TransferToepassingTeller)) + 1, LEN(CONVERT(VARCHAR(3), @TransferToepassingTeller)), CONVERT(VARCHAR(3), @TransferToepassingTeller))

    + 'BcpErr.txt" '

    SET @bcpCmd = @bcpCmd + '-f "' + dbo.GetApplicatieParameter('BcpPrestatieFmtFile') + '" '

    SET @bcpCmd = @bcpCmd + ' -T'

    --print @bcpcmd

    EXEC master..xp_cmdshell @bcpCmd

    DROP TABLE ##t

    GO

    SET QUOTED_IDENTIFIER OFF

    GO

    SET ANSI_NULLS ON

    GO

  • The trigger - only for testing purposes looks like this:

    CREATE TRIGGER TransferToepassingTriggerBcp ON TransferToepassing FOR UPDATE

    AS

    DECLARE @TransferToepassingId INT

    SELECT @TransferToepassingId = TransferToepassingId FROM INSERTED

    EXEC spBcpPrestatie @TransferToepassingId

    GO

    When I issue following statement

    UPDATE TransferToepassing SET versie = versie WHERE TransferToepassingId = 8 (where TransferToepassingId is PK)

    The blocking/locking occurs.

  • While I'm looking at it, I just want to be sure that you're QA is not set up with IMPLICIT_TRANSACTIONS.  Your who shows the QA is the runnable task, which means it is doing the blocking.  Its a guess, but maybe implicit transactions is on?

     

  • Have taken a look at the QA options and IMPLICIT_TRANSACTIONS is not checked, so my QA is operating in autocommit mode.

  • If you run JUST the update query, what is the resultant time to run?

    What is the results of SET STATISTICS IO ON.

    Being its a primary key, I'm assuming its also the clustered index(and you have not changed that). 

     

    What is the timing without the other query?

  • PK is indeed Clustered Index

    - Execute Update statement from QA with trigger disabled:

    Table 'TransferToepassing'. Scan count 1, logical reads 2, physical reads 0, read-ahead reads 0.

    - Execute Stored proc only from QA with STATISTICS IO:

    Table 'TransferToepassing'. Scan count 1, logical reads 2, physical reads 0, read-ahead reads 0.

    Table '##t'. Scan count 0, logical reads 83, physical reads 0, read-ahead reads 0.

    Table 'BijzondereHoegrootheid'. Scan count 1, logical reads 219, physical reads 0, read-ahead reads 0.

    Table 'WeefselbankZiekenhuis'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'Patient'. Scan count 39, logical reads 139, physical reads 0, read-ahead reads 0.

    Table 'NomenclatuurForfait'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'PrestatieHechtingForfait'. Scan count 39, logical reads 78, physical reads 0, read-ahead reads 0.

    Table 'Scanner'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'Zorgenverstrekker'. Scan count 68, logical reads 230, physical reads 0, read-ahead reads 0.

    Table 'TarificatieCode'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'GroepOmschrijving'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'Groep'. Scan count 78, logical reads 780, physical reads 0, read-ahead reads 0.

    Table 'ProfylaxisReden'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'Categorie'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'NZiekenhuisCategorie'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'BetrekkelijkewaardeZk'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'NZiekenhuisBetrekkelijkeWaarde'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'NomenclatuurZiekenhuis'. Scan count 39, logical reads 39, physical reads 0, read-ahead reads 0.

    Table 'Betrekkelijkewaarde'. Scan count 39, logical reads 78, physical reads 0, read-ahead reads 0.

    Table 'NSleutelBetrekkelijkewaarde'. Scan count 39, logical reads 214, physical reads 0, read-ahead reads 0.

    Table 'NomenclatuurGroep'. Scan count 234, logical reads 468, physical reads 0, read-ahead reads 0.

    Table 'OpnameAnderZiekenhuis'. Scan count 68, logical reads 68, physical reads 0, read-ahead reads 0.

    Table 'Labo'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'PrestatieHistoriek'. Scan count 136, logical reads 460, physical reads 0, read-ahead reads 0.

    Table 'Dossier'. Scan count 68, logical reads 249, physical reads 0, read-ahead reads 0.

    Table 'DossierContact'. Scan count 68, logical reads 230, physical reads 0, read-ahead reads 0.

    Table 'Nomenclatuur'. Scan count 39, logical reads 227, physical reads 0, read-ahead reads 0.

    Table 'NomenclatuurSleutel'. Scan count 39, logical reads 78, physical reads 0, read-ahead reads 0.

    Table 'Prestatie'. Scan count 1, logical reads 14694, physical reads 0, read-ahead reads 0.

    Table '##t'. Scan count 0, logical reads 2, physical reads 0, read-ahead reads 0.

    Table '##t'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'Patient'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'Dossier'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'DossierContact'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'TarificatieCode'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'PrestatieAlgKostHistoriek'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'NomenclatuurAlgKost'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'PrestatieAlgKost'. Scan count 1, logical reads 308, physical reads 0, read-ahead reads 0.

    Table '##t'. Scan count 0, logical reads 5, physical reads 0, read-ahead reads 0.

    Execute update with trigger enabled and STATISTICS IO ON:

    Table 'TransferToepassing'. Scan count 1, logical reads 2, physical reads 0, read-ahead reads 0.

    Table 'Worktable'. Scan count 0, logical reads 4, physical reads 0, read-ahead reads 0.

    Table 'Worktable'. Scan count 1, logical reads 2, physical reads 0, read-ahead reads 0.

    Table 'TransferToepassing'. Scan count 1, logical reads 2, physical reads 0, read-ahead reads 0.

    Table '##t'. Scan count 0, logical reads 83, physical reads 0, read-ahead reads 0.

    Table 'BijzondereHoegrootheid'. Scan count 1, logical reads 219, physical reads 0, read-ahead reads 0.

    Table 'WeefselbankZiekenhuis'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'Patient'. Scan count 39, logical reads 139, physical reads 0, read-ahead reads 0.

    Table 'NomenclatuurForfait'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'PrestatieHechtingForfait'. Scan count 39, logical reads 78, physical reads 0, read-ahead reads 0.

    Table 'Scanner'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'Zorgenverstrekker'. Scan count 68, logical reads 230, physical reads 0, read-ahead reads 0.

    Table 'TarificatieCode'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'GroepOmschrijving'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'Groep'. Scan count 78, logical reads 780, physical reads 0, read-ahead reads 0.

    Table 'ProfylaxisReden'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'Categorie'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'NZiekenhuisCategorie'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'BetrekkelijkewaardeZk'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'NZiekenhuisBetrekkelijkeWaarde'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'NomenclatuurZiekenhuis'. Scan count 39, logical reads 39, physical reads 0, read-ahead reads 0.

    Table 'Betrekkelijkewaarde'. Scan count 39, logical reads 78, physical reads 0, read-ahead reads 0.

    Table 'NSleutelBetrekkelijkewaarde'. Scan count 39, logical reads 214, physical reads 0, read-ahead reads 0.

    Table 'NomenclatuurGroep'. Scan count 234, logical reads 468, physical reads 0, read-ahead reads 0.

    Table 'OpnameAnderZiekenhuis'. Scan count 68, logical reads 68, physical reads 0, read-ahead reads 0.

    Table 'Labo'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0.

    Table 'PrestatieHistoriek'. Scan count 136, logical reads 460, physical reads 0, read-ahead reads 0.

    Table 'Dossier'. Scan count 68, logical reads 249, physical reads 0, read-ahead reads 0.

    Table 'DossierContact'. Scan count 68, logical reads 230, physical reads 0, read-ahead reads 0.

    Table 'Nomenclatuur'. Scan count 39, logical reads 227, physical reads 0, read-ahead reads 0.

    Table 'NomenclatuurSleutel'. Scan count 39, logical reads 78, physical reads 0, read-ahead reads 0.

    Table 'Prestatie'. Scan count 1, logical reads 14694, physical reads 0, read-ahead reads 0.

    Query cancelled by User

    [Microsoft][ODBC SQL Server Driver]Operation canceled

    -> I canceled here because executing in this way seems to last forever...

    Can we deduct from this output that the blocking occurs when the proc is trying to insert the data from the second select?

    Many thanks in advance...

  • Yes, I think it is hanging at that select.

     

    This particular line really concerns me.

    Table 'Prestatie'. Scan count 1, logical reads 14694, physical reads 0, read-ahead reads 0.

    It menas in the Prestatie table you are probably missing valuable indexes.  Check your indexes on this table.  Ensure that you have an index covering all fields in the where clause and order by. 

    As a general rule, I always shoot to have my logical reads under 1000 if at all possible.  Even 500 on good days. 

     

    I would pull out that query (by itself), set statistics io on and address tables with the highest logical reads first.  Once you have that query fully optimized, try popping it back in to see what you end up with.  I think we're on the right track.  Post back with any updates.

  • Doug,

    Am going to pull the query out and see what I can do about indexes. Prestatie table contains about 700.000 records and joins to PrestatieHistoriek which contains about 900.000 records and growing at about 100.000 a month (2 months in production now).

    What worries me a bit is that the procedure executes reasonably fast executed from QA but when in trigger or launched from code it hangs with blocking occurring.

    Am also looking to make a little working example to test with and will post the code when I am finished. Don't know if it will be today because it's almost 6PM over here and that means the weekend begins...

  • Have a little bit of testcode ready

    - creation of a table with 5 recs

    - creation of a table with one rec and update trigger on it

    - creation of stored proc which creates a global temp table and tries to insert the data from the 5-rec-table two times

    - one line of code to execute proc like it is -> executes nicely

    - one line of code to execute proc through trigger -> locks/blocks (and we're talking about tables with less than 10 records now)

    - script to delete all garbage created.

    Carefull: stored proc contains hardcoded c:\temp path where bcp-ed files will be created so adjust or create directory if necessary

    -- -- TESTSCRIPT LOCKING/BLOCKING BCP

    -- -- uncomment to create temp tables and insert data

    -- SET QUOTED_IDENTIFIER OFF

    -- GO

    -- SET ANSI_NULLS OFF

    -- GO

    --

    -- CREATE TABLE tmpA (sometext VARCHAR(20) PRIMARY KEY)

    -- GO

    --

    -- INSERT INTO tmpA VALUES ('Doug')

    -- INSERT INTO tmpA VALUES ('Diederik')

    -- INSERT INTO tmpA VALUES ('Daniella')

    -- INSERT INTO tmpA VALUES ('Marie')

    -- INSERT INTO tmpA VALUES ('Marc')

    -- GO

    --

    -- CREATE TABLE tmpTriggerTable (firecol VARCHAR(10))

    -- GO

    --

    -- INSERT INTO tmpTriggerTable VALUES ('fire')

    -- GO

    --

    -- if exists (select * from dbo.sysobjects where id = object_id(N'[dbo].[tmpBCP]') and OBJECTPROPERTY(id, N'IsProcedure') = 1)

    -- drop procedure [dbo].[tmpBCP]

    -- GO

    --

    -- CREATE PROCEDURE tmpBCP

    -- AS

    --

    -- DECLARE @recordCounter INT

    --

    -- CREATE TABLE ##t([tKey] INT PRIMARY KEY IDENTITY(2,1), sometext VARCHAR(20))

    --

    -- INSERT INTO ##t (sometext)

    -- SELECT sometext FROM tmpA

    --

    -- SET @recordCounter = @@ROWCOUNT

    --

    -- -- If no records where returned add separator

    -- IF @recordCounter = 0

    -- INSERT INTO ##t (sometext) VALUES ('separator no recs')

    --

    -- -- Add separator

    -- INSERT INTO ##t (sometext) VALUES ('normal separator')

    --

    -- INSERT INTO ##t (sometext)

    -- SELECT sometext FROM tmpA

    --

    -- SET @recordCounter = @recordCounter + @@ROWCOUNT

    --

    -- -- Add identifier record on first position

    -- SET IDENTITY_INSERT ##t ON

    --

    -- INSERT INTO ##t (tKey, sometext)

    -- VALUES (1, 'first record')

    --

    -- SET IDENTITY_INSERT ##t OFF

    --

    -- SET NOCOUNT OFF

    --

    -- /* use xp_cmdshell to BCP the data out */

    -- DECLARE @bcpCmd VARCHAR(1024)

    -- SET @bcpCmd = 'bcp "SELECT sometext FROM tempdb..##t ORDER BY tKey" queryout '

    -- SET @bcpCmd = @bcpCmd + '"C:\temp\testBcp.txt" '

    -- SET @bcpCmd = @bcpCmd + '-e "C:\temp\testBcpErr.txt" '

    -- SET @bcpCmd = @bcpCmd + '-c '

    -- SET @bcpCmd = @bcpCmd + ' -T'

    --

    -- --print @bcpcmd

    --

    -- EXEC master..xp_cmdshell @bcpCmd

    --

    -- DROP TABLE ##t

    --

    -- GO

    --

    -- IF EXISTS (SELECT * FROM dbo.sysobjects WHERE id = OBJECT_ID('[dbo].[UpdateTriggerTmpTriggerTable]') AND OBJECTPROPERTY(id, 'IsTrigger') = 1)

    -- DROP TRIGGER [dbo].[UpdateTriggerTmpTriggerTable]

    -- GO

    --

    -- CREATE TRIGGER UpdateTriggerTmpTriggerTable ON tmpTriggerTable FOR UPDATE

    -- AS

    --

    -- EXEC tmpBCP

    --

    -- GO

    --

    -- SET QUOTED_IDENTIFIER OFF

    -- GO

    -- SET ANSI_NULLS ON

    -- GO

    -- Execute in following ways:

    -- Directly proc: no problem

    EXEC tmpbcp

    -- Through trigger: everything locks/blocks -> open task manager and kill bcp to cancel

    UPDATE tmpTriggerTable SET firecol = firecol

    -- -- uncomment and execute to get rid of all previous junk

    -- DROP TABLE tmpTriggerTable

    -- GO

    -- DROP PROCEDURE tmpBCP

    -- GO

    -- DROP TABLE tmpA

    -- GO

Viewing 13 posts - 1 through 12 (of 12 total)

You must be logged in to reply to this topic. Login to reply