Lucee returns blank pages

I don’t see any issues at all with your memory-- not in those graphs at least. Memory being “high” as in the sawtooth approaching the top but then goes back down is perfectly normal. It would have to be smashed at the top with no room to be concerning. Plus, all your memory spaces (like non-heap) aren’t even visible in that screenshot.

To be honest, I’m not sure that there’s a correlation between sometimes getting a “white page” and the fact that some JDBC calls sometimes hang. And the on session end error you’ve talked about but not shared any details of is entirely possible to be a totally unrelated third issue. It’s also not actually clear which specific one of the 3 issues above coincided with your screenshots you posted.

1 Like

Probably not related, but in the application.log, I see a lot of this line, like every minutes :

“INFO”,“Thread-95805”,“12/01/2021”,“15:32:35”,“lucee.runtime.PageSourcePool”,“PagePool size [1747] has exceeded max size [1000]. Clearing unused…”
“INFO”,“Thread-95805”,“12/01/2021”,“15:32:35”,“lucee.runtime.PageSourcePool”,“New pagePool size [1747].”

I found this topic : https://lucee.daemonite.io/t/pagepool-1191-1000/5562

I continue to look at the logs.

Interesting. I found 9 errors like that this morning, before the incident, related to the application.cfc and my cfc in the OnSessionEnd :

“ERROR”,“Thread-1547582”,“12/01/2021”,“04:58:28”,“”,"key [CFID] doesn’t exist;key [CFID] doesn’t exist;lucee.runtime.exp.ExpressionException: key [CFID] doesn’t exist
at lucee.runtime.type.util.StructSupport.invalidKey(StructSupport.java:67)
at lucee.runtime.type.StructImpl.get(StructImpl.java:139)
at lucee.runtime.type.scope.storage.StorageScopeImpl.get(StorageScopeImpl.java:255)
at lucee.runtime.util.VariableUtilImpl.get(VariableUtilImpl.java:278)
at lucee.runtime.PageContextImpl.get(PageContextImpl.java:1539)
at application_cfc$cf.udfCall(/application.cfc:338)
at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:106)
at lucee.runtime.type.UDFImpl._call(UDFImpl.java:344)
at lucee.runtime.type.UDFImpl.call(UDFImpl.java:217)
at lucee.runtime.ComponentImpl._call(ComponentImpl.java:684)
at lucee.runtime.ComponentImpl._call(ComponentImpl.java:572)
at lucee.runtime.ComponentImpl.call(ComponentImpl.java:1911)
at lucee.runtime.listener.ModernAppListener.call(ModernAppListener.java:437)
at lucee.runtime.listener.ModernAppListener.onSessionEnd(ModernAppListener.java:362)
at lucee.runtime.type.scope.ScopeContext.clearUnusedMemoryScope(ScopeContext.java:961)
at lucee.runtime.type.scope.ScopeContext.clearUnused(ScopeContext.java:825)
at lucee.runtime.engine.Controler.control(Controler.java:346)
at lucee.runtime.engine.Controler.control(Controler.java:244)
at lucee.runtime.engine.Controler.access$000(Controler.java:58)
at lucee.runtime.engine.Controler$ControlerThread.run(Controler.java:113)
"

My code is similar to this :

<cffunction
    name="OnSessionEnd"
    access="public"
    returntype="void"
    output="false"
    hint="Fires when the session is terminated.">
 
    <!--- Define arguments. --->
    <cfargument
        name="SessionScope"
        type="struct"
        required="true"
        />

    <cfargument
        name="ApplicationScope"
        type="struct"
        required="false"
        default="#StructNew()#"
        />
            
    <cfset var myDatabases = "">
            
    <cfinvoke component="cfc.myproject.client.databases" method="getMyDatabases" returnvariable="myDatabases">
        
        <cfloop query="myDatabases">
        
                <cfinvoke component="cfc.myproject.client.transactions-paiements" method="ope_clean_data" datasource="#myDatabases.Datasource#"
                cfid="#ARGUMENTS.SessionScope.CFID#"
            	cftoken="#ARGUMENTS.SessionScope.CFTOKEN#">
        
        </cfloop>
        
		<!--- Return out. --->
		<cfreturn />
        
	</cffunction>

And I found this error too :

