-
Type:
Bug
-
Resolution: Done
-
Priority:
Critical - P2
-
Affects Version/s: 1.1.8
-
Component/s: None
-
None
-
Environment:PHP 5.5.37 (possible other PHP 5.x, but not PHP 7)
jwage encountered a crash due to a libmongoc assert failure, where a cursor was being killed during a shutdown function:
#0 0x0000003b20e32625 in raise (sig=<value optimized out>) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
resultvar = 0
pid = <value optimized out>
selftid = <value optimized out>
#1 0x0000003b20e33e05 in abort () at abort.c:92
save_stage = 2
act = {__sigaction_handler = {sa_handler = 0x60, sa_sigaction = 0x60}, sa_mask = {__val = {253958350976, 47549832, 47537728, 0, 140735799216256, 1, 253955669547, 206158430256, 140735799214840,
140735799214624, 157312, 70326552, 228518431, 32, 140250760109120, 1454}}, sa_flags = -1396939744, sa_restorer = 0x10}
sigs = {__val = {32, 0 <repeats 15 times>}}
#2 0x00007f8eacb9e415 in mongoc_cluster_fetch_stream_pooled (cluster=0x2d58d88, sd=0x3e2c1d0, reconnect_ok=false, error=0x0) at src/mongoc/mongoc-cluster.c:1544
stream = 0x7fff9b51c880
topology = <value optimized out>
cluster_node = <value optimized out>
timestamp = <value optimized out>
#3 _mongoc_cluster_stream_for_server_description (cluster=0x2d58d88, sd=0x3e2c1d0, reconnect_ok=false, error=0x0) at src/mongoc/mongoc-cluster.c:1365
topology = <value optimized out>
server_stream = <value optimized out>
#4 0x00007f8eacb9e838 in mongoc_cluster_stream_for_server (cluster=0x2d58d88, server_id=3, reconnect_ok=false, error=0x0) at src/mongoc/mongoc-cluster.c:1422
topology = <value optimized out>
sd = 0x3e2c1d0
server_stream = 0x0
__func__ = "mongoc_cluster_stream_for_server"
#5 0x00007f8eacb991a6 in _mongoc_client_kill_cursor (client=0x2d58d70, server_id=<value optimized out>, cursor_id=4536838857318534913, db=0x7fff9b51c880 "opensky_devo", collection=0x3e4b9a5 "sellables")
at src/mongoc/mongoc-client.c:1282
server_stream = <value optimized out>
__func__ = "_mongoc_client_kill_cursor"
#6 0x00007f8eacba5028 in _mongoc_cursor_destroy (cursor=0x3e4b7f0) at src/mongoc/mongoc-cursor.c:273
db = "opensky_devo\000\000\000\000 -\321\003\000\000\000\000p\022\315\003\000\000\000\000X\000\000\000\000\000\000\000bM[\000\000\000\000\000\270\v\000\000\000\000\000\000bM[\000\000\000\000\000\220\017\000\000\000\000\000\000bM[\000\000\000\000\000 [\345\003\000\000\000\000\020Y\344\003\000\000\000\000@\002\000\000\000\000\000\000bM[\000\000\000\000\000X\000\000\000\000\000\000\000bM[\000\000\000\000"
__func__ = "_mongoc_cursor_destroy"
#7 0x00007f8eacdf67b2 in php_phongo_cursor_free (cursor=0x3e09b60) at /usr/src/debug/php-pecl-mongodb-1.1.8/NTS/php_phongo.c:2142
No locals.
#8 0x00007f8eacdedbe1 in php_phongo_cursor_free_object (object=<value optimized out>) at /usr/src/debug/php-pecl-mongodb-1.1.8/NTS/src/MongoDB/Cursor.c:226
intern = 0x3e09b60
#9 0x000000000060623c in zend_objects_store_free_object_storage (objects=0x9f66c0) at /usr/src/debug/php-5.5.37/Zend/zend_objects_API.c:97
obj = <value optimized out>
i = <value optimized out>
#10 0x00000000005ceb23 in shutdown_executor () at /usr/src/debug/php-5.5.37/Zend/zend_execute_API.c:290
---Type <return> to continue, or q <return> to quit---
__orig_bailout = 0x7fff9b51ce80
__bailout = {{__jmpbuf = {10445600, -9101158388112889313, 140251056034432, 140251056037176, 140251056037720, 0, 9100937786234956319, -9101158395108857313}, __mask_was_saved = 0, __saved_mask = {
__val = {9345585548714895903, 0, 5983586, 32, 5983586, 184, 5983586, 140251056282616, 62546720, 96, 10445336, 1, 140251056034432, 140251056037176, 6139470, 10445248}}}}
#11 0x00000000005dcce2 in zend_deactivate () at /usr/src/debug/php-5.5.37/Zend/zend.c:946
No locals.
#12 0x000000000057c761 in php_request_shutdown (dummy=<value optimized out>) at /usr/src/debug/php-5.5.37/main/main.c:1813
report_memleaks = 1 '\001'
#13 0x00000000006976c9 in main (argc=<value optimized out>, argv=<value optimized out>) at /usr/src/debug/php-5.5.37/sapi/fpm/fpm/fpm_main.c:1981
primary_script = <value optimized out>
__orig_bailout = 0x0
__bailout = {{__jmpbuf = {0, 9100937787569793567, 2, 0, 10423264, 0, 9100937786052504095, -9101158278872241633}, __mask_was_saved = 0, __saved_mask = {__val = {0 <repeats 14 times>, 253950458591,
0}}}}
exit_status = 0
c = <value optimized out>
use_extended_info = 0
file_handle = {type = ZEND_HANDLE_FILENAME, filename = 0x7f8ebe5fd0b8 "x\324\177\002", opened_path = 0x0, handle = {fd = 0, fp = 0x0, stream = {handle = 0x0, isatty = 0, mmap = {len = 0,
pos = 253979787264, map = 0x3b2261d000, buf = 0x3b2261c6bc <Address 0x3b2261c6bc out of bounds>, old_handle = 0x3b2261c6bc, old_closer = 0}, reader = 0x5, fsizer = 0x3b2281c000,
closer = 0x3b2281e000}}, free_filename = 0 '\000'}
orig_optind = 1
orig_optarg = 0x0
ini_entries_len = <value optimized out>
max_requests = 2500
requests = 11
fcgi_fd = 10444256
request = {listen_socket = 0, fd = -1, id = 1, keep = 0, closed = 0, in_len = 0, in_pad = 7, out_hdr = 0x0, out_pos = 0x7fff9b51d010 "\001\006",
out_buf = "\001\006\000\001\000\a\001\000/html>\n\000\001\003\000\001\000\b\000\000\000\000\000\000\000he\r\nDate: Fri, 08 Jul 2016 15:24:14 GMT\r\nContent-Type: text/html; charset=UTF-8\r\nX-OSKY-P-NODE: dc1osphp01\r\n\r\n\000\000\000\000\000\001\006\000\001\330p\000\000ssion-language/Symfony/Component/ExpressionLangua"..., reserved = '\000' <repeats 15 times>, env = 0x7f8ebe5fd040}
fpm_config = 0x0
fpm_prefix = 0x0
fpm_pid = 0x0
test_conf = 0
force_daemon = 1
php_information = 0
php_allow_to_run_as_root = 0
__func__ = "main"
My initial analysis:
Also of note: before I noticed mongoc_cluster_fetch_stream_pooled() in the crash backtrace, we originally suspected this was a recurrence of
PHPC-671(fixed in 1.1.7), which entailed a crash due to PHP 5.x freeing the MongoDB\Driver\Manager object before open MongoDB\Driver\Cursor objects. That resulted in the Manager also destroying libmongoc's client object (and all streams) and causing a use-after-free when the Cursor wanted to free itself and send a kill command over the stream it was last associated with.That said, mongoc_cluster_fetch_stream_pooled() is really the red flag here, as there's no reason that libmongoc should not be in single_threaded mode. See the _mongoc_cluster_stream_for_server_description for the relevant logic in libmongoc (one level deep in the backtrace).
Most likely, the MongoDB\Driver\Manager (and its mongoc_client_t) was again freed before the non-exhausted MongoDB\Driver\Cursor. This resulted in topology->single_threaded being zeroed in memory (responsible for libmongoc attempting to fetch a stream from a pool). Somehow, the mongoc_cursor_t still had a reference to this memory when it attempted to kill itself.
Since jwage was using mongo-php-adapter, this issue may be a duplicate of PHPC-732 and caused entirely by the use of generators. We'll need to confirm that.
