Re: Need help with debugging LO freeze

On Tue, 2012-05-08 at 21:10 +0200, Daniel Naber wrote:
> I'm quite sure, as I just print the milliseconds before and after certain 
> lines. This line often takes about 20ms on my computer, because its result 
> is not cached:

        ok ? when I ctrl-c I get traces going into Java and into languagetool
from this place:

... empty java frames ...
JNI stuff
libjava_uno.so
libgcc3_uno.so  
LngSvcMgd::GetAvailableGrammarSvcs_Impl()
...

        There is (by now) probably some wunder-Java/gdb/python thing that would
unwind the stack enough to show what methods are being jitted (I guess),
but I don't know how to do that.

> As it is called about 200 times because of the many Locales that 
> Languagetool supports, I get a 4-second freeze.

        Right - I get a 9 second freeze here (wow) - but I'm running under
strace -f -o /tmp/slog -ttt with some instrumentation (I attach the
patch) - it's a bit of a fun hack ;-) but it shows at least something.

        The transition into java is made much more painful by the large number
of maps we have in /proc/self/maps - which has to be parsed to ensure
that we add/remove the stack-guard page as we enter/leave java (sadly
that performs really poorly) - /proc/self/maps is 68K and is 'read' 1K
at a time - 68 system-calls per switch to Java (sigh).

> Maybe there simply never was a component which supports that many locales, 
> thus this was never an issue...

        Yep - it's possible :-) but I think you're on the money with the cache
idea - it seems nonsensical to me that we would call:
'GetAvailableGrammarSvcs_Impl' so many times back-to-back without
pAvailGrammarSvcs being set to cache it. After all - if we change the
configure keys - we should refresh that thing.

        So - after all that ;-) I'm essentially with you that disabling caching
in LngSvcMgr::getAvailableServices is really silly :-) particularly
since the LngSvcMgr::Notify() -should- cause the cache to be
re-generated if the GrammarCheckerList is changed [ does that include
new languages ? ].

        Wow - the CalcDataFilesChangedCheckValue() method seems to always
return zero ;-) so ... it'd be worth chopping that out of the code as a
simple re-factor to clarify (seems that's just a first-start style
boolean). 

        I guess; in general it'd be rather nice to have a nice, pretty, boost
"UNO components changed" signal - that denotes that a new component has
been installed / removed - so we could throw away some of these
caches :-) Stephan - is there anything like that, that we could hook ?
        
        Daniel - thanks for doing some great research here - what's your
preferred fix ? any chance of a patch for that so we can give credit
where it is due ? [ or do you want me to go wild in that general area -
a bonus of doing it yourself is that I can sign it off for
3.5.<next> ;-]

        Many thanks,

                Michael

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

diff --git a/linguistic/source/lngsvcmgr.cxx b/linguistic/source/lngsvcmgr.cxx
index b93364b..5e57f50 100644
--- a/linguistic/source/lngsvcmgr.cxx
+++ b/linguistic/source/lngsvcmgr.cxx
@@ -790,6 +790,7 @@ void LngSvcMgr::GetAvailableSpellSvcs_Impl()
     }
 }
 
+#include <unistd.h>
 
 void LngSvcMgr::GetAvailableGrammarSvcs_Impl()
 {
@@ -797,6 +798,7 @@ void LngSvcMgr::GetAvailableGrammarSvcs_Impl()
     {
         pAvailGrammarSvcs = new SvcInfoArray;
 
+        access ("grammar: start_impl", 0);
         uno::Reference< lang::XMultiServiceFactory >  xFac( comphelper::getProcessServiceFactory() 
);
         if (xFac.is())
         {
@@ -823,7 +825,9 @@ void LngSvcMgr::GetAvailableGrammarSvcs_Impl()
                             uno::Reference< beans::XPropertySet > xProps( xFac, uno::UNO_QUERY );
 
                             xProps->getPropertyValue( OUString( RTL_CONSTASCII_USTRINGPARAM( 
"DefaultContext" ))) >>= xContext;
+                            access ("grammar: createInstance", 0);
                             xSvc = uno::Reference< linguistic2::XProofreader >( ( 
xCompFactory.is() ? xCompFactory->createInstanceWithContext( xContext ) : 
xFactory->createInstance() ), uno::UNO_QUERY );
+                            access ("grammar: createInstance - done", 0);
                         }
                         catch (uno::Exception &rEx)
                         {
@@ -837,6 +841,7 @@ void LngSvcMgr::GetAvailableGrammarSvcs_Impl()
                         OUString            aImplName;
                         uno::Sequence< sal_Int16 >   aLanguages;
                         uno::Reference< XServiceInfo > xInfo( xSvc, uno::UNO_QUERY );
+                        access ("grammar: getImplementationName", 0);
                         if (xInfo.is())
                             aImplName = xInfo->getImplementationName();
                         DBG_ASSERT( aImplName.getLength(),
@@ -849,10 +854,12 @@ void LngSvcMgr::GetAvailableGrammarSvcs_Impl()
                         }
 
                         pAvailGrammarSvcs->push_back( new SvcInfo( aImplName, aLanguages ) );
+                        access ("grammar: getImplementationName - done", 0);
                     }
                 }
             }
         }
+        access ("grammar: end_impl", 0);
     }
 }