[SERVER-39098] Show JS stacktrace when the test hangs Created: 18/Jan/19  Updated: 29/Oct/23  Resolved: 31/Jan/19

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: None
Fix Version/s: 4.1.8

Type: Improvement Priority: Major - P3
Reporter: Siyuan Zhou Assignee: Andrew Morrow (Inactive)
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related
is related to SERVER-35646 MozJSImplScope::buildStackString() se... Closed
Backwards Compatibility: Fully Compatible
Sprint: Dev Tools 2019-02-11
Participants:

 Description   

When a test fails, we can get where stacktrace to pinpoint the problem. However, if a test hangs, there seems no way to get the JS stacktrace. Hang analyzer can print out the stacktrace of the shell, but it shows the stacktrace of the JS interpreter instead of the JS code.

Thread 3: "js" (Thread 0x7f3826ca8700 (LWP 26620))
#0  0x00007f382bac2d0d in recvmsg () from /lib64/libpthread.so.0
#1  0x00007f382e4dad6a in asio::detail::socket_ops::recv (s=7, bufs=0x7f3826ca5900, count=<optimized out>, flags=0, ec=...) at src/third_party/asio-master/asio/include/asio/detail/impl/socket_ops.ipp:790
#2  0x00007f382e4dae28 in asio::detail::socket_ops::sync_recv (s=<optimized out>, state=<optimized out>, bufs=bufs@entry=0x7f3826ca5900, count=count@entry=1, flags=flags@entry=0, all_empty=<optimized out>, ec=...) at src/third_party/asio-master/asio/include/asio/detail/impl/socket_ops.ipp:813
#3  0x00007f382e3e624e in asio::detail::reactive_socket_service_base::receive<asio::mutable_buffers_1> (this=<optimized out>, impl=..., impl=..., ec=..., flags=0, buffers=...) at src/third_party/asio-master/asio/include/asio/detail/reactive_socket_service_base.hpp:315
#4  asio::basic_stream_socket<asio::generic::stream_protocol>::read_some<asio::mutable_buffers_1> (ec=..., buffers=..., this=0x7f3830c2d228) at src/third_party/asio-master/asio/include/asio/basic_stream_socket.hpp:853
#5  asio::detail::read_buffer_sequence<asio::basic_stream_socket<asio::generic::stream_protocol>, asio::mutable_buffers_1, asio::mutable_buffer const*, asio::detail::transfer_all_t> (s=..., buffers=..., completion_condition=..., ec=...) at src/third_party/asio-master/asio/include/asio/impl/read.hpp:54
#6  0x00007f382e3f0889 in asio::read<asio::basic_stream_socket<asio::generic::stream_protocol>, asio::mutable_buffers_1, asio::detail::transfer_all_t> (ec=..., buffers=..., s=..., completion_condition=...) at src/third_party/asio-master/asio/include/asio/impl/read.hpp:71
#7  asio::read<asio::basic_stream_socket<asio::generic::stream_protocol>, asio::mutable_buffers_1> (ec=..., buffers=..., s=...) at src/third_party/asio-master/asio/include/asio/impl/read.hpp:93
#8  mongo::transport::TransportLayerASIO::ASIOSession::opportunisticRead<asio::basic_stream_socket<asio::generic::stream_protocol>, asio::mutable_buffers_1> (this=this@entry=0x7f3830c2d010, stream=..., buffers=..., baton=std::shared_ptr (empty) 0x0) at src/mongo/transport/session_asio.h:459
#9  0x00007f382e3fd08f in mongo::transport::TransportLayerASIO::ASIOSession::read<asio::mutable_buffers_1> (this=this@entry=0x7f3830c2d010, buffers=..., baton=std::shared_ptr (empty) 0x0) at src/mongo/transport/session_asio.h:412
#10 0x00007f382e4004ac in mongo::transport::TransportLayerASIO::ASIOSession::sourceMessageImpl (this=this@entry=0x7f3830c2d010, baton=std::shared_ptr (empty) 0x0) at src/mongo/transport/session_asio.h:350
#11 0x00007f382e400928 in mongo::transport::TransportLayerASIO::ASIOSession::sourceMessage (this=0x7f3830c2d010) at src/mongo/transport/session_asio.h:133
#12 0x00007f382e371c71 in mongo::DBClientConnection::call (this=0x7f3830c2c400, toSend=..., response=..., assertOk=false, actualServer=<optimized out>) at src/mongo/client/dbclient_connection.cpp:612
#13 0x00007f382e493e19 in mongo::DBClientBase::runCommandWithTarget (this=this@entry=0x7f3830c2c400, request=...) at src/mongo/client/dbclient_base.cpp:215
#14 0x00007f382e36cbf8 in mongo::DBClientConnection::runCommandWithTarget (this=0x7f3830c2c400, request=...) at src/mongo/client/dbclient_connection.cpp:340
#15 0x00007f382e491817 in mongo::DBClientBase::runCommandWithTarget (this=this@entry=0x7f3830c2c400, request=..., me=std::shared_ptr (count 3, weak 0) 0x7f3830c2c400) at src/mongo/client/dbclient_base.cpp:242
#16 0x00007f382e36ce1a in mongo::DBClientConnection::runCommandWithTarget (this=this@entry=0x7f3830c2c400, request=..., me=std::shared_ptr (empty) 0x0) at src/mongo/client/dbclient_connection.cpp:353
#17 0x00007f382e4938d6 in mongo::DBClientBase::runCommandWithTarget (this=0x7f3830c2c400, dbname="admin", cmd=unowned empty BSONObj @ 0x7f382ecebe3f <mongo::BSONObj::BSONObj()::kEmptyObjectPrototype>, info=unowned empty BSONObj @ 0x7f382ecebe3f <mongo::BSONObj::BSONObj()::kEmptyObjectPrototype>, me=std::shared_ptr (empty) 0x0, options=0) at src/mongo/client/dbclient_base.cpp:266
#18 0x00007f382dcebd21 in mongo::mozjs::MongoBase::Functions::runCommand::call (cx=0x7f3830b5ab80, args=...) at src/mongo/scripting/mozjs/mongo.cpp:251
#19 0x00007f382dcf1655 in mongo::mozjs::smUtils::wrapConstrainedMethod<mongo::mozjs::MongoBase::Functions::runCommand, true, mongo::mozjs::MongoExternalInfo> (cx=cx@entry=0x7f3830b5ab80, argc=<optimized out>, vp=0x7f3826ca6518) at src/mongo/scripting/mozjs/wrapconstrainedmethod.h:118
#20 0x00007f382e169d5b in js::CallJSNative (args=..., native=<optimized out>, cx=0x7f3830b5ab80) at src/third_party/mozjs-45/extract/js/src/jscntxtinlines.h:240
#21 js::Invoke (cx=cx@entry=0x7f3830b5ab80, args=..., construct=construct@entry=js::NO_CONSTRUCT) at src/third_party/mozjs-45/extract/js/src/vm/Interpreter.cpp:444
#22 0x00007f382e051602 in js::fun_apply (cx=cx@entry=0x7f3830b5ab80, argc=<optimized out>, vp=0x7f3830d925d8) at src/third_party/mozjs-45/extract/js/src/jsfun.cpp:1259
#23 0x00007f382e169d5b in js::CallJSNative (args=..., native=<optimized out>, cx=0x7f3830b5ab80) at src/third_party/mozjs-45/extract/js/src/jscntxtinlines.h:240
#24 js::Invoke (cx=0x7f3830b5ab80, args=..., construct=<optimized out>) at src/third_party/mozjs-45/extract/js/src/vm/Interpreter.cpp:444
#25 0x00007f382e165701 in Interpret (cx=0x7f3830b5ab80, state=...) at src/third_party/mozjs-45/extract/js/src/vm/Interpreter.cpp:2766
#26 0x00007f382e169ad3 in js::RunScript (cx=cx@entry=0x7f3830b5ab80, state=...) at src/third_party/mozjs-45/extract/js/src/vm/Interpreter.cpp:391
#27 0x00007f382e1704cf in js::ExecuteKernel (cx=cx@entry=0x7f3830b5ab80, script=..., script@entry=..., scopeChainArg=..., newTargetValue=..., type=<optimized out>, evalInFrame=..., evalInFrame@entry=..., result=<optimized out>) at src/third_party/mozjs-45/extract/js/src/vm/Interpreter.cpp:650
#28 0x00007f382e170639 in js::Execute (cx=cx@entry=0x7f3830b5ab80, script=..., scopeChainArg=..., rval=rval@entry=0x7f3826ca7890) at src/third_party/mozjs-45/extract/js/src/vm/Interpreter.cpp:685
#29 0x00007f382e01665a in ExecuteScript (cx=cx@entry=0x7f3830b5ab80, scope=..., scope@entry=..., script=..., script@entry=..., rval=rval@entry=0x7f3826ca7890) at src/third_party/mozjs-45/extract/js/src/jsapi.cpp:4410
#30 0x00007f382e016700 in JS_ExecuteScript (cx=0x7f3830b5ab80, scriptArg=scriptArg@entry=..., rval=rval@entry=...) at src/third_party/mozjs-45/extract/js/src/jsapi.cpp:4436
#31 0x00007f382dcd9317 in mongo::mozjs::MozJSImplScope::<lambda()>::operator() (__closure=<optimized out>) at src/mongo/scripting/mozjs/implscope.cpp:802
#32 mongo::mozjs::MozJSImplScope::_runSafely<mongo::mozjs::MozJSImplScope::exec(mongo::StringData, const string&, bool, bool, bool, int)::<lambda()> > (functionToRun=..., this=<optimized out>) at src/mongo/scripting/mozjs/implscope.cpp:543
#33 mongo::mozjs::MozJSImplScope::exec (this=0x7f3830bab000, code=..., name=..., printResult=<optimized out>, reportError=<optimized out>, assertOnError=false, timeoutMs=0) at src/mongo/scripting/mozjs/implscope.cpp:817
#34 0x00007f382dd045bf in mongo::mozjs::MozJSProxyScope::<lambda()>::operator() (__closure=<optimized out>) at src/mongo/scripting/mozjs/proxyscope.cpp:228
#35 std::_Function_handler<void(), mongo::mozjs::MozJSProxyScope::exec(mongo::StringData, const string&, bool, bool, bool, int)::<lambda()> >::_M_invoke(const std::_Any_data &) (__functor=...) at /opt/mongodbtoolchain/stow/gcc-v2.XtY/include/c++/5.4.0/functional:1871
#36 0x00007f382dd04d93 in std::function<void ()>::operator()() const (this=0x7f38309a85d0) at /opt/mongodbtoolchain/stow/gcc-v2.XtY/include/c++/5.4.0/functional:2267
#37 mongo::mozjs::MozJSProxyScope::implThread (arg=0x7f38309a8500) at src/mongo/scripting/mozjs/proxyscope.cpp:362
#38 0x00007f382dd004ec in nspr::Thread::ThreadRoutine (arg=0x7f3830ba1240) at src/mongo/scripting/mozjs/PosixNSPR.cpp:56
#39 0x00007f382ec05a30 in std::execute_native_thread_routine (__p=<optimized out>) at ../../../../../src/gcc-5.4.0/libstdc++-v3/src/c++11/thread.cc:84
#40 0x00007f382babbaa1 in start_thread () from /lib64/libpthread.so.0
#41 0x00007f382b808bdd in clone () from /lib64/libc.so.6 



 Comments   
