[CDRIVER-4420] bson_error_t message shows garbage in some cases Created: 02/Jul/22  Updated: 27/Oct/23  Resolved: 14/Jul/22

Status: Closed
Project: C Driver
Component/s: None
Affects Version/s: None
Fix Version/s: None

Type: Bug Priority: Unknown
Reporter: Joseph Canedo Assignee: Ezra Chung
Resolution: Works as Designed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified


 Description   

Summary

In some cases printing bson_error_t message outputs garbage characters. For example: No suitable servers found (`serverSelectionTryOnce` set): [connection refused calling hello on '127.0.0.1:27017']
r��Ux
_r��U u���U`u���U�㰕�U�㰕�U�;ܖ�U�=ܖ�U�;ܖ�U�;ܖ�U�=ܖ�U�=ܖ�U���l^Jy����������l^Jy������������������������������������������l^Jy����������l^Jy��������K��_
                                                                                                                                                         __���U�;ܖ�UX9ܖ�UL��h9ܖ�U0L��`L���X���UpL��89ܖ�UPL��p<ܖ�UpL���L���X���U�kg��U89ܖ�Up<ܖ�U"._

Environment

C driver 1.22.0

Linux Ubuntu 22.10

gcc 12.1

MongoDB server 5.0.9

How to Reproduce

Happens for example with following code without MongoDB running.

char **strv = mongoc_client_get_database_names_with_opts(_client, nullptr, &error);
if (!strv)

{       HX2A_LOG(error) << "Cannot get MongoDB databases list for database identifier \"" << db_id << "\". Got error message \"" << error.message << "\".";       throw request_rollback(); }

Additional Background

Suspect that setting null char does not happen in correct position in message string in bson_set_error function. 

error->message[sizeof error->message - 1] = '\0';

Should set at whatever position after last char bson_vsnprintf writes (with check it does not overflow message buffer of course). 



 Comments   
Comment by Joseph Canedo [ 14/Jul/22 ]

Just realizing issue I get is linked to "corner" case in C++. We have an overload operator<< which takes a const char (&)[N] which expected a string literal (hence null terminated at N - 1). bson_error_t::message is a C array hence function prints it all regardless null char just after error message. I'll change code to avoid this issue.

Sorry for the spam, and thanks for having taken time to look the problem.

Comment by Joseph Canedo [ 14/Jul/22 ]

Hi Ezra, thanks for having a look. 

I've just run application without no MongoDB server running and I get this error message:

 

1 [2022-07-13 19:54:03.996230] Thread<0x00007f9a28904340> error: Cannot get MongoDB databases list for database identifier "8ee67fa16c5e4a799fc4d3ead5e51a89". Got error me�(Vs�B�$�Z�N���(V84��(V8�(Vx�(V�(V`�(V��������`�ce` set): [connection refused calling hello on '127.0.0.1:27017']��(���(�HY�(@�(V84��(V��
�(V�".ף3�(V`�

Comment by Ezra Chung [ 13/Jul/22 ]

Hello, josephcanedo@gmail.com.

I have attempted to reproduce your reported behavior using the following minimum example without success:

#include <bson/bson.h>
#include <mongoc/mongoc.h>
 
#include <assert.h>
#include <stdio.h>
 
int main(void) {
  mongoc_init ();
 
  /* No server should be running on specified host and port. */
  mongoc_client_t *const client = mongoc_client_new ("mongodb://127.0.0.1:27017/");
 
  assert (client);
 
  bson_error_t error;
 
  assert (!mongoc_client_get_database_names_with_opts (client, NULL, &error));
 
  printf ("%s\n", error.message); /* Look for garbage in resulting message. */
 
  mongoc_client_destroy (client);
 
  mongoc_cleanup ();
 
  return 0;
}

Output (no garbage observed):

No suitable servers found (`serverSelectionTryOnce` set): [connection refused calling hello on '127.0.0.1:27017']

Can you please confirm if the example above produces garbage as reported when run in your environment?

bson_set_error is implemented using bson_vsnprintf, which in turn is implemented using vsnprintf. vsnprintf is equivalent to snprintf, which has the following specification: "If n is zero, nothing is written, and s may be a null pointer. Otherwise, output characters beyond the {{n-1}}st are discarded rather than being written to the array, and a null character is written at the end of the characters actually written into the array." If the error message is set with a non-zero string length (as evidenced by the presence of the "No suitable servers found" portion of the message), it should always be null-terminated immediately after the last character written to the array accordingly.

Note: the str[size - 1] = '\0'; in bson-string.c and the error->message[sizeof error->message - 1] = '\0'; in bson-error.c are both redundant safeguards on top of vsnprintf that ensure a null terminator at the end of the message buffer. Further examination of the relevant source code does not suggest the presence of a (missing) null termination bug.

If we rule out the possibility of a bug in the implementation of vsnprintf, my best guess is that operator<< given HX2A_LOG(error) << error.message is overloaded such that, given an argument of array type, it prints every element of the array, regardless of the presence of null terminators (that is, it behaves like a "print an array" formatter rather than a "print a null-terminated byte string" formatter). This may be verified by examining whether there is a null terminator after the ']' character in the originally reported message that is being ignored.

Can you please confirm if there is a null terminator at the end of the (valid) error message (immediately following the ']') in the original output?

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