“ERROR”,“Thread-1559271”,“12/01/2021”,“04:57:31”,“controller”,"stop request (35) because run into a timeout. ATM we have 4 active request(s) and 0 active cfthreads path: T:\inetpub\wwwroot\myProject\application.cfc (T:\customtags\cfc\myProject\client\transactions-paiements.cfc).;java.lang.Throwable;java.lang.Throwable

I would check for the existence of the CFID before assuming it’s there and using it. But I think you’re off in the weeds with that. There’s no indication that’s related to any of the other issues above. Probably just a bug that’s always been there.

The “stop requests” message is simply telling you that Lucee tried to stop a long-running request.

You are right.

When you say to check my servlet’s “out” logs, is it a file with a specific name? Right now I look in :

  • C:\lucee\tomcat\logs
  • T:\inetpub\wwwroot\myProject\WEB-INF\lucee\logs

I continue my research with the leads you gave me. Thank you so much.

Probably unrelated either, but like I’m taking time to find different errors, I might as well correct them at the same time.I found endless errors like this in the lucee-stderr.log and catalina.log :

javax.mail.Session.loadResource expected resource not found: /META-INF/javamail.default.address.map

Mentionned in this topic : https://lucee.daemonite.io/t/recurring-log-error-with-possible-thread-issues/8751/2

I will look at it tomorrow.

It depends on the servlet container you’re using (Tomcat, Jetty, CommandBox, etc) The “out” logs capture the standard output stream of the Java process that is your server. For Tomcat, it’s usually called catalina.out and would be in Tomcat’s log dir.

Vote on this ticket here:
https://luceeserver.atlassian.net/browse/LDEV-3130

1 Like

Done!

Hi!

I opened every logs I found and there is nothing about out of memory error.

Here’s what I found, but none of it explains the White Pages.

A lot of this errors

javax.mail.Session.loadResource expected resource not found: /META-INF/javamail.default.address.map

Few errors like this

INFO [ajp-nio-8009-exec-11] org.apache.tomcat.util.http.parser.Cookie.logInvalidHeader A cookie header was received […] that contained an invalid cookie. That cookie will be ignored.Note: further occurrences of this error will be logged at DEBUG level.

Few hours before the incident, just one error like this :

01-Dec-2021 04:58:58.034 WARNING [Thread-1547582] com.microsoft.sqlserver.jdbc.TDSReader.readPacket ConnectionID:77223 ClientConnectionId: ******* TDS header contained invalid packet length:0; packet size:8000

01-Dec-2021 04:58:58.034 SEVERE [Thread-1547582] com.microsoft.sqlserver.jdbc.TDSReader.throwInvalidTDS ConnectionID:77223 ClientConnectionId: ******* got unexpected value in TDS response at offset:0

And this one :

“ERROR”,“Thread-1576539”,“12/01/2021”,“05:00:18”,“controller”,"stop request (10) because run into a timeout. ATM we have 4 active request(s) and 0 active cfthreads path: T:\inetpub\wwwroot\myProject\application.cfc (T:\customtags\cfc\myProject\client\transactions-paiements.cfc).;java.lang.Throwable;java.lang.Throwable

Then the incident and we restarted Lucee.

In archived metrics, I am able to find all the requests (POST, GET) before the incident, but nothing suspicious for now.

I’m probably saying bullshit, but is it possible that the problem is with IIS or the BonCode connector? After all, is that what manages the final return of the content? Perhaps by restarting Lucee the connection was reestablished correctly?

We are going to improve our monitoring. In case of an incident like that, before restarting, we will test if our server is able to return a static file like an image. If the server does not succeed, then the problem is not directly linked to Lucee / Tomcat.

I continue my investigations…

My colleague has just confirmed to me that there was already a probe running during the incident which checked if IIS was able to return a static html file. And IIS was still responding during the Blank Pages incident.

That’s not an “error” as you say. It’s an “INFO” message. It would appear a bot probably sent a badly formed cookie to your server. Nothing to worry about IMO.

Those interesting. Hard to say if they signal anything to be concerned about. You’d need to post to a Microsoft forum however, to get support on errors coming from the MS JDBC driver.

That’s certainly possible, but I can’t say I’ve ever seen that happen with Boncode myself. Usually when there is a connection issue, you get a Boncode error message or an IIS error message, not a white page.


