From ee299664940139f6f9543592ece3b3c0210b59f4 Mon Sep 17 00:00:00 2001 From: Stephan Bergmann Date: Wed, 19 Jul 2017 15:20:04 +0200 Subject: SalInstance::DoYield: Don't drop SolarMutex when accessing user event queue fails with the assert in the OSL_DEBUG_LEVEL > 0 test code in Scheduler::ProcessEventsToIdle firing (see below), indicating that (even though the SolarMutex is locked one frame up in VCLXToolkit::processEventsToIdle), when Application::Reschedule(true) returned, there are unprocessed events in the queue. That failure is with the headless plugin, and looking at SvpSalInstance::DoYield, there was a window of time after m_aEventGuard has been released and before the SolarMutex has been re-acquired, where other threads could enqueue events. If Application::Reschedule(true) can thus not guarantee that the queue is empty when it returned, that would mean that the assert in Scheduler::ProcessEventsToIdle (introduced with c0710abfebd320903a3edb23d4b1441ea351b0be "Add some Scheduler unit tests and logging") is bogus. However, at least the two SalInstance::DoYield implementations SvpSalInstance::DoYield and AquaSalInstance::DoYield appear to have no reason in the first place to drop the SolarMutex when accessing the user event queue. So removing that dropping should make the assert in Scheduler::ProcessEventsToIdle faithful, at least for these two implementations. But I have no idea whether the other three implementations (X11SalInstance::DoYield in vcl/unx/generic/app/salinst.cxx, GtkInstance::DoYield in vcl/unx/gtk/gtkinst.cxx, and WinSalInstance::DoYield in vcl/win/app/salinst.cxx) have similar issues---i.e., whether everything is good after this change, whether those other implementations need similar changes, or whether ultimately Application::Reschedule(true) cannot guarantee the queue to be empty upon return (in which case the assert in Scheduler::ProcessEventsToIdle would need to go). > warn:vcl.schedule:27575:54:vcl/source/app/svapp.cxx:535: Unprocessed Idle: vcl::Window maPaintIdle > soffice.bin: /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/vcl/source/app/svapp.cxx:540: static void Scheduler::ProcessEventsToIdle(): Assertion `!bAnyIdle' failed. [...] > Thread 2 (Thread 0x2b12bf1e4a00 (LWP 27575)): > #0 0x00002b12bfb1a69d in poll () at /lib64/libc.so.6 > #1 0x00002b12ca9129e7 in SvpSalInstance::DoReleaseYield(int) (this=0x1be8b40, nTimeoutMS=5) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/vcl/headless/svpinst.cxx:392 > aPoll = {fd = 6, events = 1, revents = 0} > nAcquireCount = 1 > #2 0x00002b12ca9128c9 in SvpSalInstance::DoYield(bool, bool, unsigned long) (this=0x1be8b40, bWait=true, bHandleAllCurrentEvents=false, nReleased=0) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/vcl/headless/svpinst.cxx:375 > nTimeoutMS = 5 > __PRETTY_FUNCTION__ = "virtual bool SvpSalInstance::DoYield(bool, bool, sal_uLong)" > aEvents = empty std::__debug::list > nAcquireCount = 1 > bEvent = false > #3 0x00002b12ca7a98cd in ImplYield(bool, bool, unsigned long) (i_bWait=true, i_bAllEvents=false, nReleased=0) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/vcl/source/app/svapp.cxx:484 > pSVData = 0x2b12cb2a9e00 ::get()::instance> > bProcessedEvent = false > #4 0x00002b12ca7a5796 in Application::Yield() () at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/vcl/source/app/svapp.cxx:555 > #5 0x00002b12ca7a52f5 in Application::Execute() () at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/vcl/source/app/svapp.cxx:461 > pSVData = 0x2b12cb2a9e00 ::get()::instance> > #6 0x00002b12bf69c7e5 in desktop::Desktop::DoExecute() () at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/desktop/source/app/app.cxx:1350 > #7 0x00002b12bf69d9c4 in desktop::Desktop::Main() (this=0x7fff49ea9ac0) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/desktop/source/app/app.cxx:1735 > layer2 = {m_aEnvTypeName = "gcc3", m_xPreviousContext = uno::Reference to (desktop::DesktopContext *) 0x1bebdf8} > rCmdLineArgs = @0x2b12bfa2c6a0: {m_cwdUrl = boost::optional "file:///home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/workdir/JunitTest/sd_unoapi/user", m_minimized = false, m_invisible = false, m_norestore = true, m_headless = true, m_eventtesting = false, m_quickstart = false, m_noquickstart = true, m_terminateafterinit = false, m_nologo = true, m_nolockcheck = false, m_nodefault = false, m_help = false, m_writer = false, m_calc = false, m_draw = false, m_impress = false, m_global = false, m_math = false, m_web = false, m_base = false, m_helpwriter = false, m_helpcalc = false, m_helpdraw = false, m_helpbasic = false, m_helpmath = false, m_helpimpress = false, m_helpbase = false, m_version = false, m_splashpipe = false, m_textcat = false, m_scriptcat = false, m_safemode = false, m_unknown = "", m_bEmpty = false, m_bDocumentArgs = false, m_accept = std::__debug::vector of length 1, capacity 1 = {"pipe,name=oootest16264f8c-0bcc-4a4f-9c1b-52af72b78eb5;urp"}, m_unaccept = std::__debug::vector of length 0, capacity 0, m_openlist = std::__debug::vector of length 0, capacity 0, m_viewlist = std::__debug::vector of length 0, capacity 0, m_startlist = std::__debug::vector of length 0, capacity 0, m_forceopenlist = std::__debug::vector of length 0, capacity 0, m_forcenewlist = std::__debug::vector of length 0, capacity 0, m_printlist = std::__debug::vector of length 0, capacity 0, m_printtolist = std::__debug::vector of length 0, capacity 0, m_printername = "", m_conversionlist = std::__debug::vector of length 0, capacity 0, m_conversionparams = "", m_conversionout = "", m_infilter = std::__debug::vector of length 0, capacity 0, m_language = "", m_pidfile = ""} > xRestartManager = uno::Reference to (comphelper::OOfficeRestartManager *) 0x29a7bf8 > layer = {m_aEnvTypeName = "gcc3", m_xPreviousContext = uno::Reference to (DesktopEnvironmentContext *) 0x1bebc38} > xContext = uno::Reference to (cppu::ComponentContext *) 0x1d200b0 > aOptions = { = { = {_vptr.ConfigurationBroadcaster = 0x2b12c8a3dfb0 , mpList = std::unique_ptr >> containing 0x0, m_nBroadcastBlocked = 0, m_nBlockedHint = NONE}, = {_vptr.ConfigurationListener = 0x2b12c8a3dfe8 }, }, = {_vptr.SfxListener = 0x2b12c8a3e010 , mpImpl = std::unique_ptr containing 0x2a46530}, static sm_pSingleImplConfig = 0x2a47e60, static sm_nAccessibilityRefCount = 16} > eStatus = desktop::Desktop::BS_OK > aUnknown = "" > inst_fin = desktop::userinstall::EXISTED > xDesktop = uno::Reference to (framework::Desktop *) 0x29cb3a8 > aAppearanceCfg = { = { = {_vptr.ConfigurationBroadcaster = 0x2b12c8a3e090 , mpList = std::unique_ptr >> containing 0x0, m_nBroadcastBlocked = 0, m_nBlockedHint = NONE}, sSubTree = "Office.Common/View", m_xHierarchyAccess = uno::Reference to (configmgr::RootAccess *) 0x29ca3f8, xChangeLstnr = empty uno::Reference, m_nMode = DelayedUpdate, m_bIsModified = false, m_bEnableInternalNotification = false, m_nInValueChange = 0}, nDragMode = SystemDep, nSnapMode = NONE, nMiddleMouse = (unknown: 2), nAAMinPixelHeight = 8, bMenuMouseFollow = true, bFontAntialiasing = true, static bInitialized = true} > #8 0x00002b12ca7b33d0 in ImplSVMain() () at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/vcl/source/app/svmain.cxx:194 > pSVData = 0x2b12cb2a9e00 ::get()::instance> > nReturn = 1 > bInit = true > #9 0x00002b12ca7b3539 in SVMain() () at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/vcl/source/app/svmain.cxx:232 > nRet = 0 > #10 0x00002b12bf6f1ff1 in soffice_main() () at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/desktop/source/app/sofficemain.cxx:163 > bSuccess = true > aDesktop = { = {_vptr.Application = 0x2b12bfa269b0 }, m_rSplashScreen = empty uno::Reference, m_bCleanedExtensionCache = false, m_bServicesRegistered = true, m_aBootstrapError = desktop::Desktop::BE_OK, m_aBootstrapErrorMessage = "", m_aBootstrapStatus = desktop::Desktop::BS_OK, m_xLockfile = std::unique_ptr containing 0x29c9b10, m_firstRunTimer = { = {_vptr.Task = 0x2b12cb2911b0 , mpSchedulerData = 0x0, mpDebugName = 0x2b12bf777570 "desktop::Desktop m_firstRunTimer", mePriority = DEFAULT, mbActive = false}, maInvokeHandler = {function_ = 0x2b12bf6a2c6c , instance_ = 0x7fff49ea9ac0}, mnTimeout = 3000, mbAuto = false}, m_aUpdateThread = {_M_id = {_M_thread = 0}}, static pResMgr = 0x0} > rCmdLineArgs = @0x2b12bfa2c6a0: {m_cwdUrl = boost::optional "file:///home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/workdir/JunitTest/sd_unoapi/user", m_minimized = false, m_invisible = false, m_norestore = true, m_headless = true, m_eventtesting = false, m_quickstart = false, m_noquickstart = true, m_terminateafterinit = false, m_nologo = true, m_nolockcheck = false, m_nodefault = false, m_help = false, m_writer = false, m_calc = false, m_draw = false, m_impress = false, m_global = false, m_math = false, m_web = false, m_base = false, m_helpwriter = false, m_helpcalc = false, m_helpdraw = false, m_helpbasic = false, m_helpmath = false, m_helpimpress = false, m_helpbase = false, m_version = false, m_splashpipe = false, m_textcat = false, m_scriptcat = false, m_safemode = false, m_unknown = "", m_bEmpty = false, m_bDocumentArgs = false, m_accept = std::__debug::vector of length 1, capacity 1 = {"pipe,name=oootest16264f8c-0bcc-4a4f-9c1b-52af72b78eb5;urp"}, m_unaccept = std::__debug::vector of length 0, capacity 0, m_openlist = std::__debug::vector of length 0, capacity 0, m_viewlist = std::__debug::vector of length 0, capacity 0, m_startlist = std::__debug::vector of length 0, capacity 0, m_forceopenlist = std::__debug::vector of length 0, capacity 0, m_forcenewlist = std::__debug::vector of length 0, capacity 0, m_printlist = std::__debug::vector of length 0, capacity 0, m_printtolist = std::__debug::vector of length 0, capacity 0, m_printername = "", m_conversionlist = std::__debug::vector of length 0, capacity 0, m_conversionparams = "", m_conversionout = "", m_infilter = std::__debug::vector of length 0, capacity 0, m_language = "", m_pidfile = ""} > aUnknown = "" > #11 0x0000000000400957 in sal_main () at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/desktop/source/app/main.c:48 > ret = 0 > #12 0x000000000040093d in main (argc=8, argv=0x7fff49ea9df8) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/desktop/source/app/main.c:47 > ret = 0 > > Thread 1 (Thread 0x2b12e6862700 (LWP 11663)): > #0 0x00002b12bfa635f7 in raise () at /lib64/libc.so.6 > #1 0x00002b12bfa64ce8 in abort () at /lib64/libc.so.6 > #2 0x00002b12bf406165 in (anonymous namespace)::callSystemHandler(int, siginfo_t*, void*) (signal=6, info=0x2b12e68607f0, context=0x2b12e68606c0) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/sal/osl/unx/signal.cxx:389 > act = {__sigaction_handler = {sa_handler = 0x0, sa_sigaction = 0x0}, sa_mask = {__val = {0 }}, sa_flags = 0, sa_restorer = 0xe6860b90} > i = 5 > #3 0x00002b12bf406472 in (anonymous namespace)::signalHandlerFunction(int, siginfo_t*, void*) (signal=6, info=0x2b12e68607f0, context=0x2b12e68606c0) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/sal/osl/unx/signal.cxx:486 > act = {__sigaction_handler = {sa_handler = 0x2b12e68607e0, sa_sigaction = 0x2b12e68607e0}, sa_mask = {__val = {0, 18446744069414584320, 0, 0, 61329184, 47360176948768, 47356309405696, 0, 47356309405696, 47356309405696, 4294967295, 47356309405696, 0, 0, 47359528444352, 47360176950400}}, sa_flags = -72537977, sa_restorer = 0x2b12bfdea1c0 <_IO_2_1_stderr_>} > Info = {Signal = osl_Signal_AccessViolation, UserSignal = 6, UserData = 0x0} > #4 0x00002b12bfa63670 in () at /lib64/libc.so.6 > #5 0x00002b12bfa635f7 in raise () at /lib64/libc.so.6 > #6 0x00002b12bfa64ce8 in abort () at /lib64/libc.so.6 > #7 0x00002b12bfa5c566 in __assert_fail_base () at /lib64/libc.so.6 > #8 0x00002b12bfa5c612 in () at /lib64/libc.so.6 > #9 0x00002b12ca7a56ba in Scheduler::ProcessEventsToIdle() () at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/vcl/source/app/svapp.cxx:540 > pSVData = 0x2b12cb2a9e00 ::get()::instance> > bAnyIdle = true > __PRETTY_FUNCTION__ = "static void Scheduler::ProcessEventsToIdle()" > nSanity = 1 > pSchedulerData = 0x0 > #10 0x00002b12c8c8c554 in (anonymous namespace)::VCLXToolkit::processEventsToIdle() (this=0x3abc2a0) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/toolkit/source/awt/vclxtoolkit.cxx:1897 > aSolarGuard = {m_solarMutex = @0x1be9610} > aZone = {m_sProfileId = 0x2b12c8e672a2 "processEvents", m_aCreateTime = 0} > #11 0x00002b12e317751d in gcc3::callVirtualMethod(void*, unsigned int, void*, _typelib_TypeDescriptionReference*, bool, unsigned long*, unsigned int, unsigned long*, double*) (pThis=0x3abc2f0, nVtableIndex=9, pRegisterReturn=0x0, pReturnTypeRef=0x1c07390, bSimpleReturn=true, pStack=0x2b12e6861170, nStack=0, pGPR=0x2b12e68612d0, pFPR=0x2b12e6861300) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/bridges/source/cpp_uno/gcc3_linux_x86-64/callvirtualmethod.cxx:133 > data = {pMethod = 47359678006708, pStack = 0x2b12e6861170, nStack = 0, pGPR = 0x2b12e68612d0, pFPR = 0x2b12e6861300, rax = 0, rdx = 47360176951616, xmm0 = 2.3399007939816937e-310, xmm1 = 3.0079874608688941e-316} > pMethod = 47359683834264 > #12 0x00002b12e317615c in cpp_call(bridges::cpp_uno::shared::UnoInterfaceProxy*, bridges::cpp_uno::shared::VtableSlot, typelib_TypeDescriptionReference*, sal_Int32, typelib_MethodParameter*, void*, void**, uno_Any**) (pThis=0x3ab9a80, aVtableSlot=..., pReturnTypeRef=0x1c07390, nParams=0, pParams=0x0, pUnoReturn=0x0, pUnoArgs=0x0, ppUnoExc=0x2b12e6861488) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/bridges/source/cpp_uno/gcc3_linux_x86-64/uno2cpp.cxx:237 > pStack = 0x2b12e6861170 > pFPR = {2.3399036413000935e-310, 2.3399017635979741e-310, 1.9097962118687451e-313, 2.3399036413020203e-310, 2.9003052604790195e-316, -1.3614915359519845e+193, 2.339903641302465e-310, 0} > __PRETTY_FUNCTION__ = "void cpp_call(bridges::cpp_uno::shared::UnoInterfaceProxy*, bridges::cpp_uno::shared::VtableSlot, typelib_TypeDescriptionReference*, sal_Int32, typelib_MethodParameter*, void*, void**, uno_Any**)" > pCppArgs = 0x2b12e6861160 > pStackStart = 0x2b12e6861170 > pGPR = {61588208, 9, 47360176952128, 47360119419570, 0, 58702832} > nTempIndices = 0 > nFPR = 0 > pAdjustedThisPtr = 0x3abc2f0 > ppTempParamTypeDescr = 0x2b12e6861160 > nGPR = 1 > pReturnTypeDescr = 0x1c07390 > pCppReturn = 0x0 > bSimpleReturn = true > pTempIndices = 0x2b12e6861160 > #13 0x00002b12e3176bdb in bridges::cpp_uno::shared::unoInterfaceProxyDispatch(_uno_Interface*, _typelib_TypeDescription const*, void*, void**, _uno_Any**) (pUnoI=0x3ab9a80, pMemberDescr=0x37fbbf0, pReturn=0x0, pArgs=0x0, ppException=0x2b12e6861488) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/bridges/source/cpp_uno/gcc3_linux_x86-64/uno2cpp.cxx:425 > nMemberPos = 27 > aVtableSlot = {offset = 0, index = 9} > pThis = 0x3ab9a80 > pTypeDescr = 0x2b14740 > __PRETTY_FUNCTION__ = "void bridges::cpp_uno::shared::unoInterfaceProxyDispatch(uno_Interface*, const typelib_TypeDescription*, void*, void**, uno_Any**)" > #14 0x00002b12e441cf28 in binaryurp::IncomingRequest::execute_throw(binaryurp::BinaryAny*, std::__debug::vector >*) const (this=0x3a0fd50, returnValue=0x2b12e68618a0, outArguments=0x2b12e6861920) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/binaryurp/source/incomingrequest.cxx:242 > exc = > pexc = 0x2b12e68614b0 > retType = {_pTypeDescr = 0x1c07390} > nSize = 0 > retBuf = std::__debug::vector of length 0, capacity 0 > outBufs = empty std::__debug::list > args = std::__debug::vector of length 0, capacity 0 > __PRETTY_FUNCTION__ = "bool binaryurp::IncomingRequest::execute_throw(binaryurp::BinaryAny*, std::__debug::vector*) const" > isExc = false > #15 0x00002b12e441bd16 in binaryurp::IncomingRequest::execute() const (this=0x3a0fd50) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/binaryurp/source/incomingrequest.cxx:79 > resetCc = true > oldCc = {m_pUnoI = 0x0} > ret = {data_ = _uno_Any(void)} > outArgs = std::__debug::vector of length 0, capacity 0 > isExc = false > #16 0x00002b12e443c7a4 in binaryurp::(anonymous namespace)::request(void*) (pThreadSpecificData=0x3a0fd50) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/binaryurp/source/reader.cxx:85 > __PRETTY_FUNCTION__ = "void binaryurp::{anonymous}::request(void*)" > #17 0x00002b12c2ce1f5f in cppu_threadpool::JobQueue::enter(long, bool) (this=0x3ab9da0, nDisposeId=61386512, bReturnWhenNoJob=true) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/cppu/source/threadpool/jobqueue.cxx:107 > guard = {pT = 0x3ab9da0} > job = {pThreadSpecificData = 0x3a0fd50, doRequest = 0x2b12e443c73b } > pReturn = 0x0 > #18 0x00002b12c2ce6bfd in cppu_threadpool::ORequestThread::run() (this=0x3a8af10) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/cppu/source/threadpool/thread.cxx:172 > #19 0x00002b12c2ce712b in osl::threadFunc(void*) (param=0x3a8af20) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/include/osl/thread.hxx:185 > pObj = 0x3a8af20 > #20 0x00002b12bf40d7bd in osl_thread_start_Impl(void*) (pData=0x3a4c7e0) at /home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/sal/osl/unx/thread.cxx:237 > terminate = false > pImpl = 0x3a4c7e0 > __PRETTY_FUNCTION__ = "void* osl_thread_start_Impl(void*)" > #21 0x00002b12bfdf7dc5 in start_thread () at /lib64/libpthread.so.0 > #22 0x00002b12bfb24ced in clone () at /lib64/libc.so.6 [...] > make[1]: *** [/home/tdf/lode/jenkins/workspace/lo_tb_master_linux_dbg/workdir/JunitTest/sd_unoapi/done] Error 1 Change-Id: I7d034c02a49d315104d8329a4e1119e14e8e5e40 Reviewed-on: https://gerrit.libreoffice.org/40176 Tested-by: Jenkins Reviewed-by: Jan-Marek Glogowski --- vcl/headless/svpinst.cxx | 4 ---- vcl/osx/salinst.cxx | 3 --- 2 files changed, 7 deletions(-) diff --git a/vcl/headless/svpinst.cxx b/vcl/headless/svpinst.cxx index 5140b27340b3..4b76f0c3fbec 100644 --- a/vcl/headless/svpinst.cxx +++ b/vcl/headless/svpinst.cxx @@ -310,9 +310,7 @@ bool SvpSalInstance::DoYield(bool bWait, bool bHandleAllCurrentEvents, sal_uLong assert(nReleased == 0); // not implemented // first, check for already queued events. - // release yield mutex std::list< SalUserEvent > aEvents; - sal_uLong nAcquireCount = ReleaseYieldMutex(); { osl::MutexGuard g(m_aEventGuard); if( ! m_aUserEvents.empty() ) @@ -329,8 +327,6 @@ bool SvpSalInstance::DoYield(bool bWait, bool bHandleAllCurrentEvents, sal_uLong } } } - // acquire yield mutex again - AcquireYieldMutex( nAcquireCount ); bool bEvent = !aEvents.empty(); if( bEvent ) diff --git a/vcl/osx/salinst.cxx b/vcl/osx/salinst.cxx index f06504cc9678..4f98d64cdb76 100644 --- a/vcl/osx/salinst.cxx +++ b/vcl/osx/salinst.cxx @@ -556,8 +556,6 @@ bool AquaSalInstance::DoYield(bool bWait, bool bHandleAllCurrentEvents, sal_uLon bool bDispatchUser = true; while( bDispatchUser ) { - sal_uLong nCount = ReleaseYieldMutex(); - // get one user event SalUserEvent aEvent( nullptr, nullptr, SalEvent::NONE ); { @@ -571,7 +569,6 @@ bool AquaSalInstance::DoYield(bool bWait, bool bHandleAllCurrentEvents, sal_uLon else bDispatchUser = false; } - AcquireYieldMutex( nCount ); // dispatch it if( aEvent.mpFrame && AquaSalFrame::isAlive( aEvent.mpFrame ) ) -- cgit v1.2.3