|
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
|
|
Author:
{'name': 'Kevin Albertson', 'email': 'kevin.albertson@mongodb.com', 'username': 'kevinAlbs'}
Message: CDRIVER-3404 error for cmds on unknown servers
|
|
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.
|
|
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);
|
+ }
|
+
|
|
|
Hi, We tested with the patch from Alexey above and it fixed it. Can this patch be included in the next release?
|
|
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:02140: 45 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:00440: 02 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:02170: 59 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:00010: 00 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:00450: 27 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:00470: 25 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
|
|
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 */
|
|
|
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.
|
|
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.