[CDRIVER-3404] Assertion hit when handshake runs against unknown server type Created: 21/Oct/19  Updated: 28/Oct/23  Resolved: 07/Jan/20

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

Type: Bug Priority: Major - P3
Reporter: Marc Dickenson Assignee: Kevin Albertson
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related
related to CDRIVER-3563 Cursor may use an invalidated server ... Closed

 Description   

Is this SIGABRT while reading records from Mongo using MongoC a bug in the driver itself?

Here is the stack trace:
Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7fc504c0c700 (LWP 10312)]
0x00007fc5b090e2c7 in raise () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install bzip2-libs-1.0.6-13.el7.x86_64 elfutils-libelf-0.172-2.el7.x86_64 elfutils-libs-0.172-2.el7.x86_64 libattr-2.4.46-13.el7.x86_64 libcap-2.22-9.el7.x86_64 systemd-libs-219-62.el7_6.9.x86_64 xz-libs-5.2.2-1.el7.x86_64
(gdb) bt
#0 0x00007fc5b090e2c7 in raise () from /lib64/libc.so.6
#1 0x00007fc5b090f9b8 in abort () from /lib64/libc.so.6
#2 0x00007fc5b0f05ce7 in mongoc_cmd_parts_assemble (parts=parts@entry=0x7fc504c0b100, server_stream=, error=error@entry=0x7fc5382e9ac0) at /home/bmatteso@us.ibm.com/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cmd.c:804
#3 0x00007fc5b0eeb6e1 in mongoc_cluster_run_command_parts (cluster=0x7fc51a9771b8, server_stream=, parts=0x7fc504c0b100, reply=0x7fc504c0ae80, error=0x7fc5382e9ac0)
at /home/bmatteso@us.ibm.com/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:728
#4 0x00007fc5b0eecbae in _mongoc_stream_run_ismaster (error=0x7fc5382e9ac0, negotiate_sasl_supported_mechs=, server_id=1, address=, stream=, cluster=0x7fc51a9771b8)
at /home/bmatteso@us.ibm.com/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:799
#5 _mongoc_cluster_run_ismaster (error=0x7fc5382e9ac0, server_id=1, node=0x7fc538429ba0, cluster=0x7fc51a9771b8) at /home/bmatteso@us.ibm.com/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:879
#6 _mongoc_cluster_add_node (error=0x7fc5382e9ac0, server_id=1, cluster=0x7fc51a9771b8) at /home/bmatteso@us.ibm.com/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:1724
#7 mongoc_cluster_fetch_stream_pooled (error=0x7fc5382e9ac0, reconnect_ok=, server_id=1, cluster=0x7fc51a9771b8) at /home/bmatteso@us.ibm.com/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:2066
#8 _mongoc_cluster_stream_for_server (cluster=0x7fc51a9771b8, server_id=1, reconnect_ok=reconnect_ok@entry=true, cs=0x0, reply=reply@entry=0x7fc504c0b500, error=error@entry=0x7fc5382e9ac0)
at /home/bmatteso@us.ibm.com/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:1841
#9 0x00007fc5b0eed95e in _mongoc_cluster_stream_for_optype (cluster=, optype=optype@entry=MONGOC_SS_READ, read_prefs=, cs=, reply=reply@entry=0x7fc504c0b500, error=error@entry=0x7fc5382e9ac0)
at /home/bmatteso@us.ibm.com/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:2252
#10 0x00007fc5b0eed9c5 in mongoc_cluster_stream_for_reads (cluster=, read_prefs=, cs=, reply=reply@entry=0x7fc504c0b500, error=error@entry=0x7fc5382e9ac0)
at /home/bmatteso@us.ibm.com/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:2290
#11 0x00007fc5b0ef4d34 in _mongoc_cursor_fetch_stream (cursor=cursor@entry=0x7fc5382e9900) at /home/bmatteso@us.ibm.com/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cursor.c:659
#12 0x00007fc5b0ef7e53 in _prime (cursor=0x7fc5382e9900) at /home/bmatteso@us.ibm.com/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cursor-find.c:40
#13 0x00007fc5b0ef5a7b in _call_transition (cursor=0x7fc5382e9900) at /home/bmatteso@us.ibm.com/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cursor.c:1196
#14 mongoc_cursor_next (cursor=0x7fc5382e9900, bson=0x7fc504c0b9b8) at /home/bmatteso@us.ibm.com/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cursor.c:1272
#15 0x00007fc5b4e2d545 in ism_proxy::ActivityDBClient::read (this=0x7fc51a9c2e30, client_state=0x7fc54cfa9660) at /home/hari.palleti@ibm.com/workspace/server_proxy/src/activity/ActivityDBClient.cpp:755
#16 0x00007fc5b4e4e79d in ism_proxy::ActivityWorker::write_new_record (this=0x7fc54cfa9580, update=std::shared_ptr (count 3, weak 0) 0x7fc54cfa97f0) at /home/hari.palleti@ibm.com/workspace/server_proxy/src/activity/ActivityWorker.cpp:499
#17 0x00007fc5b4e4cc52 in ism_proxy::ActivityWorker::run (this=0x7fc54cfa9580) at /home/hari.palleti@ibm.com/workspace/server_proxy/src/activity/ActivityWorker.cpp:241
#18 0x00007fc5b4e537ff in std::Mem_fn<void (ism_proxy::ActivityWorker::)()>::operator()<, void>(ism_proxy::ActivityWorker_) const (this=0x7fc51b4055b8, __object=0x7fc54cfa9580) at /usr/include/c++/4.8.2/functional:601
#19 0x00007fc5b4e5370b in std::Bind_simple<std::_Mem_fn<void (ism_proxy::ActivityWorker::)()> (ism_proxy::ActivityWorker_)>::_M_invoke<0ul>(std::_Index_tuple<0ul>) (this=0x7fc51b4055b0) at /usr/include/c++/4.8.2/functional:1732
#20 0x00007fc5b4e535c9 in std::Bind_simple<std::_Mem_fn<void (ism_proxy::ActivityWorker::)()> (ism_proxy::ActivityWorker_)>::operator()() (this=0x7fc51b4055b0) at /usr/include/c++/4.8.2/functional:1720
#21 0x00007fc5b4e53518 in std::thread::Impl<std::_Bind_simple<std::_Mem_fn<void (ism_proxy::ActivityWorker::)()> (ism_proxy::ActivityWorker_)> >::_M_run() (this=0x7fc51b405598) at /usr/include/c++/4.8.2/thread:115
#22 0x00007fc5b0470070 in ?? () from /lib64/libstdc++.so.6
#23 0x00007fc5b0cacdd5 in start_thread () from /lib64/libpthread.so.0
#24 0x00007fc5b09d602d in clone () from /lib64/libc.so.6
(gdb)



 Comments   
