SQL MYSTERIES: Tracing BCP Might Fool You

Published Feb 22 2022 07:02 AM 420 Views
Microsoft
Moved from bobsql.com

 

Today I was tracking a large BCP.exe ‘IN’ operation and monitoring the sys.dm_exec_requests entries.  The ‘BULK INSERT’ command entry appeared, showing the CPU, reads, writes, … but these values where getting reset from time to time.  Here are 3 snapshots from my system.

cpu_time    total_elapsed_time      writes      session_id   start_time              command
1387        1396                    32          51           2018-08-07 00:45:42.670 BULK INSERT
1930        1941                    66          51           2018-08-07 00:46:02.087 BULK INSERT
632         638                     32          51           2018-08-07 00:46:23.313 BULK INSERT

Instead of a single BULK INSERT batch I saw multiple BULK INSERT batches taking place on the same session.  When you specify the BCP, batch size (-b) the rows are streamed until the batch size is reached, a commit is issued and a new batch is started for subsequent rows.  Thus, you see a series of BULK INSERT operations and not the BCP in it entirety. 

%3CLINGO-SUB%20id%3D%22lingo-sub-3199223%22%20slang%3D%22en-US%22%3ESQL%20MYSTERIES%3A%20Tracing%20BCP%20Might%20Fool%20You%3C%2FLINGO-SUB%3E%3CLINGO-BODY%20id%3D%22lingo-body-3199223%22%20slang%3D%22en-US%22%3E%3CH6%20id%3D%22toc-hId-1769251929%22%20id%3D%22toc-hId-1769252020%22%3EMoved%20from%20bobsql.com%3C%2FH6%3E%0A%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3CP%3EToday%20I%20was%20tracking%20a%20large%20BCP.exe%20%E2%80%98IN%E2%80%99%20operation%20and%20monitoring%20the%3CSPAN%3E%26nbsp%3B%3C%2FSPAN%3E%3CFONT%20face%3D%22Courier%20New%22%3Esys.dm_exec_requests%3C%2FFONT%3E%3CSPAN%3E%26nbsp%3B%3C%2FSPAN%3Eentries.%26nbsp%3B%20The%20%E2%80%98BULK%20INSERT%E2%80%99%20command%20entry%20appeared%2C%20showing%20the%20CPU%2C%20reads%2C%20writes%2C%20%E2%80%A6%20but%20these%20values%20where%20getting%20reset%20from%20time%20to%20time.%26nbsp%3B%20Here%20are%203%20snapshots%20from%20my%20system.%3CBR%20%2F%3E%3CBR%20%2F%3E%3C%2FP%3E%0A%3CPRE%3E%3CFONT%20face%3D%22Courier%20New%22%20size%3D%222%22%3Ecpu_time%26nbsp%3B%26nbsp%3B%26nbsp%3B%20total_elapsed_time%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%20writes%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%20session_id%26nbsp%3B%26nbsp%3B%20start_time%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%20command%3C%2FFONT%3E%3C%2FPRE%3E%0A%3CPRE%3E%3CFONT%20face%3D%22Courier%20New%22%20size%3D%222%22%3E1387%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%201396%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%2032%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%2051%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%202018-08-07%2000%3A45%3A42.670%20BULK%20INSERT%3CBR%20%2F%3E%3C%2FFONT%3E%3CFONT%20face%3D%22Courier%20New%22%20size%3D%222%22%3E1930%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%201941%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%2066%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%2051%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%202018-08-07%2000%3A46%3A02.087%20BULK%20INSERT%3CBR%20%2F%3E%3C%2FFONT%3E%3CFONT%20size%3D%222%22%3E%3CFONT%20face%3D%22Courier%20New%22%3E632%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%20638%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%2032%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%2051%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%26nbsp%3B%202018-08-07%2000%3A46%3A23.313%20BULK%20INSERT%3C%2FFONT%3E%3C%2FFONT%3E%3C%2FPRE%3E%0A%3CP%3EInstead%20of%20a%20single%20BULK%20INSERT%20batch%20I%20saw%20multiple%20BULK%20INSERT%20batches%20taking%20place%20on%20the%20same%20session.%26nbsp%3B%20When%20you%20specify%20the%20BCP%2C%20batch%20size%20(-b)%20the%20rows%20are%20streamed%20until%20the%20batch%20size%20is%20reached%2C%20a%20commit%20is%20issued%20and%20a%20new%20batch%20is%20started%20for%20subsequent%20rows.%26nbsp%3B%20Thus%2C%20you%20see%20a%20series%20of%20BULK%20INSERT%20operations%20and%20not%20the%20BCP%20in%20it%20entirety.%26nbsp%3B%3C%2FP%3E%3C%2FLINGO-BODY%3E%3CLINGO-TEASER%20id%3D%22lingo-teaser-3199223%22%20slang%3D%22en-US%22%3E%3CH3%20class%3D%22single-title%22%20id%3D%22toc-hId-1057684338%22%3ESQL%20MYSTERIES%3A%20Tracing%20BCP%20Might%20Fool%20You%3C%2FH3%3E%3C%2FLINGO-TEASER%3E%3CLINGO-LABS%20id%3D%22lingo-labs-3199223%22%20slang%3D%22en-US%22%3E%3CLINGO-LABEL%3EBobSQL%3C%2FLINGO-LABEL%3E%3C%2FLINGO-LABS%3E
Co-Authors
Version history
Last update:
‎Feb 22 2022 07:02 AM
Updated by: