Item9267: configure is way too slow my windows with strawberry perl (`id -un` takes 31s)!

When you run configure on windows, it's very very slow, and all images takes like 2 minutes to come. Trying to shortcut some module loading when rendering resources...

-- OlivierRaginel - 06 Jul 2010

What version of perl are you running? I've managed to get a NYTProf run using Strawberry 5.12 - I don't see anything jump out as being an obvious bottleneck. I've run a wireshark trace and I see a number of pauses in output, but they are prior to the final TCP FIN, and look similar on Linux. But I do agree, windows is very slow. - Firebug / YSlow are reporting times to load the graphics as long as 13+ seconds. On linux it's sub-second. But serving the files from the pub directory, the times are nearly identical. So it's something in configure action=resource

-- GeorgeClark - 07 Jul 2010

For one thing - when bin/configure runs, even when asked just to serve a resource string, it goes through loading of all the configure modules. It took almost 1/2 second to load up 23 modules - many of which are probably not needed for action=resource.

I've changed configure to save a reference to _loadBasicModule, and was able to avoid all of the Foswiki:: loading except for the TemplateParser when handling a resource. This should help but I want to test a bit more before checking it in. This can't accounts for seconds of delay, but it will certainly knock some time off of the image handling.

-- GeorgeClark - 07 Jul 2010

I'm using strawberry 5.10.0 and NYTProf fails because it depends on JSON::Any, which needs JSON::DWIW, which fails.

• For the record, it fails, but as it's not a required depency, it works just fine with -f(orce) -- OlivierRaginel - 28 Jul 2010

Anyway, here are my logs to give you an idea of the timeframe. It's a clean trunk checkout, prior to George patch. I did kind of the same patch myself and didn't bother committing, because it didn't change much / anything:

127.0.0.1 - admin [06/Jul/2010:13:38:07 +0200] "GET /foswiki/bin/configure HTTP/1.1" 200 415648
127.0.0.1 - admin [06/Jul/2010:13:38:56 +0200] "GET /foswiki/bin/configure?action=resource;resource=logo.gif HTTP/1.1" 200 1585
127.0.0.1 - admin [06/Jul/2010:13:38:56 +0200] "GET /foswiki/bin/configure?action=resource;resource=icon_info.gif HTTP/1.1" 200 203
127.0.0.1 - admin [06/Jul/2010:13:39:27 +0200] "GET /foswiki/bin/configure?action=resource;resource=icon_warn_white.gif HTTP/1.1" 200 212
127.0.0.1 - admin [06/Jul/2010:13:40:27 +0200] "GET /foswiki/bin/configure?action=resource;resource=icon_up.gif HTTP/1.1" 200 64
127.0.0.1 - admin [06/Jul/2010:13:39:57 +0200] "GET /foswiki/bin/configure?action=resource;resource=bg_submit_gradient.gif HTTP/1.1" 200 1533
127.0.0.1 - admin [06/Jul/2010:13:41:27 +0200] "GET /foswiki/bin/configure?action=resource;resource=icon_down.gif HTTP/1.1" 200 64
127.0.0.1 - admin [06/Jul/2010:13:41:42 +0200] "GET /foswiki/bin/configure?action=resource;resource=icon_error_white.gif HTTP/1.1" 200 215
127.0.0.1 - admin [06/Jul/2010:13:42:12 +0200] "GET /foswiki/bin/configure?action=resource;resource=icon_warn_blue.gif HTTP/1.1" 200 212
127.0.0.1 - admin [06/Jul/2010:13:42:42 +0200] "GET /foswiki/bin/configure?action=resource;resource=bg_button_gradient.gif HTTP/1.1" 200 1490

-- OlivierRaginel - 07 Jul 2010

FWIW I just ran it on my laptop, standard crappy 1.5GHz machine, running Apache 2.2 and AS Perl 5.10.1 from IE7, and it was fine. Not exactly quick, but not noticeably slow either.

-- CrawfordCurrie - 09 Jul 2010

On my virtualbox test system, I get this:

127.0.0.1 - admin [27/Jul/2010:19:26:34 +0200] "GET /foswiki/bin/configure HTTP/1.1" 200 416695
127.0.0.1 - admin [27/Jul/2010:19:27:17 +0200] "GET /foswiki/bin/configure?action=resource;resource=favicon.ico HTTP/1.1" 200 1150
127.0.0.1 - admin [27/Jul/2010:19:27:49 +0200] "GET /foswiki/bin/configure?action=resource;resource=favicon.ico HTTP/1.1" 200 1150
127.0.0.1 - admin [27/Jul/2010:19:27:17 +0200] "GET /foswiki/bin/configure?action=resource;resource=logo.gif HTTP/1.1" 200 1585
127.0.0.1 - admin [27/Jul/2010:19:27:17 +0200] "GET /foswiki/bin/configure?action=resource;resource=icon_warn_white.gif HTTP/1.1" 200 212
127.0.0.1 - admin [27/Jul/2010:19:27:18 +0200] "GET /foswiki/bin/configure?action=resource;resource=icon_info.gif HTTP/1.1" 200 203
127.0.0.1 - admin [27/Jul/2010:19:27:19 +0200] "GET /foswiki/bin/configure?action=resource;resource=icon_error_white.gif HTTP/1.1" 200 215
127.0.0.1 - admin [27/Jul/2010:19:27:18 +0200] "GET /foswiki/bin/configure?action=resource;resource=bg_submit_gradient.gif HTTP/1.1" 200 1533
127.0.0.1 - admin [27/Jul/2010:19:29:19 +0200] "GET /foswiki/bin/configure?action=resource;resource=favicon.ico HTTP/1.1" 200 1150

So overall a bit under 3 minutes to render the page, with images.

-- OlivierRaginel - 27 Jul 2010

Ok, found out that forking id -un is slow. Don't really know why, because forking something else looks OK. Anyway, moved that away so that it's not done when serving resources, and cleaned up the code, like perltidy, put it back in unix mode and not dos, etc...

Downgrading that one, as it is still slow, but it's usable. 32s is long, but there is nothing much we can do apart from removing the username / groups Apache runs under under Strawberry.

-- OlivierRaginel - 27 Jul 2010

Babar, the id -un command is part of cygwin according to the comments. I don't have cygwin installed and I don't see the delay. For a test I pulled out just the few lines of code that pulls the uid and gid, I get the uid, the gid returns an error that getgrgid function is unimplemented. And the code that tries id -un does nothing because the id, and sh commands are not available.

Does it make sense to try to use the cygwin id command under strawberry perl? My system seems to run fine without the gid, so what value does it add to run the cygwin id command. My grep skills might be challenged, but from what I could find, the gid is only referenced in CGISsetup - for reporting as part of the environment.

-- GeorgeClark - 28 Jul 2010

Yes, I was wondering about that, and thought that, as it works, and as it's written in the command, some part of cygwin ought to be installed for some other things to work.

What I'm more worried about is that this slowness seems to occur with some forks, and therefore on windows, if we use anything that forks, it might be awfully slow.

But also, as you point out, it seems my system is the only one experiencing this delay, so, I just took this opportunity to optimise a bit configure, which doesn't harm.

I'll keep this bug opened just in case I find something more, but I've downgraded it and I will change the title, as CDot never experienced such delays under ActiveState.

-- OlivierRaginel - 28 Jul 2010

Closing this as the fixes have been long since released. If it's still a problem it should probably be a new task.

-- GeorgeClark - 09 Mar 2011

Commenting is disabled while not logged in