This may be a silly question-- but have you checked the possibility that you actually just have a default error page that has no contents-- or an onError() method perhaps with a code path that outputs nothing? Can you tell from FR if the ALL requests to the server were returning a blank page during the incident, and were those requests also being logged in FusionReactor as hitting CF? What was their response code?

Hi!

Not a silly question at all. I have an onError in my application.cfc for the whole application. I catch all the errors. The code inside look like this :

  1. Send an email with cfmail with a dump of Except
  2. Inside a cftry, I collect more information, remove some for security reason, insert the error in the database, send another detailed email and redirect the user to a custom error page.
  3. If the cftry fail, I send another email with basic information.

During the incident, I received no email at all. I’m also assuming that if cfmail had failed in onError, users wouldn’t have gotten a blank page, unless the error page configured in Lucee is incorrect. It’s set at error-public.cfm.

I will remove the onError soon because Fusion Reactor cannot catch these errors. I need to find a way too to send me an email when an error occurred, but I didn’t find a way with the standard Fusion Reactor yet.

I did go in Metrics - Archived Metrics - Requests and selected the period during the incident. The response codes were 200, and several requests had 0 in the Bytes sent column, but not all. In this report, Bytes sent are the bytes sent by the browser to the server or the server to the browser?

My boss just informed me that the blank page incident happened again this weekend. He refreshed the page and sometimes he had the blank page, sometimes the expected content. It was random. He was forced to restart the server.

It is starting to be worrisome. I’ll see if we hire the services of a consultant to find the source of all this.

Apparently the second incident started around 9pm, at the same time I received this error message by email :

New request is not allowed to start because it should come with valid transaction descriptor.

lucee.runtime.exp.DatabaseException: New request is not allowed to start because it should come with valid transaction descriptor. at com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDatabaseError(SQLServerException.java:262) at com.microsoft.sqlserver.jdbc.TDSTokenHandler.onEOF(tdsparser.java:283) at com.microsoft.sqlserver.jdbc.TDSParser.parse(tdsparser.java:129) at com.microsoft.sqlserver.jdbc.TDSParser.parse(tdsparser.java:37) at com.microsoft.sqlserver.jdbc.TDSParser.parse(tdsparser.java:26) at com.microsoft.sqlserver.jdbc.SQLServerConnection$1ConnectionCommand.doExecute(SQLServerConnection.java:3248) at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:7375) at com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:3206) at com.microsoft.sqlserver.jdbc.SQLServerConnection.connectionCommand(SQLServerConnection.java:3252) at com.microsoft.sqlserver.jdbc.SQLServerConnection.setAutoCommit(SQLServerConnection.java:3385) at lucee.runtime.db.DatasourceConnectionImpl.setAutoCommit(DatasourceConnectionImpl.java:409) at lucee.runtime.db.DatasourceManagerImpl.end(DatasourceManagerImpl.java:366) at lucee.runtime.db.DatasourceManagerImpl.end(DatasourceManagerImpl.java:345) at lucee.runtime.tag.Transaction.doFinally(Transaction.java:160) at scheduled_tasks450.ope_changements_prix_cfm$cf.call(/scheduled-tasks/ope_changements_prix.cfm:18) at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:1034) at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:926) at lucee.runtime.PageContextImpl.doInclude(PageContextImpl.java:907) at application_cfc$cf.udfCall(/application.cfc:289) at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:106) at lucee.runtime.type.UDFImpl._call(UDFImpl.java:344) at lucee.runtime.type.UDFImpl.call(UDFImpl.java:217) at lucee.runtime.ComponentImpl._call(ComponentImpl.java:684) at lucee.runtime.ComponentImpl._call(ComponentImpl.java:572) at lucee.runtime.ComponentImpl.call(ComponentImpl.java:1911) at lucee.runtime.listener.ModernAppListener.call(ModernAppListener.java:437) at lucee.runtime.listener.ModernAppListener._onRequest(ModernAppListener.java:216) at lucee.runtime.listener.MixedAppListener.onRequest(MixedAppListener.java:44) at lucee.runtime.PageContextImpl.execute(PageContextImpl.java:2460) at lucee.runtime.PageContextImpl._execute(PageContextImpl.java:2450) at lucee.runtime.PageContextImpl.executeCFML(PageContextImpl.java:2421) at lucee.runtime.engine.Request.exe(Request.java:45) at lucee.runtime.engine.CFMLEngineImpl._service(CFMLEngineImpl.java:1179) at lucee.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:1125) at lucee.loader.engine.CFMLEngineWrapper.serviceCFML(CFMLEngineWrapper.java:102) at lucee.loader.servlet.CFMLServlet.service(CFMLServlet.java:51) at javax.servlet.http.HttpServlet.service(HttpServlet.java:742) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at sun.reflect.GeneratedMethodAccessor38.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.intergral.fusionreactor.j2ee.filterchain.WrappedFilterChain.doFilter(WrappedFilterChain.java:134) at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doNext(FusionReactorRequestHandler.java:772) at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doHttpServletRequest(FusionReactorRequestHandler.java:344) at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doFusionRequest(FusionReactorRequestHandler.java:207) at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.handle(FusionReactorRequestHandler.java:809) at com.intergral.fusionreactor.j2ee.filter.FusionReactorCoreFilter.doFilter(FusionReactorCoreFilter.java:36) at sun.reflect.GeneratedMethodAccessor35.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.intergral.fusionreactor.j2ee.filterchain.WrappedFilterChain.doFilter(WrappedFilterChain.java:71) at sun.reflect.GeneratedMethodAccessor37.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.intergral.fusionreactor.agent.filter.FusionReactorStaticFilter.doFilter(FusionReactorStaticFilter.java:54) at com.intergral.fusionreactor.agent.pointcuts.NewFilterChainPointCut$1.invoke(NewFilterChainPointCut.java:42) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:493) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) at org.apache.coyote.ajp.AjpProcessor.service(AjpProcessor.java:479) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:806) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:748)

