[CDRIVER-3801] mongoc_client_pool_destroy performance degradation Created: 18/Sep/20  Updated: 28/Oct/23  Resolved: 13/Jan/21

Status: Closed
Project: C Driver
Component/s: None
Affects Version/s: 1.17.0
Fix Version/s: 1.18.0, 1.18.0-alpha

Type: Bug Priority: Major - P3
Reporter: Patrick Freed Assignee: Samantha Ritter (Inactive)
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related

 Description   

In libmongoc 1.17.0, calls to mongoc_client_pool_destroy take roughly 500ms, or the default value for minHeartbeatFrequencyMS. In 1.16.2 this was near instantaneous.

I'm able to observe lower shutdown times by settingĀ  MONGOC_TOPOLOGY_MIN_HEARTBEAT_FREQUENCY_MS to lower values, but the shutdown time is always at least what that value is set to.

This behavior seems buggy, though I imagine it could be an intended part of the streaming changes made for 4.4 servers like the other ticket I field.

On 1.17, the following prints about 0.5 seconds. On 1.16.2, it prints 0.00x seconds.

int main(int argc, char *argv[]) {
    const char *uri_string = "mongodb://localhost:27017/?retryReads=true";
    mongoc_uri_t *uri;
    bson_error_t error;
 
    mongoc_init();
 
    uri = mongoc_uri_new_with_error(uri_string, &error);
    if (!uri) {
        fprintf(stderr,
                "failed to parse URI: %s\n"
                "error message:       %s\n",
                uri_string, error.message);
        return EXIT_FAILURE;
    }
 
    mongoc_client_pool_t *pool = mongoc_client_pool_new(uri);
 
    mongoc_client_t *client = mongoc_client_pool_pop(pool);
    mongoc_database_t *database = mongoc_client_get_database(client, "test");
    mongoc_collection_t *collection = mongoc_database_get_collection(database, "blah");
 
    mongoc_database_command_simple(database, BCON_NEW ("ping", BCON_INT32(1)), NULL, NULL, NULL);
    mongoc_client_pool_push(pool, client);
 
    struct timeval  tv1, tv2;
    gettimeofday(&tv1, NULL);
 
    mongoc_client_pool_destroy(pool);
 
    gettimeofday(&tv2, NULL);
    printf ("Total time = %f seconds\n",
            (double) (tv2.tv_usec - tv1.tv_usec) / 1000000 +
            (double) (tv2.tv_sec - tv1.tv_sec));
    return 0;
}



 Comments   
Comment by Samantha Ritter (Inactive) [ 13/Jan/21 ]

Changed this so the minHeartbeatFrequencyMS flag can be used to offset the performance change for the Swift driver.

Comment by Githook User [ 13/Jan/21 ]

Author:

{'name': 'Samantha Ritter', 'email': 'samantha.f.ritter@gmail.com', 'username': 'samantharitter'}

Message: CDRIVER-3801 set server monitor polling time to minHeartbeatFrequencyMS (#715)
Branch: master
https://github.com/mongodb/mongo-c-driver/commit/873ceb046f95b00ec4cd3f4d07dfe9b7ae911707

Comment by Patrick Freed [ 12/Jan/21 ]

Thanks for looking into this samantha.ritter! I just re-tested it again, and I also see that different values of minHeartbeatFrequencyMS have no effect on the 500ms of blocking during shutdown. I think I may have seen a speedup elsewhere by changing the frequency which I wrongly attributed to the shutdown being faster.

Controlling the polling interval via minHeartbeatFrequencyMS sounds like a fine solution for us, since this really is only a testing issue. We expect users to use Swift MongoClients the same way they'd use mongoc_client_pool_t's, so I don't think the 500ms blocking at the end is an issue for them either.

Comment by Samantha Ritter (Inactive) [ 06/Jan/21 ]

Hi patrick.freed,

The change in performance that you are observing is related to the long polling that was added to the C driver to support streamable ismaster. The client pool now has to shut down the server monitor, which holds a set of sockets internally that it polls, using a hard-coded polling interval of 500ms. What you're observing is the destroying thread waiting for the calls to poll() to return in the background server monitor thread, which can take up to 500ms, so it can call pthread_join on that background thread and exit.

From talking with kevin.albertson about the polling implementation, this 500ms-polling strategy was chosen over other possible implementations because the other choices were either platform-dependent or would have been much more complicated to implement.

It's unfortunate that this change is causing your tests to run more slowly, but we can't think of a likely "real world" use case where a slightly slower client pool shutdown would negatively affect users. mongoc_client_pools are designed to be used so one pool is created for the lifetime of the user's program, ideally only needing to be shut down one time. Because it's unlikely that this will adversely affect users, and because redesigning the polling implementation would be complicated, we'd rather not go down that path.

As far as I can tell, it is just a coincidence that 500ms is the default minHeartbeatFrequencyMS. And though I can reproduce the slowdown in shutdown, I was unable to see this delay change by changing minHeartbeatFrequencyMS.

However, it seems like a good workaround for the Swift driver to allow the polling interval to be controlled by minHeartbeatFrequencyMS, rather than having it be hard-coded at 500ms. Would this be a good solution for you?

Thanks!
Samantha

Generated at Wed Feb 07 21:19:04 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.