-
Type:
Bug
-
Resolution: Done
-
Priority:
Major - P3
-
Affects Version/s: 1.1.5
-
Component/s: None
-
Labels:None
Steps to reproduce:
- Populate a collection with a number of documents.
- Execute a query with a limit that would return less than the number of matched documents without said limit.
- Iterate on the cursor and allow it to be freed during standard garbage collection
A segfault can be reproduced easily via PHP 5.x's built-in web server (but not PHP 7) and querying via the legacy OP_QUERY code path (i.e. MongoDB <3.2). There appears to be a race condition between freeing the cursor and the client. If the client is freed first, the underlying stream is destroyed. When the cursor is later freed, libmongoc attempts to kill the cursor before freeing it, which results in an attempt to use a null stream pointer.
Relevant backtrace info:
(gdb) bt full
#0 0x00007f68d21b878c in mongoc_cluster_stream_for_server (cluster=0x3530740, server_id=1, reconnect_ok=false, error=0x0)
at /home/jmikola/workspace/mongodb/phpc/src/libmongoc/src/mongoc/mongoc-cluster.c:1414
topology = 0x7f68d21fd990
sd = 0x7f68d21ce910 <mongoc_log+125>
server_stream = 0x0
__func__ = "mongoc_cluster_stream_for_server"
#1 0x00007f68d21b3524 in _mongoc_client_kill_cursor (client=0x3530728, server_id=1, cursor_id=78788420618884, db=0x7ffe3a102f10 "db", collection=0x3533393 "testing")
at /home/jmikola/workspace/mongodb/phpc/src/libmongoc/src/mongoc/mongoc-client.c:1274
server_stream = 0x30bcfe0
__func__ = "_mongoc_client_kill_cursor"
#2 0x00007f68d21c1720 in _mongoc_cursor_destroy (cursor=0x3533250) at /home/jmikola/workspace/mongodb/phpc/src/libmongoc/src/mongoc/mongoc-cursor.c:273
db = "db\000\000\000\000\000\000xn\361\000\000\000\000\000\240/\020:\376\177\000\000Ļ\220", '\000' <repeats 13 times>, "p\274\220\000\000\000\000\000\200/\020:\376\177", '\000' <repeats 14 times>, "\223\000\000\000\220\331\037\322h\177\000\000\000XR\003\000\000\000\000\200\n\005\003\000\000\000\000\250WR\003\000\000\000\000\250\000\000\000\000\000\000\000\t\000\000\000\000\000\000\000`\v\005\003\000\000\000"
__func__ = "_mongoc_cursor_destroy"
#3 0x00007f68d21c1559 in mongoc_cursor_destroy (cursor=0x3533250) at /home/jmikola/workspace/mongodb/phpc/src/libmongoc/src/mongoc/mongoc-cursor.c:249
__func__ = "mongoc_cursor_destroy"
#4 0x00007f68d21fb613 in php_phongo_cursor_free (cursor=0x35317f0) at /home/jmikola/workspace/mongodb/phpc/php_phongo.c:2167
No locals.
#5 0x00007f68d217ec67 in php_phongo_cursor_free_object (object=0x35317f0, tsrm_ls=0x304e3e0) at /home/jmikola/workspace/mongodb/phpc/src/MongoDB/Cursor.c:223
intern = 0x35317f0
#6 0x0000000000995d99 in zend_objects_store_del_ref_by_handle_ex (handle=19, handlers=0x7f68d242f680 <php_phongo_handler_cursor>, tsrm_ls=0x304e3e0)
at /tmp/build_php-5.5.30.d39/php-5.5.30/Zend/zend_objects_API.c:226
__orig_bailout = 0x7ffe3a104a40
__bailout = {{__jmpbuf = {10084735, -717301010640819705, 4360000, 140729872577040, 0, 0, -717301010703734265, 718279701098637831}, __mask_was_saved = 0, __saved_mask = {
__val = {50662016, 55727872, 168, 4294967296, 50662240, 50652128, 10084735, 55603656, 55603776, 82, 9485424, 15804928, 15822456, 1279900254290, 10084735,
140729872560752}}}}
obj = 0x7f68d71eb8e8
failure = 0
#7 0x00000000009958c7 in zend_objects_store_del_ref (zobject=0x3531fb8, tsrm_ls=0x304e3e0) at /tmp/build_php-5.5.30.d39/php-5.5.30/Zend/zend_objects_API.c:178
handle = 19
#8 0x000000000094fa9f in _zval_dtor_func (zvalue=0x3531fb8, __zend_filename=0xf16e78 "/tmp/build_php-5.5.30.d39/php-5.5.30/Zend/zend_execute.h", __zend_lineno=81)
at /tmp/build_php-5.5.30.d39/php-5.5.30/Zend/zend_variables.c:54
tsrm_ls = 0x304e3e0
#9 0x0000000000997c13 in _zval_dtor (zvalue=0x3531fb8, __zend_filename=0xf16e78 "/tmp/build_php-5.5.30.d39/php-5.5.30/Zend/zend_execute.h", __zend_lineno=81)
at /tmp/build_php-5.5.30.d39/php-5.5.30/Zend/zend_variables.h:35
No locals.
#10 0x0000000000997d0d in i_zval_ptr_dtor (zval_ptr=0x3531fb8, __zend_filename=0xf16f68 "/tmp/build_php-5.5.30.d39/php-5.5.30/Zend/zend_execute.c", __zend_lineno=1510)
at /tmp/build_php-5.5.30.d39/php-5.5.30/Zend/zend_execute.h:81
tsrm_ls = 0x304e3e0
__PRETTY_FUNCTION__ = "i_zval_ptr_dtor"
#11 0x000000000099d8d5 in i_free_compiled_variables (execute_data=0x7f68d71cf1a0) at /tmp/build_php-5.5.30.d39/php-5.5.30/Zend/zend_execute.c:1510
cv = 0x7f68d71cf238
end = 0x7f68d71cf240
#12 0x000000000099e3e2 in zend_leave_helper_SPEC (execute_data=0x7f68d71cf1a0, tsrm_ls=0x304e3e0) at /tmp/build_php-5.5.30.d39/php-5.5.30/Zend/zend_vm_execute.h:399
nested = 0 '\000'
op_array = 0x34b8c30
#13 0x00000000009a4b90 in ZEND_RETURN_SPEC_CONST_HANDLER (execute_data=0x7f68d71cf1a0, tsrm_ls=0x304e3e0) at /tmp/build_php-5.5.30.d39/php-5.5.30/Zend/zend_vm_execute.h:2376
opline = 0x34bce60
retval_ptr = 0x34bfec0
#14 0x000000000099e239 in execute_ex (execute_data=0x7f68d71cf1a0, tsrm_ls=0x304e3e0) at /tmp/build_php-5.5.30.d39/php-5.5.30/Zend/zend_vm_execute.h:363
ret = 0
original_in_execution = 1 '\001'
#15 0x000000000099e322 in zend_execute (op_array=0x34b8c30, tsrm_ls=0x304e3e0) at /tmp/build_php-5.5.30.d39/php-5.5.30/Zend/zend_vm_execute.h:388
No locals.
#16 0x000000000093da80 in zend_call_function (fci=0x7ffe3a103600, fci_cache=0x7ffe3a1035d0, tsrm_ls=0x304e3e0) at /tmp/build_php-5.5.30.d39/php-5.5.30/Zend/zend_execute_API.c:934
i = 0
original_return_value = 0x0
calling_symbol_table = 0x3051b68
original_op_array = 0x7f68d7207e98
Logging via mongodb.debug yields the following trace information immediately before the segfault:
[2016-04-12T21:26:16+00:00] mongoc: TRACE > ENTRY: _mongoc_write_command_destroy():994 [2016-04-12T21:26:16+00:00] mongoc: TRACE > EXIT: _mongoc_write_command_destroy():1000 [2016-04-12T21:26:16+00:00] mongoc: TRACE > ENTRY: _mongoc_write_result_destroy():1024 [2016-04-12T21:26:16+00:00] mongoc: TRACE > EXIT: _mongoc_write_result_destroy():1032 [2016-04-12T21:26:16+00:00] mongoc: TRACE > ENTRY: mongoc_topology_description_destroy():89 [2016-04-12T21:26:16+00:00] mongoc: TRACE > ENTRY: mongoc_server_description_destroy():145 [2016-04-12T21:26:16+00:00] mongoc: TRACE > EXIT: mongoc_server_description_destroy():151 [2016-04-12T21:26:16+00:00] mongoc: TRACE > EXIT: mongoc_topology_description_destroy():103 [2016-04-12T21:26:16+00:00] stream: TRACE > ENTRY: mongoc_stream_destroy():103 [2016-04-12T21:26:16+00:00] PHONGO: DEBUG > Not destroying RSRC#36 [2016-04-12T21:26:16+00:00] stream: TRACE > EXIT: mongoc_stream_destroy():111 [2016-04-12T21:26:16+00:00] cluster: TRACE > ENTRY: mongoc_cluster_destroy():1643 [2016-04-12T21:26:16+00:00] cluster: TRACE > EXIT: mongoc_cluster_destroy():1653 [2016-04-12T21:26:16+00:00] cursor: TRACE > ENTRY: mongoc_cursor_destroy():242 [2016-04-12T21:26:16+00:00] cursor: TRACE > ENTRY: _mongoc_cursor_destroy():259 [2016-04-12T21:26:16+00:00] client: TRACE > ENTRY: _mongoc_client_kill_cursor():1276 [2016-04-12T21:26:16+00:00] cluster: TRACE > ENTRY: mongoc_cluster_stream_for_server():1411
In this case, we see the BulkWrite and its returned WriteResult object being freed. Freeing of the Manager object begins with the mongoc_topology_description_destroy() block (topologies are freed for single-threaded drivers). As part of this freeing, mongoc_stream_destroy() is called (while freeing the underlying topology scanner and each connected node). The mongoc_cluster_destroy() block is the last evidence of the Manager's free sequence. After this point, the Cursor is freed and we encountered a segfault while selecting a stream for the server, which is now null.
