Re: --headless broken with --enable-headless

Hi Riccardo,

On Fri, 2012-09-28 at 20:26 +0200, Riccardo Magliocchetti wrote:
> > Here you go, you'll find the valgrind output sans all the zlib / python
> > related errors. Thanks a lot!
>
> update to git 7a3a8a254363801bf6893b23d67f86a7461f8f3b and more or less 
> same valgrind errors. See attached trace.

        It looks really interesting :-) it's hard to tell (from valgrind) where
the threads were pre-empted [ actually logging that might be quite a
nice feature to add to for valgrind ;-], but there is already the
SolarMutex guard to try to stop this from happening.

        I append the odd trace with some thoughts.

        It is -possible- that we never get around to taking the solar mutex in
the first instance in 'main' - such that by the time we come to release
and re-take it in vcl/headless/svpinst.cxx:

void SvpSalInstance::Yield( bool bWait, bool bHandleAllCurrentEvents )

        the count is zero - could you add some fprintf debugging to check that
- just dump nAcquireCount. If that is the case this patch might help:

--- a/vcl/headless/svpinst.cxx
+++ b/vcl/headless/svpinst.cxx
@@ -171,6 +171,9 @@ bool SvpSalInstance::CheckTimeout( bool
bExecuteTimers )
                 // timed out, update timeout
                 m_aTimeout = aTimeOfDay;
                 m_aTimeout += m_nTimeoutMS;
+
+                osl::SolarGuard aGuard( mpSalYieldMutex );
+
                 // notify
                 ImplSVData* pSVData = ImplGetSVData();
                 if( pSVData->mpSalTimer )

        If it does - it's not the real fix ;-) but it'd be good to know.

        Thanks for posting the trace - rather interesting :-)

        All the best,

                Michael.

==28574== Thread 1:
==28574== Invalid read of size 8
==28574==    at 0x739C702: SfxStateCache::SetState_Impl(unsigned short, SfxPoolItem const*, 
unsigned char) (statcach.cxx:454)
==28574==    by 0x738042E: SfxBindings::UpdateControllers_Impl(SfxInterface const*, 
SfxFoundCache_Impl const*, SfxPoolItem const*, unsigned short) (bindings.cxx:1500)
==28574==    by 0x7383C5B: SfxBindings::Update_Impl(SfxStateCache*) (bindings.cxx:437)
==28574==    by 0x7383FD7: SfxBindings::NextJob_Impl(Timer*) (bindings.cxx:1646)
==28574==    by 0x92BF4AD: Timer::ImplTimerCallbackProc() (timer.cxx:142)

        The YieldMutex -should- be held at this point excluding this other thread (?).

==28574==    by 0x95D152D: SvpSalInstance::CheckTimeout(bool) (saltimer.hxx:57)
==28574==    by 0x95D17D7: SvpSalInstance::Yield(bool, bool) (svpinst.cxx:288)
==28574==    by 0x92B4530: Application::Yield(bool) (svapp.cxx:434)
==28574==    by 0x92B45E6: Application::Execute() (svapp.cxx:413)
==28574==    by 0x50AED58: desktop::Desktop::Main() (app.cxx:1711)
==28574==    by 0x92BDFB8: ImplSVMain() (svmain.cxx:173)
==28574==    by 0x92BE8E4: SVMain() (svmain.cxx:210)
==28574==    by 0x50E1CF4: soffice_main (sofficemain.cxx:83)
==28574==    by 0x40069A: main (main.c:25)

==28574==  Address 0x1466bdc8 is 56 bytes inside a block of size 72 free'd
==28574==    at 0x4C27FF2: operator delete(void*) (vg_replace_malloc.c:387)
==28574==    by 0x737F479: SfxBindings::DeleteControllers_Impl() (bindings.cxx:325)
==28574==    by 0x7380572: SfxBindings::~SfxBindings() (bindings.cxx:264)
==28574==    by 0x7380718: SfxBindings::~SfxBindings() (bindings.cxx:275)
==28574==    by 0x758B91E: SfxFrame::DoClose_Impl() (frame.cxx:178)
==28574==    by 0x75AAFC1: SfxBaseController::dispose() (sfxbasecontroller.cxx:1041)

sfx2/source/view/sfxbasecontroller.cxx:

        This method has a live:

                    SolarMutexGuard aGuard;

==28574==    by 0x16B8E785: 
framework::Frame::setComponent(com::sun::star::uno::Reference<com::sun::star::awt::XWindow> const&, 
com::sun::star::uno::Reference<com::sun::star::frame::XController> const&) (frame.cxx:1380)
==28574==    by 0x16B8E1CF: framework::Frame::close(unsigned char) (frame.cxx:1633)
==28574==    by 0x758BE87: SfxFrame::DoClose() (frame.cxx:140)
==28574==    by 0x797F51C: SfxBroadcaster::Broadcast(SfxHint const&) (brdcst.cxx:49)
==28574==    by 0x7511211: SfxModelListener_Impl::notifyClosing(com::sun::star::lang::EventObject 
const&) (objxtor.cxx:173)
==28574==    by 0x7534972: SfxBaseModel::close(unsigned char) (sfxbasemodel.cxx:1491)
==28574==    by 0x1E776909: SwXTextDocument::close(unsigned char) (unotxdoc.cxx:578)
==28574==    by 0x7537FB0: SfxBaseModel::dispose() (sfxbasemodel.cxx:788)
==28574==    by 0x1211D6E7: gcc3::callVirtualMethod(void*, unsigned int, void*, 
_typelib_TypeDescriptionReference*, bool, unsigned long*, unsigned int, unsigned long*, unsigned 
int, double*, unsigned int) (callvirtualmethod.cxx:128)
==28574==    by 0x12120FEE: cpp_call(bridges::cpp_uno::shared::UnoInterfaceProxy*, 
bridges::cpp_uno::shared::VtableSlot, _typelib_TypeDescriptionReference*, int, 
_typelib_MethodParameter*, void*, void**, _uno_Any**) (uno2cpp.cxx:246)
==28574==    by 0x12121ACD: bridges::cpp_uno::shared::unoInterfaceProxyDispatch(_uno_Interface*, 
_typelib_TypeDescription const*, void*, void**, _uno_Any**) (uno2cpp.cxx:440)
==28574==    by 0x15D5CE5E: binaryurp::IncomingRequest::execute_throw(binaryurp::BinaryAny*, 
std::vector<binaryurp::BinaryAny, std::allocator<binaryurp::BinaryAny> >*) const 
(incomingrequest.cxx:251)
==28574==    by 0x15D5D8AB: binaryurp::IncomingRequest::execute() const (incomingrequest.cxx:80)
==28574==    by 0x15D61B4C: request (reader.cxx:89)
==28574==    by 0x663A506: cppu_threadpool::JobQueue::enter(long, unsigned char) (jobqueue.cxx:115)
==28574==    by 0x663B00D: cppu_threadpool::ORequestThread::run() (thread.cxx:179)
==28574==    by 0x663B4E9: threadFunc (thread.hxx:196)
==28574==    by 0x4E467AE: osl_thread_start_Impl (thread.c:261)
==28574==    by 0x5E53EFB: start_thread (pthread_create.c:304)
==28574==    by 0x5B8E89C: clone (clone.S:112)

-- 
michael.meeks@suse.com  <><, Pseudo Engineer, itinerant idiot