Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-27041

Improve utility of error message when an exception escapes the thread pool

    • 0

      When something scheduled into the ThreadPool throws an exception, the logs are pretty cryptic:

      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.113+0000 d21511| 2016-09-16T18:30:30.113+0000 F EXECUTOR [replication-6] Exception escaped task in thread pool replication: UnknownError: Caught std::exception of type std::system_error: Invalid argument
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.114+0000 d21511| 2016-09-16T18:30:30.113+0000 F EXECUTOR [replication-0] Exception escaped task in thread pool replication: UnknownError: Caught std::exception of type std::system_error: Invalid argument
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.114+0000 d21511| 2016-09-16T18:30:30.113+0000 F EXECUTOR [replication-7] Exception escaped task in thread pool replication: UnknownError: Caught std::exception of type std::system_error: Invalid argument
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.115+0000 d21511| 2016-09-16T18:30:30.113+0000 F EXECUTOR [replication-5] Exception escaped task in thread pool replication: UnknownError: Caught std::exception of type std::system_error: Invalid argument
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.115+0000 d21511| 2016-09-16T18:30:30.113+0000 F EXECUTOR [replication-3] Exception escaped task in thread pool replication: UnknownError: Caught std::exception of type std::system_error: Invalid argument
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.116+0000 d21511| 2016-09-16T18:30:30.113+0000 F EXECUTOR [replication-1] Exception escaped task in thread pool replication: UnknownError: Caught std::exception of type std::system_error: Invalid argument
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.116+0000 d21511| 2016-09-16T18:30:30.113+0000 F EXECUTOR [replication-4] Exception escaped task in thread pool replication: UnknownError: Caught std::exception of type std::system_error: Invalid argument
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.117+0000 d21511| 2016-09-16T18:30:30.113+0000 F EXECUTOR [replication-2] Exception escaped task in thread pool replication: UnknownError: Caught std::exception of type std::system_error: Invalid argument
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.117+0000 d21511| 2016-09-16T18:30:30.113+0000 F -        [replication-6] terminate() called. An exception is active; attempting to gather more information
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.121+0000 d21511| 2016-09-16T18:30:30.121+0000 F -        [replication-6] std::exception::what(): Invalid argument
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.121+0000 d21511| Actual exception type: std::system_error
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.121+0000 d21511|
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.122+0000 d21511|  0x7fbda987ea61 0x7fbda987e325 0x7fbdaa2c89f6 0x7fbdaa2c8a41 0x7fbda97f647c 0x7fbda97f6cd0 0x7fbda97f7879 0x7fbdaa2e3790 0x7fbda57f1aa1 0x7fbda553eaad
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.122+0000 d21511| ----- BEGIN BACKTRACE -----
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.135+0000 d21511| {"backtrace":[{"b":"7FBDA8248000","o":"1636A61","s":"_ZN5mongo15printStackTraceERSo"},{"b":"7FBDA8248000","o":"1636325"},{"b":"7FBDA8248000","o":"20809F6","s":"_ZN10__cxxabiv111__terminateEPFvvE"},{"b":"7FBDA8248000","o":"2080A41"},{"b":"7FBDA8248000","o":"15AE47C","s":"_ZN5mongo10ThreadPool10_doOneTaskEPSt11unique_lockISt5mutexE"},{"b":"7FBDA8248000","o":"15AECD0","s":"_ZN5mongo10ThreadPool13_consumeTasksEv"},{"b":"7FBDA8248000","o":"15AF879","s":"_ZN5mongo10ThreadPool17_workerThreadBodyEPS0_RKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEE"},{"b":"7FBDA8248000","o":"209B790"},{"b":"7FBDA57EA000","o":"7AA1"},{"b":"7FBDA5456000","o":"E8AAD","s":"clone"}],"processInfo":{ "mongodbVersion" : "3.3.12-236-gb50e092", "gitVersion" : "b50e092ab2856db10c29055fe11b6b3b6fa5d783", "compiledModules" : [ "enterprise" ], "uname" : { "sysname" : "Linux", "release" : "2.6.32-220.el6.x86_64", "version" : "#1 SMP Wed Nov 9 08:03:13 EST 2011", "machine" : "x86_64" }, "somap" : [ { "b" : "7FBDA8248000", "elfType" : 3, "buildId" : "9043B23E3B18DE7320A58D5F8B68A78646152D2D" }, { "b" : "7FFFBF2FF000", "elfType" : 3, "buildId" : "08F634A1D22DEFF00461D50A7699DACDC97657BF" }, { "b" : "7FBDA7DD9000", "path" : "/usr/lib64/libnetsnmpagent.so.20", "elfType" : 3, "buildId" : "1270BB069D761BD79C79F8986BB3ED5DCAA7D06D" }, { "b" : "7FBDA7BB3000", "path" : "/usr/lib64/libnetsnmphelpers.so.20", "elfType" : 3, "buildId" : "3FA4F246A7DF00EC1355C5226C9308DC7B4AB5CD" }, { "b" : "7FBDA76EB000", "path" : "/usr/lib64/libnetsnmpmibs.so.20", "elfType" : 3, "buildId" : "A12008903CCB8F814439276CDF5238BB9C289D4C" }, { "b" : "7FBDA7410000", "path" : "/usr/lib64/libnetsnmp.so.20", "elfType" : 3, "buildId" : "0FB0EADB5887E03256EF6C7EEA8B3388E39E4BB0" }, { "b" : "7F861CDF6000", "path" : "/usr/lib64/libsasl2.so.2", "elfType" : 3, "buildId" : "E0AEE889D5BF1373F2F9EE0D448DBF3F5B5113F0" }, { "b" : "7F861D7B2000", "path" : "/lib64/libgssapi_krb5.so.2", "elfType" : 3, "buildId" : "9B852585C66329AA02EFB28497E652A40F538E78" }, { "b" : "7F861BD61000", "path" : "/lib64/libldap-2.4.so.2", "elfType" : 3, "buildId" : "1FA3BC4E18EEEB915FDD4E9BE33D0542C3FB2804" }, { "b" : "7F861B752000", "path" : "/lib64/liblber-2.4.so.2", "elfType" : 3, "buildId" : "244D2593BDE4FE657BC88572DB5DA88FA274B7F3" }, { "b" : "7FBDA68FD000", "path" : "/usr/lib64/libcurl.so.4", "elfType" : 3, "buildId" : "F8B2645ECACB90EC35AB098EDFBC5540BAF37CE1" }, { "b" : "7FBDA6691000", "path" : "/usr/lib64/libssl.so.10", "elfType" : 3, "buildId" : "7C5A504A21B221F299B1C45B9ED9C2340AEC6AEB" }, { "b" : "7FBDA62AD000", "path" : "/usr/lib64/libcrypto.so.10", "elfType" : 3, "buildId" : "2CF03CE94B9388A10544E4EF073450851A4D6AEB" }, { "b" : "7F8621CA5000", "path" : "/lib64/librt.so.1", "elfType" : 3, "buildId" : "86FE5BC1F46B8F8AA9A7A479FF991900DB93F720" }, { "b" : "7F86226A1000", "path" : "/lib64/libdl.so.2", "elfType" : 3, "buildId" : "045D39F19533291EBD72D0EE0247F9D49BE2521E" }, { "b" : "7F862101D000", "path" : "/lib64/libm.so.6", "elfType" : 3, "buildId" : "B60EF3FCE5D4D2D8BAD2585D5CAAA1167B35DBFD" }, { "b" : "7F8620207000", "path" : "/lib64/libgcc_s.so.1", "elfType" : 3, "buildId" : "9A6E4BDFA184364D81F7DFD789474C3FB8F98A00" }, { "b" : "7F86217EA000", "path" : "/lib64/libpthread.so.0", "elfType" : 3, "buildId" : "B3BD4C596D72FCBE4607C86FEEC14F47B46D0DCC" }, { "b" : "7F8621856000", "path" : "/lib64/libc.so.6", "elfType" : 3, "buildId" : "24D3AB3DB0F38C7515FEADF82191651DA4117A18" }, { "b" : "7F8624C25000", "path" : "/lib64/ld-linux-x86-64.so.2", "elfType" : 3, "buildId" : "F3EEBD18E66EB139EA4D76CDFA86D643ABCF0070" }, { "b" : "7FBDA524B000", "path" : "/lib64/libwrap.so.0", "elfType" : 3, "buildId" : "083332F88CF3C61AB0184D8F397FC8BFF4548D8E" }, { "b" : "7F86206E0000", "path" : "/usr/lib64/perl5/CORE/libperl.so", "elfType" : 3, "buildId" : "545478030DF991A635CC5E3258A3F5D8A7E94561" }, { "b" : "7F861F0C6000", "path" : "/lib64/libresolv.so.2", "elfType" : 3, "buildId" : "DDF6449707FD4C49DDE32A293EEE9AC218BFC460" }, { "b" : "7F861E2AD000", "path" : "/lib64/libnsl.so.1", "elfType" : 3, "buildId" : "BC86E56751E93653BD1C92975968937148A407CD" }, { "b" : "7F861D076000", "path" : "/lib64/libcrypt.so.1", "elfType" : 3, "buildId" : "B21E32412356755F1851BAE219A0C8EFDAEEC686" }, { "b" : "7F8620273000", "path" : "/lib64/libutil.so.1", "elfType" : 3, "buildId" : "82DEB5906312B8D8F888D206DE11BC6B6FDF57D8" }, { "b" : "7F861A408000", "path" : "/usr/lib64/librpm.so.1", "elfType" : 3, "buildId" : "C65174824A80EDE5374CFF6143C808807160CA63" }, { "b" : "7F861B1D9000", "path" : "/usr/lib64/librpmio.so.1", "elfType" : 3, "buildId" : "F858A331FA080C7E82549BE3191EB4BADE02A5C0" }, { "b" : "7F861E3D0000", "path" : "/lib64/libpopt.so.0", "elfType" : 3, "buildId" : "E7B49911F1136073DD7DC58E8118CD9A4FBE2A19" }, { "b" : "7F861F5BA000", "path" : "/lib64/libz.so.1", "elfType" : 3, "buildId" : "D053BB4FF0C2FC983842F81598813B9B931AD0D1" }, { "b" : "7FBDA3BAA000", "path" : "/usr/lib64/libsensors.so.4", "elfType" : 3, "buildId" : "6855E5BF5B3634C15F01B1043BD892D727EE3C08" }, { "b" : "7F8619CC3000", "path" : "/lib64/libkrb5.so.3", "elfType" : 3, "buildId" : "EF3AACAFD6BF71BB861F194C1559153FB0B020E2" }, { "b" : "7F861A697000", "path" : "/lib64/libk5crypto.so.3", "elfType" : 3, "buildId" : "DDE6774979156442185836150FC0785170F8001F" }, { "b" : "7F861DC93000", "path" : "/lib64/libcom_err.so.2", "elfType" : 3, "buildId" : "13FFCD68952B7715DDF34C9321D82E3041EA9006" }, { "b" : "7F8619288000", "path" : "/lib64/libkrb5support.so.0", "elfType" : 3, "buildId" : "A23DAFBCE170763BF1E836A8B26113F9CD20E0DA" }, { "b" : "7F861A485000", "path" : "/lib64/libkeyutils.so.1", "elfType" : 3, "buildId" : "3BCCABE75DC61BBA81AAE45D164E26EF4F9F55DB" }, { "b" : "7F861AE42000", "path" : "/usr/lib64/libssl3.so", "elfType" : 3, "buildId" : "9080D18543F337F6F6B5C5265B1A3D2073A0FFBF" }, { "b" : "7F861A815000", "path" : "/usr/lib64/libsmime3.so", "elfType" : 3, "buildId" : "DE75A3731E7ABC427888BA8D38E96606264FBEBB" }, { "b" : "7F861C0D5000", "path" : "/usr/lib64/libnss3.so", "elfType" : 3, "buildId" : "0375F2A6DA6EDCF870C52584B71798AC9003CFF2" }, { "b" : "7F861B6A9000", "path" : "/usr/lib64/libnssutil3.so", "elfType" : 3, "buildId" : "F3A25CFCCA8191255ECFCFCD62248E393AFF3D01" }, { "b" : "7F861C4A5000", "path" : "/lib64/libplds4.so", "elfType" : 3, "buildId" : "1D3CD12F36DFB9E232953D3B73C34F8C0EF1004D" }, { "b" : "7F861B6A0000", "path" : "/lib64/libplc4.so", "elfType" : 3, "buildId" : "535FB904872A936ECC2E926C612B1B2BFD0FB722" }, { "b" : "7F861AC62000", "path" : "/lib64/libnspr4.so", "elfType" : 3, "buildId" : "29B15E2260EA9A50E0993DEEF7ABD8334F37E6B9" }, { "b" : "7F8617230000", "path" : "/lib64/libidn.so.11", "elfType" : 3, "buildId" : "5659EB985475B586E3BBCB95BA21F4A30BE5EBF4" }, { "b" : "7FBDA1C08000", "path" : "/usr/lib64/libssh2.so.1", "elfType" : 3, "buildId" : "8727EC925D6D91DAC74A99BDE8B3C6EE96AF13EA" }, { "b" : "7F861B605000", "path" : "/lib64/libfreebl3.so", "elfType" : 3, "buildId" : "AFF1C795A3CF422C9F8AC32C7522F6376B1EA087" }, { "b" : "7F86193F4000", "path" : "/lib64/libbz2.so.1", "elfType" : 3, "buildId" : "1250B1D041DD7552F0C870BB188DC3A34DF2651D" }, { "b" : "7F861B1DE000", "path" : "/usr/lib64/libelf.so.1", "elfType" : 3, "buildId" : "50517407A07B8D6C9A55A392E99246B52E8BFEEA" }, { "b" : "7F8619BBD000", "path" : "/usr/lib64/liblzma.so.0", "elfType" : 3, "buildId" : "6FF9BAEEEE9DDEEF2DFA5CBD36147A75891C0AD4" }, { "b" : "7F8617990000", "path" : "/usr/lib64/liblua-5.1.so", "elfType" : 3, "buildId" : "6BDB4E1990D6EBA12A5C8D39A7650DB8798BF568" }, { "b" : "7F861BF71000", "path" : "/lib64/libselinux.so.1", "elfType" : 3, "buildId" : "B4576BE308DDCF7BC31F7304E4734C3D846D0236" }, { "b" : "7F861796D000", "path" : "/lib64/libcap.so.2", "elfType" : 3, "buildId" : "A436538388F1F25113FDA834CA2EED524EFA17D6" }, { "b" : "7F8617F65000", "path" : "/lib64/libacl.so.1", "elfType" : 3, "buildId" : "26CC708AC7C0FC1797A2340C024F0ADD0CE054D8" }, { "b" : "7F86187F1000", "path" : "/lib64/libdb-4.7.so", "elfType" : 3, "buildId" : "54DB4E3C4EC743FE95DD31C9D312E2898724577E" }, { "b" : "7F86189EC000", "path" : "/lib64/libattr.so.1", "elfType" : 3, "buildId" : "8EF0683858704EF173AB11B1E27076F37F82B7B6" } ] }}
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.135+0000 d21511|  mongod(_ZN5mongo15printStackTraceERSo+0x41) [0x7fbda987ea61]
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.136+0000 d21511|  mongod(+0x1636325) [0x7fbda987e325]
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.136+0000 d21511|  mongod(_ZN10__cxxabiv111__terminateEPFvvE+0x6) [0x7fbdaa2c89f6]
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.136+0000 d21511|  mongod(+0x2080A41) [0x7fbdaa2c8a41]
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.136+0000 d21511|  mongod(_ZN5mongo10ThreadPool10_doOneTaskEPSt11unique_lockISt5mutexE+0x40C) [0x7fbda97f647c]
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.137+0000 d21511|  mongod(_ZN5mongo10ThreadPool13_consumeTasksEv+0xC0) [0x7fbda97f6cd0]
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.137+0000 d21511|  mongod(_ZN5mongo10ThreadPool17_workerThreadBodyEPS0_RKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEE+0x149) [0x7fbda97f7879]
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.137+0000 d21511|  mongod(+0x209B790) [0x7fbdaa2e3790]
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.137+0000 d21511|  libpthread.so.0(+0x7AA1) [0x7fbda57f1aa1]
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.137+0000 d21511|  libc.so.6(clone+0x6D) [0x7fbda553eaad]
      [js_test:clean_shutdown_oplog_state] 2016-09-16T18:30:30.138+0000 d21511| -----  END BACKTRACE  -----
      

      Note that the backtrace just points to the catch block within ThreadPool::_doOneTask, giving no hint as to what the task was, where it was scheduled from, or the thing that went wrong.

            Assignee:
            ben.caimano@mongodb.com Benjamin Caimano (Inactive)
            Reporter:
            charlie.swanson@mongodb.com Charlie Swanson
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated:
              Resolved: