Date: prev next · Thread: first prev next last
2020 Archives by date, by thread · List index


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


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.