slow startup time #45

alanhamlett · 2015-07-26T18:12:45Z

Some users are experiencing slow IDE startup times (up to 4 minutes) with the WakaTime plugin installed. Possible causes are:

downloading Python because it's not detected on the system
downloading or upgrading wakatime cli
other unknown issue

N-Molham · 2015-07-26T18:18:42Z

when the plugin is installed when ever I type something in the PHPStorm editor and press Ctrl+Z or Ctrl+S the application goes our of blur ( Like and focused on other application ) for 2 : 3 seconds and returns back !!!!! you said on slack that you release new update but I still give version 4.0.12.

That besides downloading wakatime cli every time you start the IDE

I tried both debug modes true and false with same result.

alanhamlett · 2015-07-26T18:38:53Z

@N-Molham did you restart PHPStorm after setting debug to false? It only checks debug from ~/.wakatime.cfg when the IDE first starts.

N-Molham · 2015-07-26T18:58:03Z

Sure I did 😄

N-Molham · 2015-07-29T12:50:20Z

@alanhamlett Any update ?

alanhamlett · 2015-07-29T19:20:07Z

I've tried reproducing it on my Windows 8.1 VM but haven't been able to yet. Could you help narrow down the section of code that's taking the most time during startup?

N-Molham · 2015-07-30T00:16:45Z

This is a screen record of what is happening => https://drive.google.com/file/d/0B2pwLeWWR6mHc1dOSDhZS3JMSFU/view?usp=sharing

alanhamlett · 2015-07-30T04:07:28Z

In debug mode, can you check if the plugin is executing pythonw.exe or python.exe from your idea.log file? pythonw.exe should run without a cmd window and shouldn't steal focus from the IDE like that, but there are a lot of quirks around Windows in general...

N-Molham · 2015-07-31T12:28:56Z

But It was working fine before !!!!
The log when debug is true:

