Is ScAreaLink::RefreshHdl run too often?

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



My slow ASan+UBSan Linux builds sometimes livelock in e.g. UITest_calc_tests8: The soffice.bin main thread's event loop at

[...]
#33 0x00007f7fe8ea35dc in ScAreaLink::RefreshHdl(Timer*) (this=0x611000891240) at sc/source/ui/docshell/arealink.cxx:492
#34 0x00007f7fe8e920a9 in ScAreaLink::LinkStubRefreshHdl(void*, Timer*) (instance=0x611000891240, data=0x611000891288) at sc/source/ui/docshell/arealink.cxx:490
#35 0x00007f8049aacf7e in Link<Timer*, void>::Call(Timer*) const (this=0x6110008912a8, data=0x611000891288) at include/tools/link.hxx:111
#36 0x00007f8049aac55d in Timer::Invoke() (this=0x611000891288) at vcl/source/app/timer.cxx:75
#37 0x00007f7fe71b606f in ScRefreshTimer::Invoke() (this=0x611000891288) at sc/source/core/tool/refreshtimer.cxx:126
#38 0x00007f8049903fcc in Scheduler::CallbackTaskScheduling() () at vcl/source/app/scheduler.cxx:471
#39 0x00007f804a9ae704 in SalTimer::CallCallback() (this=0x6030002ef180) at vcl/inc/saltimer.hxx:54
#40 0x00007f804a9a22f1 in SvpSalInstance::CheckTimeout(bool) (this=0x611000001bc0, bExecuteTimers=true) at vcl/headless/svpinst.cxx:210
#41 0x00007f804a9a8f06 in SvpSalInstance::DoYield(bool, bool) (this=0x611000001bc0, bWait=true, bHandleAllCurrentEvents=false) at vcl/headless/svpinst.cxx:467
#42 0x00007f80499f6eb2 in ImplYield(bool, bool) (i_bWait=true, i_bAllEvents=false) at vcl/source/app/svapp.cxx:465
#43 0x00007f80499f5fd8 in Application::Yield() () at vcl/source/app/svapp.cxx:532
#44 0x00007f80499f5c0a in Application::Execute() () at vcl/source/app/svapp.cxx:444
#45 0x00007f807e228626 in desktop::Desktop::Main() (this=0x7f8017cb8080) at desktop/source/app/app.cxx:1602
#46 0x00007f8049a965ca in ImplSVMain() () at vcl/source/app/svmain.cxx:199
#47 0x00007f8049a9faa1 in SVMain() () at vcl/source/app/svmain.cxx:231
#48 0x00007f807e40d23b in soffice_main() () at desktop/source/app/sofficemain.cxx:98
#49 0x000000000030114d in sal_main () at desktop/source/app/main.c:49
#50 0x0000000000301127 in main (argc=7, argv=0x7ffc396eab68) at desktop/source/app/main.c:47

keeps invoking ScAreaLink::RefreshHdl. It looks like the work that it does takes so long that a fresh timer-triggered invocation is already pending whenever the previous one is done. So Application::Execute (frame 44) keeps calling Appliation::Yield (frame 43) keeps calling SvpSalInstance::DoYield (frame 41) keeps calling ScAreaLink::RefreshHdl (frame 33), without SvpSalInstance::DoYield ever running into a code path that would temporarily release the SolarMutex, so thread 1 keeps running forever with the SolarMutex locked.

The controlling Python process sent a remote URP request that is pending in soffice.bin at

