I have a slow startup problem with a library I have written. The observed behavior is that perl scripts that use my library *intermittently* take 30 seconds to startup. If I run them again immediately thereafter, they drop back down to about 10 seconds to startup. If I wait for some time (several hours, perhaps, although I'm not sure what the trigger is), then the script will exhibit slow startup again for the first execution and behave normally thereafter. Rebooting also causes the problem to reappear.
I'm using Win32::OLE quite extensively to interact with several of our COM objects - and I even have some COM calls in one of by BEGIN blocks. All of this works fine, with the exception of this intermittent startup lag. I have trouble reproducing the problem, so I even have trouble diagnosing it further (using process explorer, etc). Does anyone have any suggestion or advice for what might be going on and how to track it down? I'm wondering if there is some caching of COM objects going on perhaps that could be going on? I'm running on Windows XP 32 bit (perhaps that matters, I don't know). I've tried running with -dprof and here's what it shows for the first and second runs: FIRST RUN: Total Elapsed Time = 37.44117 Seconds User+System Time = 2.947177 Seconds Exclusive Times %Time ExclSec CumulS #Calls sec/call Csec/c Name 70.8 2.087 2.079 1730 0.0012 0.0012 Win32::OLE::Dispatch 9.03 0.266 0.421 2 0.1329 0.2103 Win32::OLE::Const::_Typelibs 5.26 0.155 0.155 744 0.0002 0.0002 Win32::OLE::Const::_Typelib 3.19 0.094 0.714 39 0.0024 0.0183 STRIDE::Test::BEGIN 1.56 0.046 0.759 4 0.0115 0.1899 main::BEGIN 1.53 0.045 0.041 796 0.0001 0.0001 Win32::OLE::DESTROY 1.36 0.040 1.053 1729 0.0000 0.0006 Win32::OLE::AUTOLOAD 1.09 0.032 0.032 2 0.0160 0.0160 Win32::OLE::new 1.05 0.031 0.031 5 0.0062 0.0062 Devel::Symdump::_symdump 1.05 0.031 0.031 4 0.0077 0.0077 Config::BEGIN 1.05 0.031 0.045 8 0.0039 0.0057 Pod::POM::BEGIN 0.54 0.016 0.016 1 0.0160 0.0160 Win32::OLE::Uninitialize 0.54 0.016 0.016 1 0.0160 0.0160 Devel::Symdump::_partdump 0.54 0.016 0.016 5 0.0032 0.0032 File::Basename::BEGIN 0.54 0.016 0.016 6 0.0027 0.0027 Text::Wrap::BEGIN SECOND RUN: Total Elapsed Time = 10.91888 Seconds User+System Time = 2.918880 Seconds Exclusive Times %Time ExclSec CumulS #Calls sec/call Csec/c Name 75.3 2.200 2.238 1730 0.0013 0.0013 Win32::OLE::Dispatch 10.1 0.295 0.419 2 0.1474 0.2094 Win32::OLE::Const::_Typelibs 4.25 0.124 0.124 744 0.0002 0.0002 Win32::OLE::Const::_Typelib 2.19 0.064 0.590 39 0.0016 0.0151 STRIDE::Test::BEGIN 1.61 0.047 0.047 5 0.0094 0.0094 Devel::Symdump::_symdump 1.30 0.038 0.035 2536 0.0000 0.0000 Win32::OLE::Tie::FETCH 0.55 0.016 0.016 1 0.0160 0.0159 ActivePerl::Config::override 0.55 0.016 0.016 3 0.0053 0.0053 DynaLoader::BEGIN 0.55 0.016 0.016 5 0.0032 0.0032 Pod::POM::View::HTML::BEGIN 0.55 0.016 0.016 7 0.0023 0.0023 IO::Handle::BEGIN 0.55 0.016 0.636 4 0.0040 0.1589 main::BEGIN 0.55 0.016 0.015 8 0.0020 0.0019 Pod::POM::BEGIN 0.55 0.016 0.027 30 0.0005 0.0009 STRIDE::Test::AddAnnotation 0.55 0.016 0.016 42 0.0004 0.0004 Pod::POM::Node::new 0.51 0.015 0.015 414 0.0000 0.0000 Pod::POM::Node::AUTOLOAD So, clearly it's showing the discrepancy in total time, but nothing stands out as far as the code that is profiled by dprof. Any advice about other things I should try? Thanks, Mike Ellery _______________________________________________ Perl-Win32-Users mailing list [email protected] To unsubscribe: http://listserv.ActiveState.com/mailman/mysubs
