With my (rather slow) local Linux ASan+UBSan build, I can occasionally see
$ make UITest_writer_tests3 UITEST_TEST_NAME=hyperlinkdialog.HyperlinkDialog.test_insert_hyperlink
fail with soffice.bin hitting the assert in rtl_uString_newFromSubString
at sal/rtl/strtmpl.cxx:1390
if ( count < 0 || beginIndex < 0 || beginIndex + count > pFrom->length )
{
assert(false); // fail fast at least in debug builds
IMPL_RTL_STRINGNAME( newFromLiteral )( ppThis, "!!br0ken!!", 10, 0 );
return;
}
with beginIndex=0 and count=4 but pFrom being the empty string. This is
on a remote worker thread #6
#0 0x00007f5cb7bdc1ea in rtl_uString_newFromSubString(rtl_uString**, rtl_uString const*, sal_Int32,
sal_Int32) (ppThis=0x7f5c251da460, pFrom=0x7f5cb79fde60 <aImplEmpty_rtl_uString>, beginIndex=0,
count=4) at sal/rtl/strtmpl.cxx:1392
#1 0x00007f5c1706f144 in rtl::OUString::copy(int, int) const (this=0x7f5c2547cb30, beginIndex=0,
count=4) at include/rtl/ustring.hxx:2256
#2 0x00007f5c1b8c6233 in SwTextNode::GetExpandText(SwRootFrame const*, int, int, bool, bool, bool,
ExpandMode) const (this=0x614000108040, pLayout=0x614000103e40, nIdx=0, nLen=4, bWithNum=false,
bAddSpaceAfterListLabelStr=false, bWithSpacesForLevel=false,
eAdditionalMode=ExpandMode::ExpandFootnote) at sw/source/core/txtnode/ndtxt.cxx:3395
#3 0x00007f5c1787230f in SwCursorShell::GetSelText() const (this=0x619000187480) at
sw/source/core/crsr/crsrsh.cxx:2570
#4 0x00007f5c198efbb8 in SwEditShell::GetSelectedText(rtl::OUString&, ParaBreakType) (this=0x619000187480,
rBuf="", nHndlParaBrk=ParaBreakType::ToBlank) at sw/source/core/edit/edglss.cxx:268
#5 0x00007f5c1ee55c81 in SwView::GetSelectionTextParam(bool, bool) (this=0x6170001ad000,
bCompleteWrds=false, bEraseTrail=true) at sw/source/uibase/uiview/view.cxx:1598
#6 0x00007f5c1ee554f6 in SwView::GetSelectionText(bool) (this=0x6170001ad000, bCompleteWrds=false)
at sw/source/uibase/uiview/view.cxx:1589
#7 0x00007f5c1ed10825 in SwEditWinUIObject::get_state() (this=0x604000a9a850) at
sw/source/uibase/uitest/uiobject.cxx:43
#8 0x00007f5c80f2e6cd in UIObjectUnoObj::getState() (this=0x611000336340) at
vcl/source/uitest/uno/uiobject_uno.cxx:147
#9 0x00007f5c80f2ee2d in non-virtual thunk to UIObjectUnoObj::getState() () at
include/c++/11.0.0/bits/stl_tree.h:2246
#10 0x00007f5c4c94e736 in gcc3::callVirtualMethod(void*, unsigned int, void*,
_typelib_TypeDescriptionReference*, bool, unsigned long*, unsigned int, unsigned long*, double*)
(pThis=0x611000336390, nVtableIndex=5, pRegisterReturn=0x7f5c267ef160,
pReturnTypeRef=0x6080000c2aa0, bSimpleReturn=false, pStack=0x7f5c267ef1c0, nStack=0,
pGPR=0x7f5c25508c60, pFPR=0x7f5c25508cc0) at
bridges/source/cpp_uno/gcc3_linux_x86-64/callvirtualmethod.cxx:77
#11 0x00007f5c4c948918 in cpp_call(bridges::cpp_uno::shared::UnoInterfaceProxy*,
bridges::cpp_uno::shared::VtableSlot, _typelib_TypeDescriptionReference*, int,
_typelib_MethodParameter*, void*, void**, _uno_Any**) (pThis=0x606000ace7a0, aVtableSlot=...,
pReturnTypeRef=0x6080000c2aa0, nParams=0, pParams=0x0, pUnoReturn=0x60200052e6f0, pUnoArgs=0x0,
ppUnoExc=0x7f5c25769880) at bridges/source/cpp_uno/gcc3_linux_x86-64/uno2cpp.cxx:233
#12 0x00007f5c4c94533b in bridges::cpp_uno::shared::unoInterfaceProxyDispatch(uno_Interface*,
typelib_TypeDescription const*, void*, void**, uno_Any**) (pUnoI=0x606000ace7a0,
pMemberDescr=0x60f0000ae730, pReturn=0x60200052e6f0, pArgs=0x0, ppException=0x7f5c25769880) at
bridges/source/cpp_uno/gcc3_linux_x86-64/uno2cpp.cxx:413
#13 0x00007f5c4784866d in binaryurp::IncomingRequest::execute_throw(binaryurp::BinaryAny*,
std::__debug::vector<binaryurp::BinaryAny, std::allocator<binaryurp::BinaryAny> >*) const
(this=0x60d000317e60, returnValue=0x7f5c25768020, outArguments=0x7f5c25768060) at
binaryurp/source/incomingrequest.cxx:235
#14 0x00007f5c4784220b in binaryurp::IncomingRequest::execute() const (this=0x60d000317e60) at
binaryurp/source/incomingrequest.cxx:78
#15 0x00007f5c4792f799 in request(void*) (pThreadSpecificData=0x60d000317e60) at
binaryurp/source/reader.cxx:85
#16 0x00007f5cb0093cba in cppu_threadpool::JobQueue::enter(void const*, bool) (this=0x612000cadd40,
nDisposeId=0x60600087c260, bReturnWhenNoJob=true) at cppu/source/threadpool/jobqueue.cxx:100
#17 0x00007f5cb00bfdbe in cppu_threadpool::ORequestThread::run() (this=0x60600087c260) at
cppu/source/threadpool/thread.cxx:165
#18 0x00007f5cb00d42b3 in threadFunc(void*) (param=0x60600087c270) at include/osl/thread.hxx:185
#19 0x00007f5cb7d35334 in osl_thread_start_Impl(void*) (pData=0x60c000362c80) at
sal/osl/unx/thread.cxx:258
#20 0x00007f5cb6255432 in start_thread (arg=<optimized out>) at
/usr/src/debug/glibc-2.31-17-gab029a2801/nptl/pthread_create.c:477
#21 0x00007f5cb61549d3 in clone () at
/usr/src/debug/glibc-2.31-17-gab029a2801/sysdeps/unix/sysv/linux/x86_64/clone.S:95
while the main thread is idle at
#0 futex_wait_cancelable (private=0, expected=0, futex_word=0x60e000025208) at
/usr/src/debug/glibc-2.31-17-gab029a2801/sysdeps/nptl/futex-internal.h:183
#1 __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x60e0000251b8, cond=0x60e0000251e0)
at /usr/src/debug/glibc-2.31-17-gab029a2801/nptl/pthread_cond_wait.c:508
#2 __pthread_cond_wait (cond=0x60e0000251e0, mutex=0x60e0000251b8) at
/usr/src/debug/glibc-2.31-17-gab029a2801/nptl/pthread_cond_wait.c:638
#3 0x00007f5cb64ab090 in __gthread_cond_wait (__mutex=<optimized out>, __cond=<optimized out>) at
/home/sbergman/gcc/trunk/build/x86_64-pc-linux-gnu/libstdc++-v3/include/x86_64-pc-linux-gnu/bits/gthr-default.h:865
#4 std::condition_variable::wait(std::unique_lock<std::mutex>&) (this=<optimized out>, __lock=...)
at /home/sbergman/gcc/trunk/src/libstdc++-v3/src/c++11/condition_variable.cc:53
#5 0x00007f5c8131294d in std::condition_variable::wait<SvpSalYieldMutex::doAcquire(unsigned
int)::$_0>(std::unique_lock<std::mutex>&, SvpSalYieldMutex::doAcquire(unsigned int)::$_0)
(this=0x60e0000251e0, __lock=..., __p=...) at include/c++/11.0.0/condition_variable:111
#6 0x00007f5c8131189a in SvpSalYieldMutex::doAcquire(unsigned int) (this=0x60e000025180,
nLockCount=1) at vcl/headless/svpinst.cxx:342
#7 0x00007f5c7d1a239e in comphelper::SolarMutex::acquire(unsigned int) (this=0x60e000025180,
nLockCount=1) at include/comphelper/solarmutex.hxx:86
#8 0x00007f5c802a3a49 in SalInstance::AcquireYieldMutex(unsigned int) (this=0x611000001d00,
nCount=1) at vcl/source/app/salvtables.cxx:118
#9 0x00007f5c8131653a in SvpSalInstance::DoYield(bool, bool) (this=0x611000001d00, bWait=true,
bHandleAllCurrentEvents=false) at vcl/headless/svpinst.cxx:503
#10 0x00007f5c8071f8a4 in ImplYield(bool, bool) (i_bWait=true, i_bAllEvents=false) at
vcl/source/app/svapp.cxx:455
#11 0x00007f5c8071ea88 in Application::Yield() () at vcl/source/app/svapp.cxx:519
#12 0x00007f5c8071e6c8 in Application::Execute() () at vcl/source/app/svapp.cxx:434
#13 0x00007f5cb6e7022d in desktop::Desktop::Main() (this=0x7f5c4dbb6080) at
desktop/source/app/app.cxx:1600
#14 0x00007f5c807c8bcd in ImplSVMain() () at vcl/source/app/svmain.cxx:201
#15 0x00007f5c807d2b91 in SVMain() () at vcl/source/app/svmain.cxx:233
#16 0x00007f5cb705f29d in soffice_main() () at desktop/source/app/sofficemain.cxx:98
#17 0x000000000032d38d in sal_main () at desktop/source/app/main.c:48
#18 0x000000000032d367 in main (argc=7, argv=0x7ffe05dcfc48) at desktop/source/app/main.c:47
#19 0x00007f5cb607a042 in __libc_start_main (main=0x32d340 <main>, argc=7, argv=0x7ffe05dcfc48, init=<optimized
out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffe05dcfc38) at
/usr/src/debug/glibc-2.31-17-gab029a2801/csu/libc-start.c:308
#20 0x0000000000250b3e in _start ()
(at least it is idle once I come around to generate the backtraces,
which doesn't happen automatically upon SIGABRT for that ASan build; so
I needed to hack the assert into an endless loop and attach gdb after it
got hit). The python.bin process is at
Traceback (most recent call first):
File "uitest/uitest/uihelper/common.py", line 11, in get_state_as_dict
return convert_property_values_to_dict(ui_object.getState())
File "sw/qa/uitest/writer_tests3/hyperlinkdialog.py", line 79, in test_insert_hyperlink
self.assertEqual(get_state_as_dict(xedit)["SelectedText"], "link")
File "instdir/program/python-core-3.8.4/lib/unittest/case.py", line 633, in _callTestMethod
method()
File "instdir/program/python-core-3.8.4/lib/unittest/case.py", line 1700, in run
File "instdir/program/python-core-3.8.4/lib/unittest/case.py", line 736, in __call__
return self.run(*args, **kwds)
File "instdir/program/python-core-3.8.4/lib/unittest/suite.py", line 378, in run
File "instdir/program/python-core-3.8.4/lib/unittest/suite.py", line 84, in __call__
return self.run(*args, **kwds)
File "instdir/program/python-core-3.8.4/lib/unittest/runner.py", line 432, in run
File "uitest/test_main.py", line 128, in <module>
result = unittest.TextTestRunner(stream=sys.stdout, verbosity=2).run(test_suite)
I assume that there is a race, and some other thread was modifying the
data in parallel with thread #6 accessing it. (But any trace of that
other thread's activity is gone by the time I get the soffice.bin
backtraces; see above.) I already verified that this is probably not a
SolarMutex issue at least on thread #6's end, by sticking
DBG_TESTSOLARMUTEX();
at the top of SwTextNode::GetExpandText, which never fired.
Any idea how to debug this further?
Context
- Race with SwEditWinUIObject::get_state during UITest_writer_tests3? · Stephan Bergmann
Privacy Policy |
Impressum (Legal Info) |
Copyright information: Unless otherwise specified, all text and images
on this website are licensed under the
Creative Commons Attribution-Share Alike 3.0 License.
This does not include the source code of LibreOffice, which is
licensed under the Mozilla Public License (
MPLv2).
"LibreOffice" and "The Document Foundation" are
registered trademarks of their corresponding registered owners or are
in actual use as trademarks in one or more countries. Their respective
logos and icons are also subject to international copyright laws. Use
thereof is explained in our
trademark policy.