Comment by Githook User [ 07/Jan/20 ]

Author:

{'name': 'Kevin Albertson', 'email': 'kevin.albertson@mongodb.com', 'username': 'kevinAlbs'}

Message: CDRIVER-3404 fix test
Branch: master
https://github.com/mongodb/mongo-c-driver/commit/7f5971d3f6fa9f7d7f4b3fb0886721d8ea1a7e3b

Comment by Githook User [ 07/Jan/20 ]

Author:

{'name': 'Kevin Albertson', 'email': 'kevin.albertson@mongodb.com', 'username': 'kevinAlbs'}

Message: CDRIVER-3404 error for cmds on unknown servers

Comment by Kevin Albertson [ 30/Dec/19 ]

Hi mdickens@us.ibm.com and alexey.khrolenko@gmail.com, thank you for the patch. We intend to fix this in 1.16.0, but need a bit more time to incorporate the patch and fix a separate test failure.

Comment by Alexey Khrolenko [ 24/Nov/19 ]

Slightly adjusted patch version:

diff --git a/libmongoc/src/mongoc/mongoc-cmd.c b/libmongoc/src/mongoc/mongoc-cmd.c
index 6e445a4..5143535 100644
--- a/libmongoc/src/mongoc/mongoc-cmd.c
+++ b/libmongoc/src/mongoc/mongoc-cmd.c
@@ -806,0 +807,8 @@ mongoc_cmd_parts_assemble (mongoc_cmd_parts_t *parts,
+
+   if (server_type == MONGOC_SERVER_UNKNOWN) {
+      if (error) {
+         memcpy(error, &server_stream->sd->error, sizeof *error);
+      }
+      RETURN (false);
+   }
+

Comment by Marc Dickenson [ 18/Nov/19 ]

Hi, We tested with the patch from Alexey above and it fixed it. Can this patch be included in the next release?

Comment by Marc Dickenson [ 01/Nov/19 ]

Hi Kevin , we think it recreated with more trace. 

These are the last trace lines in the our  trace file and MongoC completely stopped producing trace after that, and our app restarted (probably SIGABORT)

T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream Message: EXIT: mongoc_stream_writev():167 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream-tls-openssl-bio Message:TRACE: mongoc_stream_tls_openssl_bio_write():282 Completed the 588 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream-tls-openssl-bio Message: EXIT: mongoc_stream_tls_openssl_bio_write():293 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream-tls-openssl Message: EXIT: _mongoc_stream_tls_openssl_write():230 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream-tls-openssl Message: EXIT: _mongoc_stream_tls_openssl_writev():379 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream Message: EXIT: mongoc_stream_writev():167 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream Message: EXIT: mongoc_stream_buffered_writev():188 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream Message: EXIT: mongoc_stream_writev():167 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream Message:TRACE: _mongoc_stream_writev_full():442 writev returned: 559 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream Message: EXIT: _mongoc_stream_writev_full():475 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:buffer Message:ENTRY: _mongoc_buffer_append_from_stream():187 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream Message:ENTRY: mongoc_stream_read():271 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream Message:ENTRY: mongoc_stream_readv():229 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream Message:ENTRY: mongoc_stream_buffered_readv():232 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:buffer Message:ENTRY: _mongoc_buffer_fill():250 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream Message:ENTRY: mongoc_stream_read():271 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream Message:ENTRY: mongoc_stream_readv():229 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream-tls-openssl Message:ENTRY: _mongoc_stream_tls_openssl_readv():419 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream-tls-openssl-bio Message:ENTRY: mongoc_stream_tls_openssl_bio_read():207 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream Message:ENTRY: mongoc_stream_read():271 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream Message:ENTRY: mongoc_stream_readv():229 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:stream Message:ENTRY: _mongoc_stream_socket_readv():143 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:socket Message:ENTRY: mongoc_socket_recv():1062 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:socket Message:TRACE: _mongoc_socket_capture_errno():68 setting errno: 11 Resource temporarily unavailable USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:socket Message:TRACE: _mongoc_socket_errno_is_again():618 errno is: 11 USER_DATA:(null)
 2019-11-01T04:41:44.151Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6 LOG_DOMAIN:socket Message:ENTRY: _mongoc_socket_wait():148 USER_DATA:(null)
 

This Mongo trace is more matched with the Segfault that happened:

 

2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:TRACE: mongoc_stream_readv():239 readv = 0x7ff2a068ad50 [1]     USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:0214045 6c c2 5e 91 72 9e 9e  a1 02 fb bd ef 38 95 4c  E l . ^ . r . .  . . . . . 8 . L      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:mongoc       Message:ENTRY: _mongoc_openssl_check_cert():269         USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:mongoc       Message: EXIT: _mongoc_openssl_check_cert():274         USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:00420:  cf 91 3d 1d 20 1a 3d dd  31 b7 42 4b bb ac 39 82  . . = .   . = .  1 . B K . . 9 .      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:002b0:  f7 eb bd d7 b6 bf fc 6e  c1 ad 29 6d 83 13 58 12  . . . . . . . n  . . ) m . . X .      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:02150:  ef a9 d8 96 5e c9 37 11  2a 6e fe 3c 6c af cd 6c  . . . . ^ . 7 .  * n . < l . . l      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream-tls-openssl   Message: EXIT: mongoc_stream_tls_openssl_handshake():563        USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:00430:  bd d2 79 02 6d 39 c9 6e  9d a8 89 fd d1 05 3b 1a  . . y . m 9 . n  . . . . . . ; .      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:02160:  c5 b1 8f 73 28 5c a6 32  15 91 ec 59 27 fa a3 25  . . . s ( \ . 2  . . . Y ' . . %      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:cluster      Message:ENTRY: _mongoc_cluster_run_ismaster():873       USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:00000:  d3 02 00 00 45 5e d9 21  d2 3c 00 00 dd 07 00 00  . . . . E ^ . !  . < . . . . . .      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:cluster      Message:ENTRY: _mongoc_stream_run_ismaster():774        USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:0044002 20 9c f2 51 d5 c9 8e  5d cc d2 fc 20 7b 67 29  .   . . Q . . .  ] . . .   { g )      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:0217059 59 02 08 a6 f1 a9 0f  1f 8a 61 80 e3 7c 1d 85  Y Y . . . . . .  . . a . . | . .      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:0001000 00 00 00 00 be 02 00  00 03 63 75 72 73 6f 72  . . . . . . . .  . . c u r s o r      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:0045027 9a f3 ad c0 be ee 30  ea d3 7e 09 db 38 ba a8  ' . . . . . . 0  . . ~ . . 8 . .      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:02180:  f9 ee 17 e6 58 0d f0 e8  a0 89 5d 8f ca 50 3e 5c  . . . . X . . .  . . ] . . P > \      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:mongoc       Message:ENTRY: mongoc_cmd_parts_assemble():801  USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:mongoc       Message:TRACE: mongoc_cmd_parts_assemble():829 Preparing 'isMaster'     USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:002c0:  6b 65 79 49 64 00 01 02  00 00 97 13 63 5d 00 00  k e y I d . . .  . . . . c ] . .      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:00460:  4d 2f f7 55 2f ac 0e 19  0c c2 e1 e1 56 82 3a 30  M / . U / . . .  . . . . V . : 0      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:02190:  8f 54 4a 00 66 ce b4 0d  f4 e1 23 3f f9 f9 b1 66  . T J . f . . .  . . # ? . . . f      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:mongoc       Message:ENTRY: _mongoc_cmd_parts_assemble_mongod():579  USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:0047025 43 9f af 44 4f 65 96  81 ef 5b e6 9a cf d0 84  % C . . D O e .  . . [ . . . . .      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:002d0:  00 00 00 00 5d 00 00 00  a7 fc 54 ea aa 12 6b 65  . . . . ] . . .  . . T . . . k e      USER_DATA:(null)
2019-11-01T04:46:29.097Z timer1 pxconfig.c:1004: MongoC Trace: LOG_LEVEL:6       LOG_DOMAIN:stream       Message:021a0:  06 f9 3c 87 98 0b ea c0  bc 4f f0 5f 1d 3f 7e 3a  . . < . . . . .  . O . _ . ? ~ :      USER_DATA:(null)

 

Here is the backtrace:

sing host libthread_db library "/lib64/libthread_db.so.1". Core was generated by `./imaproxy -d -t /var/log/msproxy/trace.log /opt/ibm/msproxy/topicrule.json /et'. Program terminated with signal 6, Aborted. #0 0x00007fd7e67a2337 in raise () from /lib64/libc.so.6 #0 0x00007fd7e67a2337 in raise () from /lib64/libc.so.6 No symbol table info available. #1 0x00007fd7e67a3a28 in abort () from /lib64/libc.so.6 No symbol table info available. #2 0x00007fd7e6d9ace7 in mongoc_cmd_parts_assemble (parts=parts@entry=0x7fd6c17f9100, server_stream=<optimized out>, error=error@entry=0x7fd794009310) at /home/xxxxxxxx/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cmd.c:804 server_type = <optimized out> cs = <optimized out> cluster_time = 0x0 prefs = <optimized out> cmd_name = <optimized out> is_get_more = <optimized out> prefs_ptr = <optimized out> ret = false __func__ = "mongoc_cmd_parts_assemble" #3 0x00007fd7e6d806e1 in mongoc_cluster_run_command_parts (cluster=0x7fd774281d88, server_stream=<optimized out>, parts=0x7fd6c17f9100, reply=0x7fd6c17f8e80, error=0x7fd794009310) at /home/xxxxxxxxxxxx/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:728 No locals. #4 0x00007fd7e6d81bae in _mongoc_stream_run_ismaster (error=0x7fd794009310, negotiate_sasl_supported_mechs=<optimized out>, server_id=2, address=<optimized out>, stream=<optimized out>, cluster=0x7fd774281d88) at /home/xxxxxxxxxx/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:799 command = <optimized out> reply = \{flags = 11, len = 32726, padding = "\220\216\177\301\326\177", '\000' <repeats 42 times>, "\005", '\000' <repeats 15 times>, "\320\221\000\224\327\177\000\000p\220\177\301\326\177\000\000\r\227\177\301\326\177\000\000\320\221\000\224\327\177\000\000\377\377\377\377\000\000\000\000\320\221\000\224\327\177\000\000\367@\377\346\327\177\000"}
copied_command = 0x7fd7940de380
 iter =
 
{raw = 0x7fd6c17f8f70 "\021p\200>)\200\377\377\003", len = 3246362496, off = 32726, type = 3246362496, key = 32726, d1 = 3875514471, d2 = 32727, d3 = 0, d4 = 0, next_off = 3246362216, err_off = 32726, value = Unknown macro: \{value_type = 3246362220, padding = 32726, value =Unknown macro}
, v_utf8 = {str = 0x7fd6c17f8e78 "0", len = 3246362240}, v_doc = {data = 0x7fd6c17f8e78 "0", data_len = 3246362240}, v_binary = {data = 0x7fd6c17f8e78 "0", data_len = 3246362240, subtype = 32726}, v_regex = {regex = 0x7fd6c17f8e78 "0", options = 0x7fd6c17f8e80 "\v"}, v_dbpointer = {collection = 0x7fd6c17f8e78 "0", collection_len = 3246362240, oid = {bytes = "\326\177\000\000p\216\177\301\326\177\000"}}, v_code = {code = 0x7fd6c17f8e78 "0", code_len = 3246362240}, v_codewscope = {code = 0x7fd6c17f8e78 "0", scope_data = 0x7fd6c17f8e80 "\v", code_len = 3246362224, scope_len = 32726}, v_symbol = {symbol = 0x7fd6c17f8e78 "0", len = 3246362240}, v_decimal128 = {low = 140560346091128, high = 140560346091136}}}}
 rtt_msec = <optimized out>
 sd = <optimized out>
 r = <optimized out>
 parts =
 Unknown macro: {assembled =
 
{db_name = 0x7fd7e6dc0e75 "admin", query_flags = MONGOC_QUERY_SLAVE_OK, command = 0x7fd7940de380, command_name = 0x7fd7940d9cf5 "isMaster", payload = 0x0, payload_size = -1048604304, payload_identifier = 0x0, server_stream = 0x7fd7940da790, operation_id = 140560346091888, session = 0x0, is_acknowledged = true, is_txn_finish = false}
, user_query_flags = MONGOC_QUERY_SLAVE_OK, body = 0x7fd7940de380, read_concern_document = {flags = 3, len = 5, padding = "005000000000000177000000020035000t327177000000340 000t327177000000353374-!c002000000k300367"c002000000317367S343245233304 j260332346327177", '000' <repeats 18 times>, "060222177301326177000000300061000t327177000000017000000000000000000000020223000224327177000000 222177301326177000000020222177301326177000"}
 , write_concern_document = {flags = 3, len = 5, padding = "\005\000\000\000\000\002", '\000' <repeats 113 times>}, extra = {flags = 3, len = 5, padding = "\005", '\000' <repeats 118 times>}, read_prefs = 0x0, assembled_body = {flags = 3, len = 5, padding = "\005", '\000' <repeats 118 times>}, is_read_command = false, is_write_command = false, prohibit_lsid = true, allow_txn_number = MONGOC_CMD_PARTS_ALLOW_TXN_NUMBER_UNKNOWN, is_retryable_read = false, is_retryable_write = false, has_temp_session = false, client = 0x7fd774281d80}
 start = 2624786223244
 server_stream = 0x7fd7940da790
 #5 _mongoc_cluster_run_ismaster (error=0x7fd794009310, server_id=2, node=0x7fd7940a9a40, cluster=0x7fd774281d88) at /home/xxxxxxxxxxxx/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:879
 No locals.
 #6 _mongoc_cluster_add_node (error=0x7fd794009310, server_id=2, cluster=0x7fd774281d88) at /home/xxxxxxxxxxx/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:1724
 host = 0x7fd7940099c0
 stream = 0x7fd7940de830
 cluster_node = <optimized out>
 sasl_supported_mechs = {scram_sha_256 = 117, scram_sha_1 = 14}
 #7 mongoc_cluster_fetch_stream_pooled (error=0x7fd794009310, reconnect_ok=<optimized out>, server_id=2, cluster=0x7fd774281d88) at /home/xxxxxxxxxxxxx/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:2066
 topology = 0x7fd774001d10
 cluster_node = <optimized out>
 timestamp = <optimized out>
 #8 _mongoc_cluster_stream_for_server (cluster=0x7fd774281d88, server_id=2, reconnect_ok=reconnect_ok@entry=true, cs=0x0, reply=reply@entry=0x7fd6c17f9500, error=error@entry=0x7fd794009310) at /home/xxxxxxxxxxxxx/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:1841
 topology = <optimized out>
 server_stream = <optimized out>
 err_local = {domain = 3246364429, code = 32726, message = "\001\000\000\000\000\000\000\000\004V!\347\327\177\000\000\004\000\000\000\000\000\000\000L\217\177\301\326\177\000\000\004\000\000\000\000\000\000\000\r\227\177\301\326\177\000\000\000\000\000\000\001", '\000' <repeats 11 times>, "\060\221\177\301\326\177\000\000H\221\177\301\326\177\000\000\200\220\177\301\326\177\000\000\000\000\000\000\000\000\000\000P\221\000\224\327\177\000\000\021p\200>)\200\377\377\003\000\000\000\327\177", '\000' <repeats 18 times>, "\060\000\000\000[\000\000\000\360\217\177\301\326\177", '\000' <repeats 18 times>, "n\000\000\000w", '\000' <repeats 11 times>, "\357\217\177\301\326\177", '\000' <repeats 11 times>...}
 err_ptr = 0x7fd794009310
 #9 0x00007fd7e6d8295e in _mongoc_cluster_stream_for_optype (cluster=<optimized out>, optype=optype@entry=MONGOC_SS_READ, read_prefs=<optimized out>, cs=<optimized out>, reply=reply@entry=0x7fd6c17f9500, error=error@entry=0x7fd794009310) at /home/xxxxxxxxxxxx/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:2252
 server_id = <optimized out>
 topology = 0x7fd774001d10
 #10 0x00007fd7e6d829c5 in mongoc_cluster_stream_for_reads (cluster=<optimized out>, read_prefs=<optimized out>, cs=<optimized out>, reply=reply@entry=0x7fd6c17f9500, error=error@entry=0x7fd794009310) at /home/xxxxxxxxxxxx/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:2290
 prefs_override = <optimized out>
 #11 0x00007fd7e6d89d34 in _mongoc_cursor_fetch_stream (cursor=cursor@entry=0x7fd794009150) at /home/xxxxxxxxxx/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cursor.c:659
 server_stream = <optimized out>
 reply = {flags = 124, len = 0, padding = '\000' <repeats 24 times>, "\006\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\004\000\000\000\000\000\000\000 \000\000\224\327\177\000\000\200\226\177\301\326\177\000\000\300~\001\000\000\000\000\000\200\000\000\000\000\000\000\000@\221\000\224\327\177\000\000\000\000\000\000\000\000\000\000\332&\177\346\327\177\000\000\200\035(t\327\177\000\000P\221\000\224\327\177\000"}
 #12 0x00007fd7e6d8ce53 in _prime (cursor=0x7fd794009150) at /home/xxxxxxxxxxxxxx/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cursor-find.c:40
 use_find_command = <optimized out>
 server_stream = <optimized out>
 data = 0x7fd794006d30
 #13 0x00007fd7e6d8aa7b in _call_transition (cursor=0x7fd794009150) at /home/xxxxxxxxxxx/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cursor.c:1196
 state = <optimized out>
 fn = <optimized out>
 #14 mongoc_cursor_next (cursor=0x7fd794009150, bson=0x7fd6c17f99b8) at /home/xxxxxxxxxxxx/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cursor.c:1272
 ret = false
 attempted_refresh = <optimized out>
 _func_ = "mongoc_cursor_next"
 #15 0x00007fd7eacbcf23 in ism_proxy::ActivityDBClient::read (this=0x7fd7741d7120, client_state=0x7fd730fb5d30) at /home/itbld/jazz-build-engines/jazza06/jazza06.ism.ism-ilnx-c7/build/server_proxy/src/activity/ActivityDBClient.cpp:769 

we compiled with OpenSSL1.1.1c and GCC4.8.5
 

Comment by Alexey Khrolenko [ 01/Nov/19 ]

Hi! I have very similar SIGABRT in my service.

Configuration: Ubuntu Trusty, mongocxx 3.4.0, mongoc 1.15.1, sharded mongodb 4.0 with 3 mongos on remote hosts.

In logfile I have:

/mongo-c-driver/libmongoc/src/mongoc/mongoc-cmd.c:611 _mongoc_cmd_parts_assemble_mongod(): precondition failed: false

Core dump:

Program terminated with signal SIGABRT, Aborted.
#0  0x00007fa20006cc37 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:5656 ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory.(gdb) bt#0  0x00007fa20006cc37 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#1  0x00007fa200070028 in __GI_abort () at abort.c:89
#2  0x0000000003f89a74 in _mongoc_cmd_parts_assemble_mongod (parts=0x7fa1eb6d7930, server_stream=0x107a5e5c0) at /mongo-c-driver/libmongoc/src/mongoc/mongoc-cmd.c:611
#3  0x0000000003f88df1 in mongoc_cmd_parts_assemble (parts=0x7fa1eb6d7930, server_stream=0x107a5e5c0, error=0x7fa1eb6d8928) at /mongo-c-driver/libmongoc/src/mongoc/mongoc-cmd.c:977
#4  0x0000000003c8074d in mongoc_cluster_run_command_parts (cluster=0x107b5b608, server_stream=0x107a5e5c0, parts=0x7fa1eb6d7930, reply=0x7fa1eb6d66b0, error=0x7fa1eb6d8928)    at /mongo-c-driver/libmongoc/src/mongoc/mongoc-cluster.c:729
#5  0x0000000003c843c3 in _mongoc_cluster_auth_node_scram (cluster=0x107b5b608, stream=0x107a5e8c0, sd=0x106352800, algo=MONGOC_CRYPTO_ALGORITHM_SHA_256, error=0x7fa1eb6d8928)    at /mongo-c-driver/libmongoc/src/mongoc/mongoc-cluster.c:1334
#6  0x0000000003c83892 in _mongoc_cluster_auth_node_scram_sha_256 (cluster=0x107b5b608, stream=0x107a5e8c0, sd=0x106352800, error=0x7fa1eb6d8928)    at /mongo-c-driver/libmongoc/src/mongoc/mongoc-cluster.c:1446
#7  0x0000000003c82dc8 in _mongoc_cluster_auth_node (cluster=0x107b5b608, stream=0x107a5e8c0, sd=0x106352800, sasl_supported_mechs=0x7fa1eb6d7c68, error=0x7fa1eb6d8928)    at /mongo-c-driver/libmongoc/src/mongoc/mongoc-cluster.c:1507
#8  0x0000000003c849e8 in _mongoc_cluster_add_node (cluster=0x107b5b608, server_id=2, error=0x7fa1eb6d8928) at /mongo-c-driver/libmongoc/src/mongoc/mongoc-cluster.c:1734
#9  0x0000000003c80f9e in mongoc_cluster_fetch_stream_pooled (cluster=0x107b5b608, server_id=2, reconnect_ok=true, error=0x7fa1eb6d8928) at /mongo-c-driver/libmongoc/src/mongoc/mongoc-cluster.c:2087
#10 0x0000000003c80a87 in _mongoc_cluster_stream_for_server (cluster=0x107b5b608, server_id=2, reconnect_ok=true, cs=0x0, reply=0x7fa1eb6d8b28, error=0x7fa1eb6d8928)    at /mongo-c-driver/libmongoc/src/mongoc/mongoc-cluster.c:1842
#11 0x0000000003c8182d in _mongoc_cluster_stream_for_optype (cluster=0x107b5b608, optype=MONGOC_SS_READ, read_prefs=0x0, cs=0x0, reply=0x7fa1eb6d8b28, error=0x7fa1eb6d8928)    at /mongo-c-driver/libmongoc/src/mongoc/mongoc-cluster.c:2275
#12 0x0000000003c816d1 in mongoc_cluster_stream_for_reads (cluster=0x107b5b608, read_prefs=0x0, cs=0x0, reply=0x7fa1eb6d8b28, error=0x7fa1eb6d8928)    at /mongo-c-driver/libmongoc/src/mongoc/mongoc-cluster.c:2313
#13 0x0000000003c6a65e in _mongoc_client_command_with_opts (client=0x107b5b600, db_name=0x107a5eb08 "ecstatic", command=0x7fa1eb6d8be8, mode=MONGOC_CMD_RAW, opts=0x7fa1eb6d8868, flags=MONGOC_QUERY_NONE, user_prefs=0x0,    default_prefs=0x0, default_rc=0x107a5ec80, default_wc=0x107a5ebc0, reply=0x7fa1eb6d8b28, error=0x7fa1eb6d8928) at /mongo-c-driver/libmongoc/src/mongoc/mongoc-client.c:1937
#14 0x0000000003facfdd in mongoc_database_command_with_opts (database=0x107a5eb00, command=0x7fa1eb6d8be8, read_prefs=0x0, opts=0x7fa1eb6d8868, reply=0x7fa1eb6d8b28, error=0x7fa1eb6d8928)    at /mongo-c-driver/libmongoc/src/mongoc/mongoc-database.c:320
#15 0x0000000003feac9e in mongocxx::v_noabi::database::_run_command (this=0x107978460, session=0x0, command=...) at /mongo-cxx-driver/mongocxx/database.cpp:188
#16 0x0000000003feae79 in mongocxx::v_noabi::database::run_command (this=0x107978460, command=...) at /mongo-cxx-driver/mongocxx/database.cpp:203
 
(gdb) up
#1  0x00007fa200070028 in __GI_abort () at abort.c:8989 abort.c: No such file or directory.
(gdb) up
#2  0x0000000003f89a74 in _mongoc_cmd_parts_assemble_mongod (parts=0x7fa1eb6d7930, server_stream=0x107a5e5c0) at /mongo-c-driver/libmongoc/src/mongoc/mongoc-cmd.c:611611 /mongo-c-driver/libmongoc/src/mongoc/mongoc-cmd.c: No such file or directory.
(gdb) up
#3  0x0000000003f88df1 in mongoc_cmd_parts_assemble (parts=0x7fa1eb6d7930, server_stream=0x107a5e5c0, error=0x7fa1eb6d8928) at /mongo-c-driver/libmongoc/src/mongoc/mongoc-cmd.c:977977 in /mongo-c-driver/libmongoc/src/mongoc/mongoc-cmd.c
(gdb) print *server_stream->sd
$1 = {id = 2, host = {next = 0x0, host = "sas-ggiufwntkt5xh7fe.db.yandex.net", '\000' <repeats 221 times>, host_and_port = "sas-ggiufwntkt5xh7fe.db.yandex.net:27017", '\000' <repeats 221 times>, port = 27017, family = 0, padding = {0x0,      0x0, 0x0, 0x0}}, round_trip_time_msec = -1, last_update_time_usec = 743684219569, last_is_master = {flags = 3, len = 5, padding = "\005", '\000' <repeats 118 times>}, has_is_master = false,  connection_address = 0x106352110 "sas-ggiufwntkt5xh7fe.db.yandex.net:27017", me = 0x0, opened = false, set_name = 0x0, error = {domain = 2, code = 5,    message = "Failed to connect to target host: sas-ggiufwntkt5xh7fe.db.yandex.net:27017\000\003\000\000\000\000\320\"\210\003\000\000\000\000@\273\244\a\001\000\000\000\260\tn\357\241\177\000\000\245\205\302\003\000\000\000\000\320\nn\357\241\177\000\000\320\nn\357\241\177\000\000\320\nn\357\241\177\000\000\320\nn\357\241\177\000\000\320\nn\357\241\177\000\000\000\344y\a\001\000\000\000\360\tn\357\241\177\000\000\230M\374\003\000\000\000\000H\tn\357\241\177\000\000\200\200\302\a\001\000\000\000\200\nn\357\241\177\000\000"...}, type = MONGOC_SERVER_UNKNOWN, min_wire_version = 0, max_wire_version = 0, max_msg_size = 48000000, max_bson_obj_size = 16777216, max_write_batch_size = 1000,  session_timeout_minutes = -1, hosts = {flags = 3, len = 5, padding = "\005", '\000' <repeats 118 times>}, passives = {flags = 3, len = 5, padding = "\005", '\000' <repeats 118 times>}, arbiters = {flags = 3, len = 5,    padding = "\005", '\000' <repeats 118 times>}, tags = {flags = 3, len = 5, padding = "\005", '\000' <repeats 118 times>}, current_primary = 0x0, set_version = -1, election_id = {bytes = '\000' <repeats 11 times>},  last_write_date_ms = -1, compressors = {flags = 3, len = 5, padding = "\005", '\000' <repeats 118 times>}}
(gdb) print *server_stream
$2 = {topology_type = MONGOC_TOPOLOGY_SHARDED, sd = 0x106352000, cluster_time = {flags = 2, len = 88,    padding = '\000' <repeats 12 times>, "\317\317\317\317\000\346\245\a\001\000\000\000\b\346\245\a\001", '\000' <repeats 11 times>, "\200\215\227\a\001\000\000\000\200\000\000\000\000\000\000\000P\205\302\003", '\000' <repeats 12 times>, '\317' <repeats 47 times>, <incomplete sequence \317>}, stream = 0x107a5e8c0}

This case appears on bad network connections and can be reproduced with following netem settings (drop part of mongos traffic):

tc qdisc del dev eth0 root
tc qdisc add dev eth0 handle 1: root htb
tc class add dev eth0 parent 1: classid 1:1 htb
tc filter add dev eth0 parent 1: protocol ipv6 prio 1 u32 match ip6 dport 27017 0xffff flowid 1:1
tc filter add dev eth0 parent 1: protocol ipv6 prio 1 u32 match ip6 sport 27017 0xffff flowid 1:1
tc qdisc add dev eth0 parent 1:1 handle 10: netem loss 50%

Imho the reason of this issue is that sd state isn't checked in mongoc_cmd_parts_assemble and _mongoc_cmd_parts_assemble_mongod() is called as default option with MONGOC_SERVER_UNKNOWN. This patch works for me:

Index: mongoc-cluster.c
===================================================================
--- mongoc-cluster.c    (revision 5884652)
+++ mongoc-cluster.c    (working copy)
@@ -798,7 +799,7 @@
    parts.prohibit_lsid = true;
    if (!mongoc_cluster_run_command_parts (
           cluster, server_stream, &parts, &reply, error)) {
-      if (negotiate_sasl_supported_mechs) {
+      if (negotiate_sasl_supported_mechs && !bson_empty(&reply)) {
          if (bson_iter_init_find (&iter, &reply, "ok") &&
              !bson_iter_as_bool (&iter)) {
             /* ismaster response returned ok: 0. According to auth spec: "If theIndex: mongoc-cmd.c
===================================================================
--- mongoc-cmd.c        (revision 5884652)
+++ mongoc-cmd.c        (working copy)
@@ -804,6 +804,12 @@
    BSON_ASSERT (server_stream);
 
    server_type = server_stream->sd->type;
+
+   if (server_type == MONGOC_SERVER_UNKNOWN &&
+       server_stream->sd->max_wire_version == 0) {
+      return false;
+   }
+
    cs = parts->prohibit_lsid ? NULL : parts->assembled.session;
 
    /* must not be assembled already */

Comment by Marc Dickenson [ 30/Oct/19 ]

Hi Kevin,

Thanks for checking into this. Here is some more info

1.  Are you able to reproduce this, and if so, under what conditions? Is this only observed during a network error (e.g. replica set failover or a mongod is terminated)?

This problem is intermittent, there is no particular scenario for reproducing this issue.  This is consistently seen in the load test env.

2. If you can reproduce it, is it possible to reproduce with tracing enabled? To do so, configure libmongoc with -DENABLE_TRACING=ON (instructions here.

We have enabled this in our load test env, and will try to recreate it with the additional trace.

3. What platform are you using?

Centos

4. The stack trace includes references to ActivityDBClient. I assume this is C++ code calling into libmongoc. Is the libmongoc code modified in any way? How are you building with it? Is it possible to include the build commands?

Yes this is C++ code calling libmongoc. Libmongoc code hasn’t been modified.

 

Comment by Kevin Albertson [ 28/Oct/19 ]

Hi mdickens@us.ibm.com. Thank you for the report!

The stacktrace you provided is helpful, referencing the source code for libmongoc 1.15.0, this stack frame:

#4 0x00007fc5b0eecbae in _mongoc_stream_run_ismaster (error=0x7fc5382e9ac0, negotiate_sasl_supported_mechs=, server_id=1, address=, stream=, cluster=0x7fc51a9771b8)
at /home/bmatteso@us.ibm.com/mongo-c-driver-1.15.0/src/libmongoc/src/mongoc/mongoc-cluster.c:799

corresponds to this code:

   server_stream = _mongoc_cluster_create_server_stream (
      cluster->client->topology, server_id, stream, error);
   if (!server_stream) {
      bson_destroy (copied_command);
      RETURN (NULL);
   }
 
   mongoc_cmd_parts_init (
      &parts, cluster->client, "admin", MONGOC_QUERY_SLAVE_OK, command);
   parts.prohibit_lsid = true;
   if (!mongoc_cluster_run_command_parts (
          cluster, server_stream, &parts, &reply, error)) {

mongoc_cluster_run_command_parts immediately calls mongoc_cmd_parts_assemble and triggers this assertion:

BSON_ASSERT (server_stream);

It surprises me that there is a NULL check of the server_stream in the caller, and this assertion still fails. So I have a few questions:

1. Are you able to reproduce this, and if so, under what conditions? Is this only observed during a network error (e.g. replica set failover or a mongod is terminated)?
2. If you can reproduce it, is it possible to reproduce with tracing enabled? To do so, configure libmongoc with -DENABLE_TRACING=ON (instructions here.
3. What platform are you using?
4. The stack trace includes references to ActivityDBClient. I assume this is C++ code calling into libmongoc. Is the libmongoc code modified in any way? How are you building with it? Is it possible to include the build commands?

Thank you,
Kevin

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