Running multiple async queries with ADODB - callbacks not always firing

Kai picture Kai · Feb 21, 2014 · Viewed 10k times · Source

I have an Excel workbook that fires three queries to a database to populate three tables on hidden sheets, and then runs three 'refresh' scripts to pull this data through to three visible presentation sheets (one per query). Running this synchronously is quite slow: The total time to refresh is the sum of the time of each of the three queries, plus the sum of the time for each 'refresh' script to run.

I'm aware that VBA isn't multi-threaded, but I thought it would be possible to speed things up a bit by firing the queries off asynchronously (thus allowing some clean-up work to be done whilst they were executing), and then doing the population / refresh work for each sheet as the data comes back.

I rewrote my script as follows (note that I've had to remove the connection strings, query strings etc and make the variables generic):

Private WithEvents cnA As ADODB.Connection
Private WithEvents cnB As ADODB.Connection
Private WithEvents cnC As ADODB.Connection

Private Sub StartingPoint()
    'For brevity, only listing set-up of cnA here. You can assume identical
    'set-up for cnB and cnC
    Set cnA = New ADODB.Connection

    Dim connectionString As String: connectionString = "<my conn string>"
    cnA.connectionString = connectionString

    Debug.Print "Firing cnA query: " & Now
    cnA.Open
    cnA.Execute "<select query>", adAsyncExecute  'takes roughly 5 seconds to execute

    Debug.Print "Firing cnB query: " & Now
    cnB.Open
    cnB.Execute "<select query>", adAsyncExecute  'takes roughly 10 seconds to execute

    Debug.Print "Firing cnC query: " & Now
    cnC.Open
    cnC.Execute "<select query>", adAsyncExecute  'takes roughly 20 seconds to execute

    Debug.Print "Clearing workbook tables: " & Now
    ClearAllTables
    TablesCleared = True
    Debug.Print "Tables cleared: " & Now
End Sub

Private Sub cnA_ExecuteComplete(ByVal RecordsAffected As Long, ...)
    Debug.Print "cnA records received: " & Now
    'Code to handle the recordset, refresh the relevant presentation sheet here, 
    'takes roughly < 1 seconds to complete
    Debug.Print "Sheet1 tables received: " & Now
End Sub

Private Sub cnB_ExecuteComplete(ByVal RecordsAffected As Long, ...)
    Debug.Print "cnB records received: " & Now
    'Code to handle the recordset, refresh the relevant presentation sheet here, 
    'takes roughly 2-3 seconds to complete
    Debug.Print "Sheet2 tables received: " & Now
End Sub

Private Sub cnC_ExecuteComplete(ByVal RecordsAffected As Long, ...)
    Debug.Print "cnC records received: " & Now
    'Code to handle the recordset, refresh the relevant presentation sheet here, 
    'takes roughly 5-7 seconds to complete
    Debug.Print "Sheet3 tables received: " & Now
End Sub

Typical expected debugger output:

Firing cnA query: 21/02/2014 10:34:22
Firing cnB query: 21/02/2014 10:34:22
Firing cnC query: 21/02/2014 10:34:22
Clearing tables: 21/02/2014 10:34:22
Tables cleared: 21/02/2014 10:34:22
cnB records received: 21/02/2014 10:34:26
Sheet2 tables refreshed: 21/02/2014 10:34:27
cnA records received: 21/02/2014 10:34:28
Sheet1 tables refreshed: 21/02/2014 10:34:28
cnC records received: 21/02/2014 10:34:34
Sheet3 tables refreshed: 21/02/2014 10:34:40

The three queries can come back in different orders depending on which finishes first, of course, so sometimes the typical output is ordered differently - this is expected.

Sometimes however, one or two of the cnX_ExecuteComplete callbacks don't fire at all. After some time debugging, I'm fairly certain the reason for this is that if a recordset returns whilst one of the callbacks is currently executing, the call does not occur. For example:

  • query A, B and C all fire at time 0
  • query A completes first at time 3, cnA_ExecuteComplete fires
  • query B completes second at time 5
  • cnA_ExecuteComplete is still running, so cnB_ExecuteComplete never fires
  • cnA_ExecuteComplete completes at time 8
  • query C completes at time 10, cnC_ExecuteComplete fires
  • query C completes at time 15

Am I right in my theory that this is the issue? If so, is it possible to work around this, or get the call to 'wait' until current code has executed rather than just disappearing?

One solution would be to do something extremely quick during the cnX_ExecuteComplete callbacks (eg, a one-liner Set sheet1RS = pRecordset and a check to see if they're all done yet before running the refresh scripts synchronously) so the chance of them overlapping is about zero, but want to know if there's a better solution first.

Answer

user2140173 picture user2140173 · Feb 24, 2014

I guess I am not able to explain why some your 'refresh scripts' don't always fire. It's a strange behavior that sometimes they run and sometimes they don't. I can't really see your entire script but I can show you how I have adopted your code and made it work each time.

Note: your question is somehow related to ExecuteComplete ADODB Connection event not fired with adAsyncExecute parameter

I have added 3 stored procedures on my SQL server; sp_WaitFor5, sp_WaitFor10, sp_WaitFor20 to simulate the delay of query execution time.

As simple as

CREATE PROCEDURE sp_WaitFor5
AS
WAITFOR DELAY '00:00:05'

for all 3 delays.

Then in my Module1 I added a very simple code to call the custom class

Option Explicit

Private clsTest As TestEvents

Sub Main()
    Cells.ClearContents
    Set clsTest = New TestEvents
    Call clsTest.StartingPoint
End Sub

Then I have renamed the class module to TestEvents and added a slightly modified version of your code

Option Explicit

Private WithEvents cnA As ADODB.Connection
Private WithEvents cnB As ADODB.Connection
Private WithEvents cnC As ADODB.Connection

Private i as Long

Public Sub StartingPoint()

    Dim connectionString As String: connectionString = "Driver={SQL Server};Server=MYSERVER\INST; UID=username; PWD=password!"

    Debug.Print "Firing cnA query(10 sec): " & Now
    Set cnA = New ADODB.Connection
    cnA.connectionString = connectionString
    cnA.Open
    cnA.Execute "sp_WaitFor10", adExecuteNoRecords, adAsyncExecute

    Debug.Print "Firing cnB query(5 sec): " & Now
    Set cnB = New ADODB.Connection
    cnB.connectionString = connectionString
    cnB.Open
    cnB.Execute "sp_WaitFor5", adExecuteNoRecords, adAsyncExecute

    Debug.Print "Firing cnC query(20 sec): " & Now
    Set cnC = New ADODB.Connection
    cnC.connectionString = connectionString
    cnC.Open
    cnC.Execute "sp_WaitFor20", adExecuteNoRecords, adAsyncExecute

End Sub


Private Sub cnA_ExecuteComplete(ByVal RecordsAffected As Long, ByVal pError As ADODB.Error, adStatus As ADODB.EventStatusEnum, ByVal pCommand As ADODB.Command, ByVal pRecordset As ADODB.Recordset, ByVal pConnection As ADODB.Connection)
    Debug.Print vbTab & "cnA_executeComplete START", Now
    For i = 1 To 55
        Range("A" & i) = Rnd(1)
    Next i
    Debug.Print vbTab & "cnA_executeComplete ENDED", Now
End Sub

Private Sub cnB_ExecuteComplete(ByVal RecordsAffected As Long, ByVal pError As ADODB.Error, adStatus As ADODB.EventStatusEnum, ByVal pCommand As ADODB.Command, ByVal pRecordset As ADODB.Recordset, ByVal pConnection As ADODB.Connection)
    Debug.Print vbTab & "cnB_executeComplete START", Now
    For i = 1 To 1000000
        Range("B" & i) = Rnd(1)
    Next i
    Debug.Print vbTab & "cnB_executeComplete ENDED", Now
End Sub

Private Sub cnC_ExecuteComplete(ByVal RecordsAffected As Long, ByVal pError As ADODB.Error, adStatus As ADODB.EventStatusEnum, ByVal pCommand As ADODB.Command, ByVal pRecordset As ADODB.Recordset, ByVal pConnection As ADODB.Connection)
    Debug.Print vbTab & "cnC_executeComplete START", Now
    For i = 1 To 55
        Range("C" & i) = Rnd(1)
    Next i
    Debug.Print vbTab & "cnC_executeComplete ENDED", Now
End Sub

I have not really changed much except the extra parameter for Execute and some code which populates activesheet just to take the time.


Now, I am able to run different variations/configurations. I can rotate the execution time for connection objects. I can have cnA 5 sec, cnB 10sec, cnC 20sec. I can swap/adjust the execution times for each of the _ExecuteComplete events.

From testing on my own I can assure you all 3 are always executed.

Here's some logs based on a configuration similar to yours

Firing cnA query(10 sec): 24/02/2014 12:59:46
Firing cnB query(5 sec): 24/02/2014 12:59:46
Firing cnC query(20 sec): 24/02/2014 12:59:46
    cnB_executeComplete START             24/02/2014 12:59:51 
    cnB_executeComplete ENDED             24/02/2014 13:00:21 
    cnA_executeComplete START             24/02/2014 13:00:21 
    cnA_executeComplete ENDED             24/02/2014 13:00:21 
    cnC_executeComplete START             24/02/2014 13:00:22 
    cnC_executeComplete ENDED             24/02/2014 13:00:22

In the above example as you can see, all 3 queries are fired asynchronously.

cnA returns the handle after 5 secs which makes cnB the first one to have the event ('refresh script') run in the hierarchy as cnC takes the longest.

Since cnB comes back first, it fires it's cnB_ExecuteComplete event procedure. The cnB_ExecuteComplete itself it's set to take some time execute (iterates 1 million times and fills in column B with random numbers. Note: cnA populates column A, cnB col B, cnC col C). Looking at the above log it takes exactly 30 seconds to run.

While the cnB_ExecuteComplete is doing its job /taking up resources (and as you know VBA is single threaded) the cnA_ExecuteComplete event is added up to the queue of TODO processes. So, you can think of it like a queue. While something is being taken care of the next thing has to just wait for its turn in the end.


If I change the configuration; cnA 5 sec, cnB 10 sec, cnC 20 sec and have each of the 'refresh scripts' iterate 1 million times then

Firing cnA query(5 sec): 24/02/2014 13:17:10
Firing cnB query(10 sec): 24/02/2014 13:17:10
Firing cnC query(20 sec): 24/02/2014 13:17:10
one million iterations each
    cnA_executeComplete START             24/02/2014 13:17:15 
    cnA_executeComplete ENDED             24/02/2014 13:17:45 
    cnB_executeComplete START             24/02/2014 13:17:45 
    cnB_executeComplete ENDED             24/02/2014 13:18:14 
    cnC_executeComplete START             24/02/2014 13:18:14 
    cnC_executeComplete ENDED             24/02/2014 13:18:44 

Clearly proved my point from the first example.

Also, tried with cnA 5 sec, cnB 5 sec, cnC 5 sec

Firing cnA query(5 sec): 24/02/2014 13:20:56
Firing cnB query(5 sec): 24/02/2014 13:20:56
Firing cnC query(5 sec): 24/02/2014 13:20:56
one million iterations each
    cnB_executeComplete START             24/02/2014 13:21:01 
    cnB_executeComplete ENDED             24/02/2014 13:21:31 
    cnA_executeComplete START             24/02/2014 13:21:31 
    cnA_executeComplete ENDED             24/02/2014 13:22:01 
    cnC_executeComplete START             24/02/2014 13:22:01 
    cnC_executeComplete ENDED             24/02/2014 13:22:31

Which also completes/executes all 3.


Like I've said I can't see your entire code, maybe you're having an unhandled error somewhere in your code, maybe there is something misleading you to think that one _ExecuteComplete is not executing at all. Try to make changes to your code to reflect the one I have given you and run a few more text on our own. I will be looking forward to your feedback.