Async opening of connections in parallel is slow/blocking · Issue #601 · dotnet/SqlClient (original) (raw)

Describe the bug

Multiple opens of connections are very slow and seem to be bocking. In pooled mode it seems only a very limited amount of new connections is being opened concurrently (in example below it seems only 1 seems to be opened up at a time). In non-pooled mode more connections are opened concurrently (in example below 8 connections seem to be opened at a time).

Issue has big impact when connecting to SQL Azure from location with higher latency connection. Issue does not have measurable impact when connecting to SQL Azure when in the same datacenter due to super fast connection times.

This issue has a great impact on startup time of our servers, since it takes up to several minutes before our web servers can handle all the requests due to the slow opening of the SQL connections.

To reproduce

using Microsoft.Data.SqlClient; using System; using System.Collections.Concurrent; using System.Diagnostics; using System.Threading.Tasks;

namespace ConsoleExperiments { class Program {

    static void Main(string[] args)
    {
        TestConnections().Wait();
    }

    static async Task TestConnections()
    {
        string connectionString = "Server=tcp:XXXXXX.database.windows.net,1433;Initial Catalog=des;Persist Security Info=False;User ID=XXXXXXX;Password=XXXXXXX;MultipleActiveResultSets=False;Encrypt=True;TrustServerCertificate=False;Connection Timeout=30;";

        Console.WriteLine("WARM UP");
        await MeasureSingleConnectionAndReuse(connectionString);

        ClearPools();
        await MeasureSingleConnectionAndReuse(connectionString);

        ClearPools();
        await MeasureSingleConnectionAndReuse(connectionString);

        Console.WriteLine("\n\nCONCURRENT POOLED CONNECTIONS");
        ClearPools();
        MeasureParallelConnections(connectionString);

        Console.WriteLine("\n\nCONCURRENT NON-POOLED CONNECTIONS");
        ClearPools();
        MeasureParallelConnections(connectionString + "Pooling=false;");


        Console.WriteLine("\nTesting finished");
        Console.ReadLine();
    }

    private static void ClearPools()
    {
        SqlConnection.ClearAllPools();
        Console.WriteLine("ALL POOLS CLEARED");
    }
    static ConcurrentDictionary<Guid, object> _connectionIDs = new ConcurrentDictionary<Guid, object>();
    private static void MeasureParallelConnections(string connectionString)
    {
        Console.WriteLine("Start delay      OpenAsync time     Connection ID                        ReusedFromPool");
        Stopwatch sw = new Stopwatch();
        sw.Start();
        int numOpens = 100;
        Task[] tasks = new Task[numOpens];
        Stopwatch start = new Stopwatch();
        start.Start();
        for (int i = 0; i < numOpens; i++)
        {
            tasks[i] = MeasureSingleConnection(i, start, connectionString);
        }
        Task.WaitAll(tasks);
        Console.WriteLine($"{sw.Elapsed} {numOpens} connections opened in paralel");
    }

    private static async Task MeasureSingleConnection(int index, Stopwatch start, string connectionString)
    {
        TimeSpan startDelay = start.Elapsed;
        Stopwatch sw = new Stopwatch();
        using (SqlConnection connection = new SqlConnection(connectionString))
        {
            sw.Start();
            await connection.OpenAsync();
            Console.WriteLine($"{startDelay} {sw.Elapsed} {index} {connection.ClientConnectionId} {IsReuse(connection)}");
            await Task.Delay(4000);
        }
    }

    private static async Task MeasureSingleConnectionAndReuse(string connectionString)
    {
        Stopwatch sw = new Stopwatch();
        using (SqlConnection connection = new SqlConnection(connectionString))
        {
            sw.Start();
            await connection.OpenAsync();
            Console.WriteLine($"{sw.Elapsed} {connection.ClientConnectionId} {IsReuse(connection)} Single open time ");
        }
        using (SqlConnection connection = new SqlConnection(connectionString))
        {
            sw.Restart();
            await connection.OpenAsync();
            Console.WriteLine($"{sw.Elapsed} {connection.ClientConnectionId} {IsReuse(connection)} Single open time with one previously opened connection");
        }
    }