Thread 24 (LWP 425037 "cppu_threadpool"):
#0  0x00007f807d6aa7b0 in __lll_lock_wait () at /lib64/libpthread.so.0
#1  0x00007f807d6a35d0 in pthread_mutex_lock () at /lib64/libpthread.so.0
#2  0x00007f807f039467 in osl_acquireMutex(oslMutex) (pMutex=0x604000092290) at sal/osl/unx/mutex.cxx:100
#3  0x00007f804600acba in osl::Mutex::acquire() (this=0x60e0000250a8) at include/osl/mutex.hxx:61
#4  0x00007f804a9a6b2a in SvpSalYieldMutex::doAcquire(unsigned int) (this=0x60e0000250a0, nLockCount=1) at vcl/headless/svpinst.cxx:383
#5  0x00007f80466d0db2 in comphelper::SolarMutex::acquire(unsigned int) (this=0x60e0000250a0, nLockCount=1) at include/comphelper/solarmutex.hxx:86
#6  0x00007f80466d0c34 in osl::Guard<comphelper::SolarMutex>::Guard(comphelper::SolarMutex&) (this=0x7f7e5623d520, t=...) at include/osl/mutex.hxx:142
#7  0x00007f80466cf29d in SolarMutexGuard::SolarMutexGuard() (this=0x7f7e5623d520) at include/vcl/svapp.hxx:1348
#8  0x00007f804a4a80e3 in (anonymous namespace)::UITestUnoObj::executeCommand(rtl::OUString const&) (this=0x60b000157b90, rCommand=".uno:Undo") at vcl/source/uitest/uno/uitest_uno.cxx:69
#9  0x00007f8016a2bd9d in gcc3::callVirtualMethod(void*, unsigned int, void*, _typelib_TypeDescriptionReference*, bool, unsigned long*, unsigned int, unsigned long*, double*) (pThis=0x60b000157be0, nVtableIndex=3, pRegisterReturn=0x60200083c6b0, pReturnTypeRef=0x6070000033c0, bSimpleReturn=true, pStack=0x7f7e5f743280, nStack=0, pGPR=0x7f7e56715060, pFPR=0x7f7e567150c0) at bridges/source/cpp_uno/gcc3_linux_x86-64/callvirtualmethod.cxx:77
#10 0x00007f8016a2666a in cpp_call(bridges::cpp_uno::shared::UnoInterfaceProxy*, bridges::cpp_uno::shared::VtableSlot, _typelib_TypeDescriptionReference*, int, _typelib_MethodParameter*, void*, void**, _uno_Any**) (pThis=0x606001f60160, aVtableSlot=..., pReturnTypeRef=0x6070000033c0, nParams=1, pParams=0x6030012ba2b0, pUnoReturn=0x60200083c6b0, pUnoArgs=0x60200083c690, ppUnoExc=0x7f7e568b7880) at bridges/source/cpp_uno/gcc3_linux_x86-64/uno2cpp.cxx:233
#11 0x00007f8016a23509 in unoInterfaceProxyDispatch(uno_Interface*, typelib_TypeDescription const*, void*, void**, uno_Any**) (pUnoI=0x606001f60160, pMemberDescr=0x60f00007f480, pReturn=0x60200083c6b0, pArgs=0x60200083c690, ppException=0x7f7e568b7880) at bridges/source/cpp_uno/gcc3_linux_x86-64/uno2cpp.cxx:413
#12 0x00007f80119a23dd in binaryurp::IncomingRequest::execute_throw(binaryurp::BinaryAny*, std::__debug::vector<binaryurp::BinaryAny, std::allocator<binaryurp::BinaryAny> >*) const (this=0x60d00034eb10, returnValue=0x7f7e568b6020, outArguments=0x7f7e568b6060) at binaryurp/source/incomingrequest.cxx:235
#13 0x00007f801199c2ac in binaryurp::IncomingRequest::execute() const (this=0x60d00034eb10) at binaryurp/source/incomingrequest.cxx:78
#14 0x00007f8011a78a33 in request(void*) (pThreadSpecificData=0x60d00034eb10) at binaryurp/source/reader.cxx:85
#15 0x00007f807779595a in cppu_threadpool::JobQueue::enter(void const*, bool) (this=0x6120000f67c0, nDisposeId=0x60600052c940, bReturnWhenNoJob=true) at cppu/source/threadpool/jobqueue.cxx:100
#16 0x00007f80777be0ad in cppu_threadpool::ORequestThread::run() (this=0x60600052c940) at cppu/source/threadpool/thread.cxx:164
#17 0x00007f80777d0c05 in threadFunc(void*) (param=0x60600052c950) at include/osl/thread.hxx:189
#18 0x00007f807f0d1170 in osl_thread_start_Impl(void*) (pData=0x60c00021a600) at sal/osl/unx/thread.cxx:264

waiting forever to acquire the SolarMutex.

<https://git.libreoffice.org/core/+/b9ea3467383ccdfe4be842e61267256f281487ee%5E!/> "svp: always release SolarMutex on yield" tried to address that (by making sure that SvpSalInstance::DoYield eventually releases the SolarMutex temporarily, but it was reverted again at least for now with <https://git.libreoffice.org/core/+/4abd2598f7816891af3bd462ffaee57f3423b9f9%5E!/> "Revert: svp: always release SolarMutex on yield".

However, regardless of how best to solve the livelock, it looks questionable whether ScAreaLink::RefreshHdl should trigger so often in the first place?

_______________________________________________
LibreOffice mailing list
LibreOffice@xxxxxxxxxxxxxxxxxxxxx
https://lists.freedesktop.org/mailman/listinfo/libreoffice



[Index of Archives]     [LARTC]     [Bugtraq]     [Yosemite Forum]     [Photo]

  Powered by Linux