http://coldfusion.com logo
Join Slack
Powered by
Can't seem to get to the `Extension/Applications` ...
# lucee
l
Can't seem to get to the 
Extension/Applications
page in the server admin in any SNAP after 5.3.9.83 - is it just me? Filed: https://luceeserver.atlassian.net/browse/LDEV-3890
b
I'm on 
5.3.9.88-SNAPSHOT
The page took 6.9 seconds to load
It made 16 HTTP calls per fusion reactor
l
Just downgraded to 83 and loads fine. Then upgraded again to 88 and times out again. Tried each SNAP in between too.
b
What does FusionReactor say the request is doing?
l
also did a 
server forget
multiple times, trying fresh install with 88 or install 83 and upgrade via admin... each way, same thing
do not have FR :-(
b
Then it's just a black box, I'm afraid šŸ™‚
You can get a thread dump with 
jstack
if you have a JDK
The profiler feature of FR shows me 90% of the request time is just downloading all these stupid thumbnails for each remote extension
LUcee does a HEAD and a GET for each thumbnail
yuck
This is super sweet-- FR now shows you totals for not only DB calls but API calls (HTTP)
message has been deleted
Refreshing the page again took 4.5 seconds and I can see right off in FR that 2.2 seconds of that are HTTP calls
Here's the profiler for the page in FR
message has been deleted
l
but the error seems to be coming from the lar file isn't it?
Copy code
request /lucee/admin/server.cfm (<zip://C>:\Users\User\.CommandBox\server\11380ECFE99F9C8B2813348F3BC40E05-MySite\lucee-5.3.9-SNAPSHOT.88\WEB-INF\lucee-web\context\lucee-admin.lar!/server.cfm) has run into a timeout (timeout: 30 seconds) and has been stopped. The thread started 36140ms ago
b
2 seconds reading binary images, half a second getting image bytes, and 1.5 seconds doing some sort of async array iteration (waiting to join back to the threads)
but the error seems to be coming from the lar file isn't it?
no, not really, but the lar is irrelevant anyway
The "error" is coming from the CF engine because the request timed out
The fact that the admin pages are in a lar is more of an implementation detail
FR will tell you exactly what it's doing in a couple seconds. I'd bet a dollar it's related to the thumbnail downloads or contacting the update providers
l
ok, right... I'm just saying (perhaps erroneously) that the error presented appears to suggest it's having trouble reading that zip file, no?
b
Lucee REALLY needs to stop downloading those stupid thumbnails and just push the link out to the browser to load. cc/ @zackster @mitrahsoft_muthu
it's having trouble reading that zip file, no?
No. The path to the CFM file is just inside the lar. That's all
Copy code
<zip://C>:/path/to/archive.zip!/path/inside/archive.txt
is just the generic way you can access a file inside a zip. Lucee's just showing you where the file lives
If you're not buying the FR developer license right now šŸ™‚ you should at least be downloading a JDK
Just ask CommandBox to get one for you
Copy code
java install openjdk11_jdk
Then go find the 
bin/jstack
binary on your hard drive under 
~/.CommandBox/serverJREs
Then run
Copy code
C:/path/to/openjdk/bin/jstack.exe -l <PID>
while the page is loading to get a stack trace
It's like a poor man's FR šŸ™‚
l
I do have jdk installed
b
There you go
Lucee pre-downloads all those thumbnails first while the page is loading, then embeds them in the source like
Copy code
data:image/png;base64,XXXXXX
it's really just terrible for performance
It does it every freaking page load too šŸ¤®
All it needs to do is just freaking point your browser to
Copy code
<https://raw.githubusercontent.com/cfsimplicity/lucee-mariadb/master/extension/META-INF/logo.png>
etc, so your browser can load it after the page is up and cache it
At least Lucee caches the actual list of extensions
ForgeBox's call is https://www.forgebox.io/rest/extension/provider/info and takes about 219 ms
Lucee's update provider call is https://extension.lucee.org/rest/extension/provider/info and takes about a second.
Gah-- it's got the freaking thumbnails embedded in the JSON response as binary. WHY??
That makes me so sad-- forgebox's info call does not do that. Probably a huge part of why it's so much faster!
l
well, I have that stack, but it's all Greek to me! What am I looking for?
b
Post it here in a snippet
Also, keep in mind the request may be doing several slow things, so you may have just caught one of them depending on when you took the stack
l
980 lines... that ok?
b
That's where FusionReactor's profiler is killer. It takes a bunch of stacks and then combines them all into one. It's amazing
yeah, just put it in a snippet here in slack
There's no max file size in snippets
l
there you go
b
Copy code
java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(java.base@11.0.13/Native Method)
        at java.net.SocketInputStream.socketRead(java.base@11.0.13/SocketInputStream.java:115)
        at java.net.SocketInputStream.read(java.base@11.0.13/SocketInputStream.java:168)
        at java.net.SocketInputStream.read(java.base@11.0.13/SocketInputStream.java:140)
        at java.io.BufferedInputStream.fill(java.base@11.0.13/BufferedInputStream.java:252)
        at java.io.BufferedInputStream.read1(java.base@11.0.13/BufferedInputStream.java:292)
        at java.io.BufferedInputStream.read(java.base@11.0.13/BufferedInputStream.java:351)
        - locked <0x00000000cafe1750> (a java.io.BufferedInputStream)
        at sun.net.www.http.HttpClient.parseHTTPHeader(java.base@11.0.13/HttpClient.java:754)
        at sun.net.www.http.HttpClient.parseHTTP(java.base@11.0.13/HttpClient.java:689)
        at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(java.base@11.0.13/HttpURLConnection.java:1615)
        - locked <0x00000000cafd70a0> (a sun.net.www.protocol.http.HttpURLConnection)
        at sun.net.www.protocol.http.HttpURLConnection.getInputStream(java.base@11.0.13/HttpURLConnection.java:1520)
        - locked <0x00000000cafd70a0> (a sun.net.www.protocol.http.HttpURLConnection)
        at java.net.HttpURLConnection.getResponseCode(java.base@11.0.13/HttpURLConnection.java:527)
        at lucee.loader.engine.CFMLEngineFactory.downloadBundle(CFMLEngineFactory.java:709)
        at lucee.runtime.osgi.OSGiUtil._loadBundle(OSGiUtil.java:555)
        at lucee.runtime.osgi.OSGiUtil.loadBundle(OSGiUtil.java:492)
        at lucee.commons.lang.ClassUtil.loadClassByBundle(ClassUtil.java:155)
        at lucee.commons.lang.ClassUtil.loadClassByBundle(ClassUtil.java:149)
        at lucee.runtime.functions.FunctionHandlerPool.use(FunctionHandlerPool.java:59)
        at lucee.runtime.functions.FunctionHandlerPool.invoke(FunctionHandlerPool.java:40)
        at ext_functions_cfm184$cf.udfCall3(/admin/ext.functions.cfm:204)
It's downloading stuff, but it actually appears to be downloading OSGI bundles, not thumbnails
Cranking your deploy log to "trace" will probably tell you more
That line in the CFML source of the admin is
Copy code
<cfset local.img=imageRead(data)>
So it is related to the image downloading somehow
I'd be interested to know if the thread is JUST doing that until it times out, or if it's doing a lot of other slow stuff, or perhaps doing this over and over for each thumbnail
I don't know what bundle it's downloading, but ā€¢ I assume it's part of the image extension ā€¢ I'm not sure why it's downloading at all since extensions should have all their bundles baked in. cc/ @zackster
l
dumb question, but: if that's the case, why is it instantaneous on SNAP-83 with same extensions preloaded and timing out on SNAPs after 83? Wouldn't they be trying to do the same thing from this same machine?
b
I have Google Fiber gigabit internet so if it's doing something odd and downloading OSGI jars over and over I may not notice it since my internet is so fast
l
I'm also on gigabit fiber
šŸ’Æ 1
so connection isn;t the problem on this end
b
Wouldn't they be trying to do the same thing from this same machine?
no freaking clue. I assume the extension version may be different between releases. just a guess
Did you crank up your deploy log like I suggested.
I think that logs all bundle downloads
If not, it would be in the application log
message has been deleted
by default you can see they're not logging much
Also, while the page is loading, pull like 5 or 6 thread dumps and see if the thread is doing the same thing every time
Like i said, just because you caught it doing that one thing at that one time doesn't mean it's the slowest part of the page, even though statistically speaking, you are more likely to catch whatever the slowest thing is
l
yeah, changed to TRACE
ok, narrowed it down to the Image extension. I have this in 
.env
file: 
LUCEE_EXTENSIONS=B737ABC4-D43F-4D91-8E8E973E37C40D1B;name=Image extension;version=1.1.0.6-SNAPSHOT
(among other extensions) Removing that extension from 
.env
fixes issue or setting that extension to anything pre 1.1.x.x works. Not sure why the same 
.env
and extension works in SNAP-83 and below, but something new in 1.1.x.x messes with Lucee SNAPs beyond 83...
2 Views
Open in Slack
PreviousNext
Powered by