    private static bool IsReuse(SqlConnection connection)
    {
        return !_connectionIDs.TryAdd(connection.ClientConnectionId, null);
    }
}

}

Expected behavior

The code first connects sequentially three times to get a good base line of the OpenAsync times of a new connection and a reused connection from the pool.

Then it opens 100 connections in parallel first in pooled mode, then in non-pooled mode. It keeps every connection open for 4 seconds to simulate a slow query (note that even with lower query times the same problems are observed). Note that number of threads of application stays low the whole time, so this is not a thread pool issue.

In the parallel runs we log the time since the start of the experiment to ensure that delays are not due to slow thread pool scheduling. All these numbers are very low and show that all OpenAsync calls are more or less done at the same time. Note that CPU usage is also extremely low during these tests.

The second displayed time shows the time it took till for OpenAsync to return.

Note that doing the total test of 100 queries in non-pooled mode is on average twice as fast as in pooled mode which is very unexpected.

Even in non-pooled mode looking at the times it seems connections are created in batches (in this case of eight) and block the creation of new connections.

In pooled mode only one new connection to SQL server seems to get opened at a time.

In pooled mode we observe one worker thread at a time working (and mostly waiting/blocking) opening new connections. In pooled mode we observe 8 threads at a time working on new connections (and mostly waiting/blocking). It seems that the code internally for OpenAsync for opening connections seem to be blocking worker threads instead of using async to wait for the network. Note however, that this seems not to be the root cause of the slowness in opening new connections. Otherwise we would see an attempt at using more threads to open connections.

Further technical details

Microsoft.Data.SqlClient version: 2.0.0-preview4.20142.4 (same problem on 1.1.3 and on System.Data.SqlClient)
.NET target: .net Core 3.1 (Same issue on regular .net)
SQL Server version: SQL Azure
Operating system: Windows 10 (But also on Windows Server editions and on Ubuntu)

Additional context
Results obtained from test run:

WARM UP
00:00:01.3203266 3ed47bf5-3135-458c-afbb-7c1d8a4fed9d False Single open time
00:00:00.0021387 3ed47bf5-3135-458c-afbb-7c1d8a4fed9d True Single open time with one previously opened connection
ALL POOLS CLEARED
00:00:00.8309554 e40ebf65-e6ac-4a4f-a4ce-343cd5f8f10c False Single open time
00:00:00.0001948 e40ebf65-e6ac-4a4f-a4ce-343cd5f8f10c True Single open time with one previously opened connection
ALL POOLS CLEARED
00:00:00.8375330 ba33b7fe-ab77-43c3-abb5-8e7627f5d496 False Single open time
00:00:00.0001340 ba33b7fe-ab77-43c3-abb5-8e7627f5d496 True Single open time with one previously opened connection