2015-07-09 14:11:30,467 [   1037]   INFO - llij.ide.plugins.PluginManager - Loaded custom plugins: WakaTime (4.0.12) 
2015-07-09 14:11:32,196 [   2766]   INFO -                       WakaTime - Initializing WakaTime plugin v4.0.12 (https://wakatime.com/) 
2015-07-09 14:11:32,196 [   2766]  DEBUG -                       WakaTime - Logging level set to DEBUG 
2015-07-09 14:11:32,196 [   2766]  DEBUG -                       WakaTime - Python location: \python33\pythonw 
2015-07-09 14:11:32,196 [   2766]  DEBUG -                       WakaTime - CLI location: *******/.WebIde80/config/plugins/WakaTime-resources\wakatime-master\wakatime\cli.py 
2015-07-09 14:11:32,571 [   3141]  DEBUG -                       WakaTime - Api Key: *******-*******-*******-*******-******* 
2015-07-09 14:11:32,571 [   3141]   INFO -                       WakaTime - Finished initializing WakaTime plugin 
2015-07-09 14:11:33,602 [   4172]   INFO -                       WakaTime - Upgrading wakatime-cli ... 
2015-07-09 14:11:46,772 [  17342]   INFO -                       WakaTime - Finished upgrading wakatime-cli.

alanhamlett · 2015-07-31T21:49:17Z

Version 4.0.13 is less strict about the wakatime cli version matching exactly, and just checks if the output contains the correct version in the string somewhere. Maybe some whitespace was causing the version to not match exactly. This might help with the slow startup time.

As for the pythonw.exe window stealing focus from your IDE, I'm not sure how to fix that at the moment.

N-Molham · 2015-07-31T22:21:40Z

Both problem still there after installing plugin version 4.0.13 !!!

alanhamlett · 2015-08-01T00:48:11Z

Can you clone this repo and debug inside IntelliJ? I've added some better debug logging with ae03d9a that will show why the plugin thinks wakatime cli is always out of date.

alanhamlett · 2015-08-01T00:51:29Z

@N-Molham just released v4.0.14 with the debug lines, so you can just upgrade instead of cloning the repo.

N-Molham · 2015-08-03T12:02:22Z

Same both problems with v4.0.15 :(

alanhamlett · 2015-08-03T20:10:58Z

Can you show the new debug messages from your idea.log file with this new plugin version? It should help me find why it's downloading wakatime cli every time you start the IDE.

N-Molham · 2015-08-03T22:19:34Z

2015-08-04 01:11:28,979 [   3264]   INFO - WakaTime - Initializing WakaTime plugin v4.0.15 (https://wakatime.com/) 
2015-08-04 01:11:28,995 [   3280]  DEBUG - WakaTime - Logging level set to DEBUG 
2015-08-04 01:11:28,995 [   3280]  DEBUG - WakaTime - Python location: \python33\pythonw 
2015-08-04 01:11:28,995 [   3280]  DEBUG - WakaTime - CLI location: C:/Users/Nabeel/.WebIde80/config/plugins/WakaTime-resources\wakatime-master\wakatime\cli.py 
2015-08-04 01:11:28,995 [   3280]  DEBUG - WakaTime - *** STDOUT *** 
2015-08-04 01:11:28,995 [   3280]  DEBUG - WakaTime -  
2015-08-04 01:11:28,995 [   3280]  DEBUG - WakaTime - *** STDERR *** 
2015-08-04 01:11:28,995 [   3280]  DEBUG - WakaTime -  
2015-08-04 01:11:28,995 [   3280]   INFO - WakaTime - Upgrading wakatime-cli ... 
2015-08-04 01:11:29,401 [   3686]  DEBUG - WakaTime - Api Key: xxxxxx-xxxxxx-xxxxxx-xxxxxx-xxxxxx 
2015-08-04 01:11:29,401 [   3686]   INFO - WakaTime - Finished initializing WakaTime plugin 
2015-08-04 01:16:35,971 [ 310256]   INFO - WakaTime - Finished upgrading wakatime-cli.

alanhamlett · 2015-08-03T23:58:14Z

Just released v4.0.17 of the plugin, can you try it?

I think we were reading the output from wakatime cli before the process had finished executing, so we missed the version number. Now we wait for wakatime cli to finish executing.

alanhamlett · 2015-08-04T00:43:18Z

v4.0.18 also fixes a bug where the thread running wakatime cli would block the UI thread.

N-Molham · 2015-08-04T12:58:19Z

The focus steal problem is gone now but the slow loading time still there
When debug = false

2015-08-04 15:48:36,499 [   1078]   INFO - llij.ide.plugins.PluginManager - Loaded custom plugins: .ignore (1.1.4), NodeJS (139.491), WakaTime (4.0.18) 
2015-08-04 15:48:38,519 [   3098]   INFO -                       WakaTime - Initializing WakaTime plugin v4.0.18 (https://wakatime.com/) 
2015-08-04 15:48:38,566 [   3145]   INFO -                       WakaTime - Upgrading wakatime-cli ... 
2015-08-04 15:48:38,961 [   3540]   INFO -                       WakaTime - Finished initializing WakaTime plugin 
2015-08-04 15:48:54,528 [  19107]   INFO -                       WakaTime - Finished upgrading wakatime-cli.

And when debug = true

2015-08-04 15:54:31,009 [   1078]   INFO - llij.ide.plugins.PluginManager - Loaded custom plugins: .ignore (1.1.4), NodeJS (139.491), WakaTime (4.0.18) 
2015-08-04 15:54:33,060 [   3129]   INFO -                       WakaTime - Initializing WakaTime plugin v4.0.18 (https://wakatime.com/) 
2015-08-04 15:54:33,075 [   3144]  DEBUG -                       WakaTime - Logging level set to DEBUG 
2015-08-04 15:54:33,075 [   3144]  DEBUG -                       WakaTime - Python location: \python33\pythonw 
2015-08-04 15:54:33,075 [   3144]  DEBUG -                       WakaTime - CLI location: C:\Users\Nabeel\.WebIde80\config\plugins\WakaTime-resources\wakatime-master\wakatime\cli.py 
2015-08-04 15:54:33,111 [   3180]  DEBUG -                       WakaTime - wakatime cli version check output: "" 
2015-08-04 15:54:33,111 [   3180]  DEBUG -                       WakaTime - wakatime cli version check exit code: -1073741515 
2015-08-04 15:54:33,111 [   3180]   INFO -                       WakaTime - Upgrading wakatime-cli ... 
2015-08-04 15:54:33,431 [   3500]  DEBUG -                       WakaTime - Api Key: ********-****-****-****-********695d 
2015-08-04 15:54:34,493 [   4562]   INFO -                       WakaTime - Finished initializing WakaTime plugin 
2015-08-04 15:54:47,376 [  17445]   INFO -                       WakaTime - Finished upgrading wakatime-cli.

alanhamlett · 2015-08-04T21:01:06Z

What happens when you run this in a cmd prompt?

\python33\python C:\Users\Nabeel\.WebIde80\config\plugins\WakaTime-resources\wakatime-master\wakatime\cli.py --version

That's the exact command being run which is exiting with -1073741515, except WakaTime uses pythonw (which won't work in a cmd prompt). Just curious if it prints any error to the cmd prompt when run manually.

Sorry I keep having to ask you for debugging help, but I'm not able to reproduce this :(

This is my output on Windows 8.1 with debug true:

2015-08-04 13:53:30,630 [  13264]   INFO -                       WakaTime - Initializing WakaTime plugin v4.0.18 (https://wakatime.com/) 
2015-08-04 13:53:30,646 [  13280]  DEBUG -                       WakaTime - Logging level set to DEBUG 
2015-08-04 13:53:30,646 [  13280]  DEBUG -                       WakaTime - Python location: \python34\pythonw 
2015-08-04 13:53:30,646 [  13280]  DEBUG -                       WakaTime - CLI location: C:\Users\IEUser\.WebIde90\config\plugins\WakaTime-resources\wakatime-master\wakatime\cli.py 
2015-08-04 13:53:32,333 [  14967]  DEBUG -                       WakaTime - Api Key: ********-****-****-****-********f9c4 
2015-08-04 13:53:34,208 [  16842]  DEBUG -                       WakaTime - wakatime cli version check output: "4.1.0" 
2015-08-04 13:53:34,208 [  16842]  DEBUG -                       WakaTime - wakatime cli version check exit code: 0 
2015-08-04 13:53:34,208 [  16842]   INFO -                       WakaTime - wakatime-cli is up to date. 
2015-08-04 13:54:08,816 [  51450]   INFO -                       WakaTime - Finished initializing WakaTime plugin

N-Molham · 2015-08-04T22:32:49Z

Yep I found the problem ... when I am trying to run python or pythonw ti gave me an error message saying some dll file is missing ... when I reinstalled python again it worked fine now.

I only imagine how feel like now :( I made you look around and around many times.

I think to be in the safe side is to check it the command executed without any errors or not first.

alanhamlett · 2015-08-04T22:48:58Z

It's no problem at all! We actually fixed a lot of bugs and improved the debug output for everyone. Glad it's working now!

N-Molham · 2015-08-30T13:27:49Z

The problem returned again after upgrading PHPStorm to 9.0.2 and Wakatime plugin to 4.0.19

Debug Log

2015-08-30 16:24:30,130 [   2188]   INFO - llij.ide.plugins.PluginManager - Loaded custom plugins: .ignore (1.2), LiveEdit (2.0.15.141.1), NodeJS (141.1509), PhoneGap/Cordova Plugin (141.1010), WakaTime (4.0.19) 
2015-08-30 16:24:32,819 [   4877]   INFO -                       WakaTime - Initializing WakaTime plugin v4.0.19 (https://wakatime.com/) 
2015-08-30 16:24:32,819 [   4877]  DEBUG -                       WakaTime - Logging level set to DEBUG 
2015-08-30 16:24:32,819 [   4877]  DEBUG -                       WakaTime - Python location: pythonw 
2015-08-30 16:24:32,819 [   4877]  DEBUG -                       WakaTime - CLI location: C:\Users\Nabeel\.WebIde90\config\plugins\WakaTime-resources\wakatime-master\wakatime\cli.py 
2015-08-30 16:24:33,210 [   5268]   INFO - ellij.project.impl.ProjectImpl - 20 project components initialized in 375 ms 
2015-08-30 16:24:33,210 [   5268]   INFO - le.impl.ModuleManagerComponent - 0 module(s) loaded in 0 ms 
2015-08-30 16:24:33,272 [   5330]  DEBUG -                       WakaTime - Api Key: ********-****-****-****-********695d 
2015-08-30 16:24:33,819 [   5877]  DEBUG -                       WakaTime - wakatime cli version check output: "4.1.4" 
2015-08-30 16:24:33,819 [   5877]  DEBUG -                       WakaTime - wakatime cli version check exit code: 0 
2015-08-30 16:24:33,819 [   5877]   INFO -                       WakaTime - Upgrading wakatime-cli ... 
2015-08-30 16:24:36,878 [   8936]   INFO -                       WakaTime - Finished initializing WakaTime plugin 
2015-08-30 16:24:36,941 [   8999]   INFO - pl.stores.ApplicationStoreImpl - 79 application components initialized in 6733 ms 
2015-08-30 16:24:37,066 [   9124]   INFO - .intellij.idea.IdeaApplication - App initialization took 9752 ms 
2015-08-30 16:25:49,836 [  81894]   INFO -                       WakaTime - Finished upgrading wakatime-cli.

and the output of running this command line you sent before
python C:\Users\Nabeel\.WebIde90\config\plugins\WakaTime-resources\wakatime-master\wakatime\cli.py --version => 4.1.4

It's everytime downloading the cli package despite it's version is 4.1.4 which is the latest!

I think I found the problem:
on file cli.py line 17 => package_folder = os.path.dirname(os.path.dirname(os.path.abspath(__file__)))
which returns C:\Users\Nabeel\.WebIde90\config\plugins\WakaTime-resources\wakatime-master
and that folder which added to the system path ... is that right ? or it should be package_folder = os.path.dirname(os.path.abspath(__file__)) to return C:\Users\Nabeel\.WebIde90\config\plugins\WakaTime-resources\wakatime-master\wakatime

alanhamlett · 2015-08-30T19:32:28Z

Fixed with v4.0.20, just released. The latest wakatime cli version is hard-coded, but later today I'll have it check GitHub for the current cli version.

The current release just updates the hard-coded wakatime cli version and also downloads wakatime cli in a non-blocking background thread.

N-Molham · 2015-09-01T12:26:31Z

Thanks @alanhamlett nice work 👍

alanhamlett closed this as completed Aug 4, 2015

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

slow startup time #45

slow startup time #45

alanhamlett commented Jul 26, 2015

N-Molham commented Jul 26, 2015

alanhamlett commented Jul 26, 2015

N-Molham commented Jul 26, 2015

N-Molham commented Jul 29, 2015

alanhamlett commented Jul 29, 2015

N-Molham commented Jul 30, 2015

alanhamlett commented Jul 30, 2015

N-Molham commented Jul 31, 2015

alanhamlett commented Jul 31, 2015

N-Molham commented Jul 31, 2015

alanhamlett commented Aug 1, 2015

alanhamlett commented Aug 1, 2015

N-Molham commented Aug 3, 2015

alanhamlett commented Aug 3, 2015

N-Molham commented Aug 3, 2015

alanhamlett commented Aug 3, 2015

alanhamlett commented Aug 4, 2015

N-Molham commented Aug 4, 2015

alanhamlett commented Aug 4, 2015

N-Molham commented Aug 4, 2015

alanhamlett commented Aug 4, 2015

N-Molham commented Aug 30, 2015

alanhamlett commented Aug 30, 2015

N-Molham commented Sep 1, 2015

slow startup time #45

slow startup time #45

Comments

alanhamlett commented Jul 26, 2015

N-Molham commented Jul 26, 2015

alanhamlett commented Jul 26, 2015

N-Molham commented Jul 26, 2015

N-Molham commented Jul 29, 2015

alanhamlett commented Jul 29, 2015

N-Molham commented Jul 30, 2015

alanhamlett commented Jul 30, 2015

N-Molham commented Jul 31, 2015

alanhamlett commented Jul 31, 2015

N-Molham commented Jul 31, 2015

alanhamlett commented Aug 1, 2015

alanhamlett commented Aug 1, 2015

N-Molham commented Aug 3, 2015

alanhamlett commented Aug 3, 2015

N-Molham commented Aug 3, 2015

alanhamlett commented Aug 3, 2015

alanhamlett commented Aug 4, 2015

N-Molham commented Aug 4, 2015

alanhamlett commented Aug 4, 2015

N-Molham commented Aug 4, 2015

alanhamlett commented Aug 4, 2015

N-Molham commented Aug 30, 2015

alanhamlett commented Aug 30, 2015

N-Molham commented Sep 1, 2015