Comment by Githook User [ 31/Jan/19 ]

Author:

{'name': 'Andrew Morrow', 'email': 'acm@mongodb.com', 'username': 'acmorrow'}

Message: SERVER-39098 Fix escaping in javascript_stack GDB extension
Branch: master
https://github.com/mongodb/mongo/commit/a0aef148ed113bf66ca4c8ab37864455524be2a2

Comment by Max Hirschhorn [ 18/Jan/19 ]

The hang_analyzer.py script did attempt to print the JavaScript stacktrace associated with the MozJSImplScope thread, but it encountered an error. I know we're hoping SERVER-35646 is resolved by upgrading SpiderMonkey - I think the same should happen for this ticket (or to figure out what function needs to be called in SpiderMonkey to make it work again).

[2019/01/17 08:37:57.959] Running Print JavaScript Stack Supplement
[2019/01/17 08:37:57.959] [Current thread is 3 (Thread 0x7f3826ca8700 (LWP 26620))]
[2019/01/17 08:37:57.959] Ignoring GDB error 'Bad format string, non-terminated '"'.' in javascript_stack

https://evergreen.mongodb.com/task_log_raw/mongodb_mongo_master_enterprise_rhel_62_64_bit_majority_read_concern_off_logical_session_cache_replication_1sec_refresh_jscore_passthrough_f07694654f3733ff664cdb8b48cee37486095c55_19_01_17_03_38_49/0?type=T&text=true

Generated at Thu Feb 08 04:51:01 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.