CONCURRENT POOLED CONNECTIONS
ALL POOLS CLEARED
Start delay      OpenAsync time     Connection ID                        ReusedFromPool
00:00:00.0009171 00:00:00.9431287 0 3f18705a-c52d-4afd-b84f-eb0d6802d41a False
00:00:00.0072154 00:00:01.7782236 1 7385c47a-7372-46ef-b9d0-c4d3078b6e71 False
00:00:00.0076698 00:00:02.5752513 2 d9408f86-55ee-4ac1-94f8-7a63b6aa2392 False
00:00:00.0080704 00:00:03.3927741 3 c1d8e999-c036-4bb4-b4e6-482804b05143 False
00:00:00.0085352 00:00:04.3548366 4 957de7e5-a666-4410-924a-6423fb234cb4 False
00:00:00.0090255 00:00:05.1882539 5 5eeb97b1-608c-4d3f-a5e6-5a11fee50156 False
00:00:00.0094626 00:00:05.1882544 6 3f18705a-c52d-4afd-b84f-eb0d6802d41a True
00:00:00.0098549 00:00:06.1260157 7 94da8202-814b-4dd4-95c6-c0114e28bb33 False
00:00:00.0101717 00:00:06.1256924 8 7385c47a-7372-46ef-b9d0-c4d3078b6e71 True
00:00:00.0104807 00:00:06.9705199 9 d859272d-c6c3-4792-b8ab-fee5b1b6d35d False
00:00:00.0107941 00:00:06.9703312 10 d9408f86-55ee-4ac1-94f8-7a63b6aa2392 True
00:00:00.0111062 00:00:07.9178724 11 9b44a56e-fa2d-4ac2-a625-bcf65871fb06 False
00:00:00.0113950 00:00:07.9175811 12 c1d8e999-c036-4bb4-b4e6-482804b05143 True
00:00:00.0116639 00:00:08.7822981 13 6baa5a1d-3b90-4987-a15e-fce475baf607 False
00:00:00.0119990 00:00:08.7820060 14 957de7e5-a666-4410-924a-6423fb234cb4 True
00:00:00.0123118 00:00:09.6348765 15 815f751b-ba0c-479d-ab8a-327ea3e078b0 False
00:00:00.0125002 00:00:09.6347587 16 3f18705a-c52d-4afd-b84f-eb0d6802d41a True
00:00:00.0127372 00:00:09.6346398 17 5eeb97b1-608c-4d3f-a5e6-5a11fee50156 True
00:00:00.0129625 00:00:10.4972251 18 b08a8c47-5721-48ad-82c1-6191b5c1e588 False
00:00:00.0134389 00:00:10.4968212 20 94da8202-814b-4dd4-95c6-c0114e28bb33 True
00:00:00.0132040 00:00:10.4970294 19 7385c47a-7372-46ef-b9d0-c4d3078b6e71 True
00:00:00.0136632 00:00:11.3346273 21 df93b12f-ee15-4425-aa81-bfd9a2aaba5a False
00:00:00.0139049 00:00:11.3345546 22 d9408f86-55ee-4ac1-94f8-7a63b6aa2392 True
00:00:00.0141698 00:00:11.3345670 23 d859272d-c6c3-4792-b8ab-fee5b1b6d35d True
00:00:00.0144175 00:00:12.1801269 24 012e06ab-1fd1-4611-b428-880e490747b4 False
00:00:00.0146370 00:00:12.1799529 25 9b44a56e-fa2d-4ac2-a625-bcf65871fb06 True
00:00:00.0148358 00:00:12.1799797 26 c1d8e999-c036-4bb4-b4e6-482804b05143 True
00:00:00.0150640 00:00:12.9915829 27 c8b47e2a-124c-4e85-a649-ee43c070029f False
00:00:00.0152143 00:00:12.9914348 28 6baa5a1d-3b90-4987-a15e-fce475baf607 True
00:00:00.0153475 00:00:12.9913237 29 957de7e5-a666-4410-924a-6423fb234cb4 True
00:00:00.0155914 00:00:13.8347511 31 5eeb97b1-608c-4d3f-a5e6-5a11fee50156 True
00:00:00.0157942 00:00:13.8345878 32 3f18705a-c52d-4afd-b84f-eb0d6802d41a True
00:00:00.0159306 00:00:13.8348588 33 815f751b-ba0c-479d-ab8a-327ea3e078b0 True
00:00:00.0154739 00:00:13.8349024 30 740c33a5-85a7-4c97-82dd-f7339679fcfe False
00:00:00.0161629 00:00:14.6559129 34 7419a61b-42c5-40aa-810a-02b770e69378 False
00:00:00.0164252 00:00:14.6557047 36 94da8202-814b-4dd4-95c6-c0114e28bb33 True
00:00:00.0165175 00:00:14.6556305 37 7385c47a-7372-46ef-b9d0-c4d3078b6e71 True
00:00:00.0162897 00:00:14.6558366 35 b08a8c47-5721-48ad-82c1-6191b5c1e588 True
00:00:00.0166906 00:00:15.4744707 38 35e77023-4eec-4421-992e-06f984fb4eda False
00:00:00.0170624 00:00:15.4743611 41 d859272d-c6c3-4792-b8ab-fee5b1b6d35d True
00:00:00.0169470 00:00:15.4743077 40 d9408f86-55ee-4ac1-94f8-7a63b6aa2392 True
00:00:00.0168105 00:00:15.4744503 39 df93b12f-ee15-4425-aa81-bfd9a2aaba5a True
00:00:00.0172026 00:00:16.2950864 42 5e254da9-f6e0-480d-a7a1-113b050c6f27 False
00:00:00.0173236 00:00:16.2949979 43 c1d8e999-c036-4bb4-b4e6-482804b05143 True
00:00:00.0175217 00:00:16.2951648 45 9b44a56e-fa2d-4ac2-a625-bcf65871fb06 True
00:00:00.0174389 00:00:16.2949583 44 012e06ab-1fd1-4611-b428-880e490747b4 True
00:00:00.0176272 00:00:17.1048935 46 ed96c994-ccc9-47fc-84fc-efb6e71147ca False
00:00:00.0177680 00:00:17.1048173 47 6baa5a1d-3b90-4987-a15e-fce475baf607 True
00:00:00.0178830 00:00:17.1047111 48 957de7e5-a666-4410-924a-6423fb234cb4 True
00:00:00.0180121 00:00:17.1046429 49 c8b47e2a-124c-4e85-a649-ee43c070029f True
00:00:00.0181488 00:00:17.9378530 50 e064dc06-71ce-453c-b9a3-0250c7e1be2a False
00:00:00.0183879 00:00:17.9376187 52 3f18705a-c52d-4afd-b84f-eb0d6802d41a True
00:00:00.0182909 00:00:17.9377202 51 815f751b-ba0c-479d-ab8a-327ea3e078b0 True
00:00:00.0184989 00:00:17.9375345 53 740c33a5-85a7-4c97-82dd-f7339679fcfe True
00:00:00.0186764 00:00:17.9374013 54 5eeb97b1-608c-4d3f-a5e6-5a11fee50156 True
00:00:00.0188466 00:00:18.7644839 55 a482b6ee-2c2f-42ad-9d7e-e56846c14d61 False
00:00:00.0190005 00:00:18.7643761 56 b08a8c47-5721-48ad-82c1-6191b5c1e588 True
00:00:00.0191638 00:00:18.7642665 57 7385c47a-7372-46ef-b9d0-c4d3078b6e71 True
00:00:00.0193381 00:00:18.7641476 58 94da8202-814b-4dd4-95c6-c0114e28bb33 True
00:00:00.0195314 00:00:18.7640385 59 7419a61b-42c5-40aa-810a-02b770e69378 True
00:00:00.0196506 00:00:19.5878196 60 8fa4dd6d-9501-4d3d-b7c9-84f20d2e31e0 False
00:00:00.0198747 00:00:19.5876152 61 35e77023-4eec-4421-992e-06f984fb4eda True
00:00:00.0200245 00:00:19.5875333 62 df93b12f-ee15-4425-aa81-bfd9a2aaba5a True
00:00:00.0201936 00:00:19.5873959 63 d9408f86-55ee-4ac1-94f8-7a63b6aa2392 True
00:00:00.0203734 00:00:19.5872999 64 d859272d-c6c3-4792-b8ab-fee5b1b6d35d True
00:00:00.0205397 00:00:20.4272665 65 56b40e9a-6034-4007-b285-23c96fe3293e False
00:00:00.0207900 00:00:20.4270913 66 9b44a56e-fa2d-4ac2-a625-bcf65871fb06 True
00:00:00.0209187 00:00:20.4269767 67 c1d8e999-c036-4bb4-b4e6-482804b05143 True
00:00:00.0210743 00:00:20.4268443 68 012e06ab-1fd1-4611-b428-880e490747b4 True
00:00:00.0211555 00:00:20.4267739 69 5e254da9-f6e0-480d-a7a1-113b050c6f27 True
00:00:00.0212630 00:00:21.2580633 70 b3141e98-6467-4919-ad90-1bb122a4d775 False
00:00:00.0214264 00:00:21.2579739 72 c8b47e2a-124c-4e85-a649-ee43c070029f True
00:00:00.0213442 00:00:21.2580963 71 6baa5a1d-3b90-4987-a15e-fce475baf607 True
00:00:00.0215609 00:00:21.2579599 73 ed96c994-ccc9-47fc-84fc-efb6e71147ca True
00:00:00.0217174 00:00:21.2579228 74 957de7e5-a666-4410-924a-6423fb234cb4 True
00:00:00.0219972 00:00:22.0892099 77 740c33a5-85a7-4c97-82dd-f7339679fcfe True
00:00:00.0222874 00:00:22.0890948 80 5eeb97b1-608c-4d3f-a5e6-5a11fee50156 True
00:00:00.0218242 00:00:22.0893555 75 6b26fd72-0c0f-4d67-866b-e16832d1a020 False
00:00:00.0220810 00:00:22.0891502 78 e064dc06-71ce-453c-b9a3-0250c7e1be2a True
00:00:00.0222042 00:00:22.0890623 79 3f18705a-c52d-4afd-b84f-eb0d6802d41a True
00:00:00.0219162 00:00:22.0892959 76 815f751b-ba0c-479d-ab8a-327ea3e078b0 True
00:00:00.0223719 00:00:22.9019644 81 53dea494-8023-442e-b35b-2886a087512a False
00:00:00.0228857 00:00:22.9017196 86 a482b6ee-2c2f-42ad-9d7e-e56846c14d61 True
00:00:00.0228039 00:00:22.9018486 85 7419a61b-42c5-40aa-810a-02b770e69378 True
00:00:00.0226841 00:00:22.9018725 84 94da8202-814b-4dd4-95c6-c0114e28bb33 True
00:00:00.0225875 00:00:22.9019097 83 7385c47a-7372-46ef-b9d0-c4d3078b6e71 True
00:00:00.0224887 00:00:22.9019135 82 b08a8c47-5721-48ad-82c1-6191b5c1e588 True
00:00:00.0229687 00:00:23.7220373 87 4712191e-622b-427f-9b78-712b3485800a False
00:00:00.0233975 00:00:23.7217751 92 8fa4dd6d-9501-4d3d-b7c9-84f20d2e31e0 True
00:00:00.0230647 00:00:23.7220062 88 df93b12f-ee15-4425-aa81-bfd9a2aaba5a True
00:00:00.0232251 00:00:23.7218647 90 d9408f86-55ee-4ac1-94f8-7a63b6aa2392 True
00:00:00.0231460 00:00:23.7219399 89 d859272d-c6c3-4792-b8ab-fee5b1b6d35d True
00:00:00.0233148 00:00:23.7218031 91 35e77023-4eec-4421-992e-06f984fb4eda True
00:00:00.0234788 00:00:25.0500933 93 a9a0b6a9-73f2-4c91-95af-09fbd3d946f5 False
00:00:00.0236017 00:00:25.0500057 94 012e06ab-1fd1-4611-b428-880e490747b4 True
00:00:00.0237120 00:00:25.0499216 95 9b44a56e-fa2d-4ac2-a625-bcf65871fb06 True
00:00:00.0237925 00:00:25.0498670 96 c1d8e999-c036-4bb4-b4e6-482804b05143 True
00:00:00.0239113 00:00:25.0498248 97 5e254da9-f6e0-480d-a7a1-113b050c6f27 True
00:00:00.0240025 00:00:25.0497718 98 56b40e9a-6034-4007-b285-23c96fe3293e True
00:00:00.0240937 00:00:25.8741867 99 09335432-62e5-4b66-bebd-24bc0d2831d2 False
00:00:29.9078228 100 connections opened in paralel


