[CDRIVER-4511] Trace logs for Atlas Serverless connection includes a lot of socket_poll output Created: 24/Oct/22  Updated: 24/Oct/22

Status: Backlog
Project: C Driver
Component/s: OCSP, tls
Affects Version/s: None
Fix Version/s: None

Type: Task Priority: Minor - P4
Reporter: Jeremy Mikola Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File serverless.log    
Issue Links:
Related

 Description   

While testing OCSP behavior in the PHP driver (1.15-dev branch using libmongoc 1.23-dev) against Atlas Serverless, I noted that the libmongoc trace logs had about 15MB worth of redundant socket_poll() logs constantly emitted every 3-4 microseconds over the span of about two seconds.

[2022-10-24T04:00:20.721645+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_poll():228
[2022-10-24T04:00:20.721664+00:00]     socket: TRACE   > ENTRY: mongoc_socket_poll():297
[2022-10-24T04:00:20.721683+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_poll():254

While there is an entry/exit for mongoc_stream_tls_openssl_new shortly before the spam starts, the majority of TLS tracing (including all references to OCSP) appears after the large block of socket_poll traces. I've attached the full trace log to this ticket.

The PHP script itself was quite simple (connect and ping):

<?php
 
ini_set('mongodb.debug', 'stderr');
 
$manager = new MongoDB\Driver\Manager('mongodb+srv://...')
$manager->executeCommand('admin', new MongoDB\Driver\Command(['ping' => 1]));


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