Either this error was caused by the blank pages incident, or the blank pages incident was caused by this error. But I tend to think that’s the first guess.

I don’t believe your understanding is correct. Firstly, the default error page configured in Lucee will ONLY kick in if you have no onError() method or if your onError() itself throws an error. Your onError() basically takes precedence over the server-level setting.

It sounds like you have no actual output in your onError(), which would result in a blank page. Unless you’re explicitly using writeOutput() or cfincluding a file, you’ll just see a white page. It’s up to you to output whatever you want the user to see when an error happens. My suggestion is to dump/abort the error after the cfmail for now until you figure out your SQL error. The fix may be simple, but I think you’re killing yourself by hiding the error messages right now.

Based on a precursory Google of the error message, it seems to be related to a bad state in a SQL connection, which due to connection pooling, may affect other requests trying to use the same connection. That may explain why a restart appears to “fix” the issue, since it’s just forcing a flush of your pooled DB connections. You’ll need to track down the bad query that is causing this and fix it.

1 Like

I understand this. Sorry sometimes I express myself badly. I do not speak native English too. What I wanted to say is that if I have an error in my code in the onError itself, like you said, that the error page configured in the Lucee server admin will kick in, and a possibility could have been that this error page in Lucee was not found or a blank page. And that’s what users see. But I suppose it’s something else.

It’s true. That could very well explain the blank pages. Except that I find it hard to understand why the cfmail in the onError wouldn’t run.

I was thinking of removing the onError in a few days, but I believe it would be better if I remove it ASAP. This would allow Fusion Reactor to catch the errors and it would confirm and eliminate the hypothesis that it comes from the onError which does not return anything. OR I could just output something simple too like “An error occurred” and see what’s happens in the next blank pages incident.

I will take a look at the error I received just before the incident. It’s a scheduled task that run every minute. In fact, there is another error with another scheduled task at the same minute :

The function [qry_changements_automatiques] has an invalid return value , [Cannot cast Object type [user defined function (qry_changements_automatiques)] to a value of type [query]]

As these two scheduled tasks have been running for weeks on Lucee and years on ACF, I would be quite surprised if these scheduled tasks were the source of the incident, but I will check anyway.

Thank you for your patience and your help. It’s very appreciated.

Tony, I’ll assume by “initial memory spool” you’re referring to the “initial memory pool” as indicated in the Tomcat Service configuration UI, and that you’re running Tomcat or Lucee as a Windows service. Even so, note that the maxmetaspacesize arg (if there) will be in the “java options” field of that service config tool, and note that there’s a slider if there are more args than you see in the box on the screen.