CONCURRENT NON-POOLED CONNECTIONS
ALL POOLS CLEARED
Start delay      OpenAsync time     Connection ID                        ReusedFromPool
00:00:00.0082260 00:00:00.8791363 1 8731f258-004c-497f-b2a4-25552e26d729 False
00:00:00.0350304 00:00:00.8652540 3 17f15f45-b019-429c-9d3f-8899fe1df403 False
00:00:00.0371347 00:00:00.8631625 5 4e49a0b4-c08b-4a32-ba41-4089b1bead79 False
00:00:00.0360206 00:00:00.8642774 4 e7465ab5-8c7f-4c0e-bcdd-d6013976c179 False
00:00:00.0000371 00:00:00.8998700 0 b5e8c122-4062-4355-82fd-eda3fae4e523 False
00:00:00.0200965 00:00:00.8982651 2 a8e63ae5-3dbe-4069-8a67-c2995a76fc2f False
00:00:00.0571568 00:00:00.8762416 6 271a82a0-9ddc-406f-a2a6-98e13a57b27b False
00:00:00.0582054 00:00:00.8899584 7 b6bfeb52-20e9-48ee-a563-1ff8c8cbaebd False
00:00:00.0684170 00:00:01.6434896 9 0dc9ede3-b4e9-417c-91c3-90b98823c7fa False
00:00:00.0688354 00:00:01.6937596 12 bae994c0-9125-4827-b77a-139d56f11f89 False
00:00:00.0680801 00:00:01.7104839 8 f3f6092c-4819-4c98-b612-c3b36acd9e8b False
00:00:00.0689648 00:00:01.7096002 13 1edda644-fc71-4b37-9199-187d305c2085 False
00:00:00.0691544 00:00:01.7206482 14 a887b006-c62c-4427-9bc0-d4ea12869c27 False
00:00:00.0693677 00:00:01.7278080 15 3beae8d2-1021-4a09-9bfc-84ece5f22f95 False
00:00:00.0685392 00:00:01.7524461 10 e4e1dc62-5da7-42c7-b672-a966f0e3834d False
00:00:00.0686659 00:00:01.8065612 11 72c8444f-b9df-4e0a-b06a-328ddc24c1d6 False
00:00:00.0697225 00:00:02.5167275 17 ee4c4888-269b-406e-8e81-2624b815c17f False
00:00:00.0702812 00:00:02.5473149 20 53c6083b-0211-4b0d-9d9e-906906281f1f False
00:00:00.0695300 00:00:02.5659749 16 abcec0f6-6385-47b9-b6b7-8c3d234b093d False
00:00:00.0704230 00:00:02.5745920 21 cc2c0bcc-bb38-4d84-a6b6-667780e4c7f2 False
00:00:00.0707054 00:00:02.5826280 22 88cb769e-b322-492b-a338-9c6e2039bf85 False
00:00:00.0698824 00:00:02.6065776 18 d7fdb271-d8e7-4a84-947e-ac95a81ff6f3 False
00:00:00.0708796 00:00:02.6286011 23 04c3acd2-51c1-49dd-8f68-414082606868 False
00:00:00.0700641 00:00:02.6421916 19 a6e22387-1ca4-4325-b6bd-1d032a760087 False
00:00:00.0715125 00:00:03.3698606 28 ef539a49-720d-48ba-8e70-6c046f61fd89 False
00:00:00.0716264 00:00:03.3854168 29 b2d50bb7-0aa8-42de-afca-18b5498eda9d False
00:00:00.0710162 00:00:03.4017447 24 80ed7be9-099e-458a-9842-c1136c30db0d False
00:00:00.0718106 00:00:03.4272883 30 e258160b-e0de-45cd-ba77-1b2af817328f False
00:00:00.0719921 00:00:03.4531244 31 ab0fd968-301f-4d97-9482-e9b831048b4d False
00:00:00.0712771 00:00:03.4631496 26 3fb9ac94-71bd-4bfa-9269-baa97eb91ee6 False
00:00:00.0714134 00:00:03.4958048 27 4707197c-bafa-4937-9564-79b568949fc9 False
00:00:00.0711336 00:00:04.0101721 25 e16b12ac-5601-41ee-9c04-2950a252ddc8 False
00:00:00.0728221 00:00:04.2175383 36 0c303f53-1535-41ee-bdfd-d153671c2ee4 False
00:00:00.0721636 00:00:04.2292704 32 f41fd3cc-7c54-4d90-8c16-a375c608c85d False
00:00:00.0730081 00:00:04.2558787 37 366255a8-220e-40f6-9839-5731de3a5c6d False
00:00:00.0731411 00:00:04.2677209 38 c1e20e7d-783c-4792-8287-b93c339f5ef3 False
00:00:00.0724948 00:00:04.2981276 34 ee8f7d85-e807-4eee-bea1-c01d9cecabfd False
00:00:00.0732596 00:00:04.3059342 39 ae67dc4d-93f0-4799-8074-b572ff5501fe False
00:00:00.0726470 00:00:04.3136311 35 e365336b-822d-4fc6-a610-35a26861d71a False
00:00:00.0722916 00:00:05.0003683 33 04899942-88f2-4338-a0fb-cbddc52cdd28 False
00:00:00.0733867 00:00:05.0761585 40 5b1f2a6f-416c-40a7-9f31-3ea4e8b5740c False
00:00:00.0737738 00:00:05.0860370 44 9ae397b5-33da-45bb-b14b-19f561696a09 False
00:00:00.0738788 00:00:05.1092445 45 22989d51-2269-44d8-9bf7-8a9acdb40b84 False
00:00:00.0735618 00:00:05.1281717 42 3f3b39b0-5dc3-4441-b713-20b0fc7d6ffe False
00:00:00.0740926 00:00:05.1407761 47 75329416-2c67-42d7-a277-7a1e18872811 False
00:00:00.0739899 00:00:05.2262708 46 0f7e6536-2b91-483e-a299-59da9f18a676 False
00:00:00.0736598 00:00:05.2556036 43 bb42232d-305c-4715-a6d0-2b205333de6c False
00:00:00.0734775 00:00:05.8277152 41 d8a03135-1c93-4a84-b5b2-6ebf102de91e False
00:00:00.0741782 00:00:05.8981467 48 feed50c7-9557-40c2-8fbd-d0b72628d42d False
00:00:00.0746467 00:00:05.9351707 52 7657291b-8495-4de1-a0df-678e7ffcef51 False
00:00:00.0747517 00:00:05.9628818 53 4238c7e7-18dc-4833-95f7-abbdc425baf3 False
00:00:00.0744323 00:00:05.9667434 50 270c0faa-78c3-45b0-9940-bcc38521ea68 False
00:00:00.0749549 00:00:05.9916126 55 c71185e0-df71-4433-a99b-8b8f2283b5f5 False
00:00:00.0748360 00:00:06.0382909 54 a34dc629-6580-42ec-a03c-6a66e5ffe449 False
00:00:00.0745356 00:00:06.1885920 51 9d1a89d0-c294-4fec-a515-718edb776bc2 False
00:00:00.0742898 00:00:06.6767112 49 6c46ab13-6e7c-4949-99cb-449ecc76c435 False
00:00:00.0750552 00:00:06.7550748 56 5ab576c2-48f3-4e31-a234-977bbb54315d False
00:00:00.0754456 00:00:06.7788956 60 24b4f30b-bae6-4a2d-aeed-9d440f988928 False
00:00:00.0755614 00:00:06.8270143 61 b4047183-4979-43d9-83c0-176e5b538e70 False
00:00:00.0752463 00:00:06.8366775 58 00f80cc6-c9b1-4b8b-a9dc-9db1b1c97210 False
00:00:00.0757391 00:00:06.8500023 63 1310b2bb-3ef1-48b7-8a24-c27b7ee63395 False
00:00:00.0756542 00:00:06.9057249 62 596a137e-df75-44bd-86db-34c999110b92 False
00:00:00.0753376 00:00:07.1438823 59 c875a1f0-9bc2-44b1-9dc5-2ba30469aa2d False
00:00:00.0751607 00:00:07.5257331 57 58356ba6-ea73-452d-aa44-f3dc607d8a6e False
00:00:00.0758308 00:00:07.6171905 64 9346588d-70fc-403c-a420-55d83ecd3cbd False
00:00:00.0762123 00:00:07.6339721 68 41f8d753-e182-4781-942f-b0485955e882 False
00:00:00.0762974 00:00:07.6729452 69 7144364b-7b02-4283-9d94-7704da06114b False
00:00:00.0760340 00:00:07.6812526 66 e47960ce-2aac-4ee8-8875-9540a34cbfb6 False
00:00:00.0764745 00:00:07.6915261 71 f5a7d10d-a935-4638-b9d2-65e653db11a8 False
00:00:00.0763879 00:00:07.7451479 70 d2cebd2b-fc1d-41c5-8a57-3eff6ced30ad False
00:00:00.0761178 00:00:07.9741511 67 fb2c0d36-2b56-4c31-9af6-8e1f04cc89b2 False
00:00:00.0759295 00:00:08.3640216 65 864ded55-c992-4375-a233-a95260fe75c3 False
00:00:00.0765942 00:00:08.4569460 72 debb7cad-6a0b-43c2-8433-b16f43cf50eb False
00:00:00.0769734 00:00:08.4853892 76 0e8365d0-c847-4266-ae52-3980f141f246 False
00:00:00.0767699 00:00:08.5296376 74 7cb528ae-fd19-468a-9cbe-ed41713d674e False
00:00:00.0772640 00:00:08.5375782 79 d3e56ddd-3157-40ff-85a7-e14694a565ee False
00:00:00.0771791 00:00:08.5838424 78 d886230f-d5e0-438e-88de-7f26cfa702bd False
00:00:00.0770874 00:00:08.6423799 77 473a7f6b-0250-41c1-a22e-ff45fff065c8 False
00:00:00.0768533 00:00:08.8495856 75 0b6836f4-72fb-4619-926a-ab34e5fb3f73 False
00:00:00.0766794 00:00:09.2128967 73 ee72ffeb-af13-4846-af89-bdb2cb827cd2 False
00:00:00.0774130 00:00:09.2726382 80 c84168b8-5f11-4b23-a390-6722cda4cac6 False
00:00:00.0777960 00:00:09.3322906 84 8e339bfd-b0b5-4291-b86a-0e3541d2368a False
00:00:00.0780933 00:00:09.3622697 87 3891adf7-4a86-43b5-bc78-e3b99da7b4c5 False
00:00:00.0776200 00:00:09.3807072 82 e43e999e-d88e-48e0-840e-72db230f8fb3 False
00:00:00.0780089 00:00:09.4039901 86 717eff11-d5d6-4f9e-813a-7ce5b3eda339 False
00:00:00.0778938 00:00:09.5096703 85 a0722782-3818-48d2-9c21-39af8f72d057 False
00:00:00.0777114 00:00:09.6978332 83 456a93a6-3cb7-4ba1-91ab-2990499f828d False
00:00:00.0775323 00:00:10.0408988 81 00dd42c3-f5ec-499a-b257-ca1bd4af9e27 False
00:00:00.0781787 00:00:10.1375742 88 d5a595e3-338b-434b-9950-1580b1fa3517 False
00:00:00.0785687 00:00:10.1639699 92 c79dd1d5-bc64-4a95-9eb9-661b2dcc481f False
00:00:00.0787588 00:00:10.2344570 94 17b13eda-16b0-4bea-8fc7-d437b9783093 False
00:00:00.0783596 00:00:10.3108077 90 3629a7f2-5db9-444c-8fd8-3fe4f2d528b0 False
00:00:00.0788632 00:00:10.3322536 95 243ce086-72f5-4232-8cd4-a2464464daf9 False
00:00:00.0786604 00:00:10.3564750 93 09edbf53-f941-432c-a1a3-ef1052c1a7e7 False
00:00:00.0784644 00:00:10.6122603 91 e7acdcfd-6224-4cc4-b106-0ce55486a017 False
00:00:00.0782738 00:00:10.9160100 89 eaaab7ec-48d0-418d-88ab-f9ddf03e62e2 False
00:00:00.0789701 00:00:10.9910167 96 f96aec13-5c90-4be2-a40c-ce3c470b39a0 False
00:00:00.0791587 00:00:11.1634095 98 a2116011-1a36-453b-8269-ccd09469a7ab False
00:00:00.0792433 00:00:11.4738357 99 23bb5ff1-46ab-4091-8d1f-fde2cff4fb78 False
00:00:00.0790698 00:00:11.7702779 97 64883b3c-9ae4-4d9b-99ea-bf4f5b8f0cd4 False
00:00:15.8613486 100 connections opened in paralel

Testing finished