But assuming you still confirm there is none, again I only proposed that because of the seeming “blank pages” you were getting. I see that in comments here since your response to me here, there’s a possibility that the “blank” output may be due to an issue in your error handler. We’ll see how that sorts out.

One other thing, you said in reply to Brad later also that you found no out of memory errors in any Lucee or other logs. Just to clarify, you’d want to look for the phrase without spaces, outofmemory…and yes, if you did run out of metaspace, you should find an outofmemory error in some tomcat or Lucee log. (Some things depend on how you installed/implemented Lucee.)

Yes, I confirm there is nothing about maxmetaspacesize in the Java options in the Java tab of the Tomcat Service configuration and the value I’m talking about is the fields : Initial memory pool and Maximum memory pool.

As soon I’m back on foot (busy week and I’m sick over the top), I will remove the onError to let Fusion Reactor capture all the errors. I am still amazed that I have never had any problem with my onError in the past, even with Lucee, and that suddenly it would be problematic and that in addition the error email was no longer sent. But I have other motives for removing it, so I might as well do it anyway. What puzzles me though, is that if this is a problem with onError, it implies that there are random errors occurring in my application, and that I find strange. Everything had been stable for several weeks. Before I rack my brains too much and do scenarios, I have to remove this onError and I’ll be fixed.

I remember that I opened each log files and I scrolled everyline to find any word about memory. And the memory graphs looked normal.

Hi!

While preparing the ground for eliminating the onError in the application.cfc file, I performed tests on the development server. I had to properly configure the error pages in IIS, especially the 500. It was then that I noticed that in the Error pages module in IIS, for the server itself (not the website), the error 500 pointed to an empty htm file. It was then that I remembered that last summer, while preparing the migration from ACF to Lucee, I had started working on these error pages to do tests and hide from users as much detail as possible concerning the errors. I then tested an empty html page and was called to work on something else. Then several months later, we had to urgently migrate our ACF application to Lucee which was not completely ready. So we copied this server to make a production one, but obviously in a hurry, I didn’t think of rechecking this part. And since error catching worked well with onError, I didn’t have any further questions.

So my plan is to restore the default 500 error pages in IIS, remove the onError in application.cfc, and let Fusion Reactor catch the errors.

I suspect that for some reason IIS was throwing a 500 error, caused by Lucee or not, and the default 500 html page for the server was showing … html page that is … blank. That would explain everything from the lack of execution of cfmail in onError to the blank page, and why I seem to be the only one with this kind of unique problem.

It would be embarrassing if that was the blank page problem, but I would be reassured at the same time. It will still be necessary to find out what causes the 500 errors, but still … I will keep you informed.

2 Likes

Hi,

I decided to take the plunge tonight. I created a custom html page for the IIS error 500, both for the server level and the website level, and removed onError from the application.cfc file. Behavior in the app is the same as it was before, except I no longer get email with error details, but at least I can see the error details in Fusion Reactor. I spoke with a Fusion Reactor rep to suggest they add an email notification feature when X number of errors occur in a T time lapse, and he will bring the idea to the team.

Very happy with this change and it will help me see more clearly when random errors occur like lately.

By the way, good call bdw429s about the default error page. When you told me that, I hadn’t thought of looking at the 500 error page set at the IIS root level. The error page for the website in IIS was not empty, but the one in the IIS root level yes. It was quite by chance that I came across it, but your suspicions were founded. It wasn’t a silly question.

1 Like

Glad you finally have resolved things.

As for your desire for FR, I’ll note that for those using FR Cloud (available free with FR Ultimate and Enterprise editions) at least, it can already be configured to alert you by email when the rate of errors exceeds a given value over a given time interval. That’s one of about 60 different metrics that FR Cloud offers in its alert check options.

Perhaps your interest is in the traditional FR (on-prem) alerting, which has only 4 things it can alert on. They’ve long been reluctant to add more, as the FR agent runs within the jvm along with Lucee or CF. But perhaps you may get them to add this one. :slight_smile: The 4th one (for cpu) was added just recently, in fact (the first new alert in many years). They are indeed responsive, and responsible about it.