CF2018 Http 500 Error upon startup, cache issue?

[kevinr1985]

CF2018 Sys Admin here so I don't know alot about the code for the application but I'm getting an http 500 error on all of my instances at boot up. Only fix I have found so far is to clear template cache and then the web app will load.

CF Error page and out log are not very descriptive either. 

Exception occured before FW/1 was initialized

Error while resolving the relationship subsectionTemplate in cfc crms.model.beans.criterionTemplates. Check the column mapping for this property.

Recently migrated these apps from CF2016 to 2018 and I'm running them on IIS8.5

This occasionally happened while they were on 2016 but not every time the instances startup.

[Charlie Arehart]

I may have a quick fix for you. There's much more that could be said, but given what you say, can you  simply confirm first if your cf admin caching page shows the "save class files" option enabled? (It should, for production and indeed for most uses.)

Assuming it is, stop cf and go to the coldfusion folder and its cfusion subfolder (assuming you are running only that one instance), and then its

/wwwroot/WEB-INF/ folder. There 

rename the cfclasses folder (NOT classes) to something like cfclasses-old. Then restart cf. CF will create a new cfclasses folder on startup. 

If doing that solves things (no more error, and no more need to clear the template cache as a fix), then you somehow had bad class files in there, and they will be created anew (and loaded into the template cache in memory). The problem should NOT recur. 

If you wanr/need to know more, there's indeed more that could be said, but this may get you going. (And again, turning OFF "save class files" is not the right solution in nearly all cases.) 

Finally, if it does work you can delete that renamed cfclasses folder. 

[BKBK]

As an alternative to Charlie's suggestion: 

1) Open the ColdFusion Administrator and go to the Caching page;

2) Click on the buttons to clear the Template cache and the Component cache.

Do you still get the error?

[Charlie Arehart]

BKBK, he had said in his first note that, "Only fix I have found so far is to clear template cache and then the web app will load."

That's why I took things in the different (but directly related) direction I did. 

[BKBK]

The template cache and the component cache should be cleared. Both are relevant to FW/1 (Framework-One).

[Dave Watts]

I honestly don't know much about FW/1, which is what you're using. But in my experience, many CMSs and frameworks etc do a lot of caching before they can actually be used. I suspect that's what's happening here. Ideally, you need a process that

a) limits access to the web server

b) starts the web server and the application server

c) initiates the first request to the application server so that it'll start loading stuff into memory or whatever

d) when everything's loaded, opens access to the web server.

I used to do this manually quite a bit for CommonSpot applications that had a lot of caching upfront. But it could be automated pretty easily as long as you can make an accurate guess about when everything's loaded. IIS properties can be changed from PowerShell or batch files, or you could temporarily block access to IIS at the host-based firewall.

Dave Watts, Eidolon LLC

[Jim Priest]

It's a weird issue as it's not consistent.  We have 3 instances running and for example 2 of them will load file and one will fail with this error.  All three are running the same application.   It started doing this in 2016 and continues in 2018.

I also tried disabling the "Save Class Files" options and toasted all the files in the cfclasses directory - but still got the error this morning. 

We could do some kind of 'warm up' per Dave's suggestion . We have Jenkins. I actually cobbled together a job that logs in every morning and hits the cache flush buttons in the admin. 

[Jim Priest]

The other thing to note as well as we have 5 developers and no one runs into this on their local with basically the same  settings.   One thing to note maybe per Dave's suggestion is I believe all of the developers are running via Commandbox / Docker with no IIS.  

[BKBK]

The error is likely caused by ColdFusion ORM being unable to resolve the following property defined in crms/model/beans/criterionTemplates.cfc

<cfproperty name="dotted.path.to.subsectionTemplate"... etc.>

If there is indeed such a property, could you please share its full definition.

[Jim Priest]

If it was an ORM or property issue I'd expect it to always fail?  It doesn't.  I've never gotten this error in my local environment, and in our dev environment we have 3 CF instances, all running the same code, and this issue will only occur in one of the instances?

Once the cache is cleared the app will run fine all day.

[BKBK]

That's just it. Your environment may differ in a subtle way from theirs. In addition, the application might, behind the scenes, use a setting stored in session or application scope. You might then be getting an error when the session or application expires.

If there is indeed a cfproperty, as I described, could you please share its full definition.

[BKBK]

I didn't pluck the ORM idea from thin air. Google the following:

"Error while resolving the relationship" "cfc" "Check the column mapping for this property"

[Jim Priest]

Here is gist of the properties in question and the one it's related to

https://gist.github.com/jimpriest/11134f907f45ee4367879c86a4961f76

[BKBK]

Does the table subsectionTemplate exist?

If so, does it contain columns corresponding to each and every one of  the properties you marked as "Table-based properties"? 

If not, manually create the table subsectionTemplate. 

Just to be on the safe side, maintain the same case wherever the property-name subsectionTemplate occurs. Hence:

• name of database table: subsectionTemplate
• <cfproperty name="subsectionTemplate"...>
• <cfcomponent displayname="Subsection Template" table="subsectionTemplate"...>

[Jim Priest]

Table and all columns exist.  I've opened 3 issues with Adobe support (including this one) and almost a month later none of them are resolved. 

Note to self: Just because you pay 5 figures for a piece of software doesn't mean you get support to match.  

Note to people considering Adobe ColdFusion - Google 'Lucee'. 

[BKBK]

Let's assume for a moment that this has to do with paths. What happens when you experiment with variations like 

(1)

<cfproperty name="subsectionTemplate" fieldtype="many-to-one" lazy="true" cfc="subsectionTemplate" cascade="save-update" />

(2) Open the Mappings page in your ColdFusion Administrator. Compare your mappings with those of a colleague whose application works flawlessly. Is there a mapping there for CFCs?

If there is, it will be something like 

Logical Path: /model/cfcs
Directory Path: C:/ColdFusion2021/cfusion/wwwroot/FW1Project/model/services

You could then experiment with

<!--- NB: My path is fictitious, and is used just to illustrate --->

<cfproperty name="subsectionTemplate" fieldtype="many-to-one" lazy="true" cfc="model.cfcs.subsectionTemplates" cascade="save-update" />

[Charlie Arehart]

Jim, we appreciate your frustration. And as you see we don't want to give up as long as you want to keep going. I have a couple of thoughts. 

1) First, for the sake of other readers, there's never any guarantee that a tracker bug report will be fixed let alone verified, sadly. (And Lucee bugs have languished before, to be fair.)

2) But back to your problem, I wonder if you might have given up on my first idea too quickly, when you say you

'tried disabling the "Save Class Files" options and toasted all the files in the cfclasses directory'. 

First, I didn't say to  disable that "save class files" option. Indeed, I recommended specifically against that. (It should be on, for most people. It's rather rare situations where turning it off is better.)

3) But most important, when you say you "toasted" the files in  cfclasses, you don't clarify if you did stop cf first. That was an important point. Can you clarify?

The fact that clearing the template cache helps just calls into question if cf is somehow still loading some bad one. 

4) But if you did or do that and it still fails, then (like other idead BKBK and Dave have offered), I'd wonder if there is some sort of race condition unique to the server experiencing the problem, which leads to different execution of the flow of code.

That can be challenging to prove, but not impossible.

Step debugging might readily show a difference between one and another. I know some people would rather gargle broken glass than do that. Just saying it's an option, whether with cfbuilder (also in its free trial) or the interactive debugging in fr ultimate or its free trial.

And while some feel that's all too complicated to setup, it really isn't and I can help if you're interested.

5) Finally, are you saying this happens on startup even if there are no requests that have run? It's possible, but unlikely. Just have to ask.

And if it is after some run, there's still the idea Dave offered to pre-warm/pre-load the app before users would make a request. 

[Jim Priest]

I have tried everything I can thing of with caching  🙂

- Enabled and disabled saving class files
- Purging class files - yes I did stop CF service first to ensure they were all deleted

- Also tried Charlies suggestion of renaming the dir and letting ColdFusion create it again

As for your last question - it basically happens on the first request.  Restart service, first request always gets this error.   We clear the cache and the app runs fine until the next restart.   This is our 'stage' environment - ColdFusion installed locally.

Same code running on our local developer machines - some folks using Docker and some using locally installed CommandBox - we never see this error.

Right now my kludgly work around is to run a Jenkins job every morning which uses Cypress to login to the admin and reset the cache via the web admin LOL.

[Charlie Arehart]

Thanks for the clarifications. Definitely an odd one.

1) It suggests that somehow SOME template gets loaded into the template cache with a problem, and when you clear the cache, it gets recreated at that later point, when all's well. That's definitely odd (and may be a bug, or again may be some unexpected race condition).

But since things DO work once that bad one is reloaded, it begs a question: why isn't the good one in the saved class files, ready to be loaded upon restart? You have said before that you disabled the "save class files". Have you let if disable? Do you have any reason to do that? Have you confirmed if all this is needed if you DO have that setting enabled? If you did, then CF would save the compilation (the good one) and reload it on the next restart.

2) Even if you may not want to bother with that, I will note that about your last point (of using a jenkins job and cypress to cause the template cache refresh after a period of time), I gather you mean it's using js to trigger clicking that button, right? FWIW, you could instead jsut call the CF Admin api instead. There's a cleartrustedcache method in the runtime.cfc, which will do the job. (That name is misleading and frankly mistakenly named, but it will do the job. I have a blog post with more.)

And note that instead of using a jenkins job (whicih I suppose you run when you rebuild things), you could also use the onserverstart.cfc feature in CF (on the CF admin settings page) to trigger a named CFC to run on restart. And you could have that go to sleep for a few mins and then call this adminapi. Maybe you know of both of those already. Again, I write as much for others who may find this thread later.

3) In that same spirit, something else to consider is that both the Admin UI and that (poorly named) cleartrustedcache admin API method both also offer the option for you to name a folder to clear (instead of clearing everything). If you knew what folder had the bad code, you could clear JUST that folder.

Or if you have NOT yet discerned what folder has the troubled template, this is a way you could try different folders if you wanted to. I realize that may be tedious and not worth the bother.

4) And certainly this sort of problem shouldn't happen. It just sounds like the kind of thing that reflects some sort of race condition, which may explain both why we don't hear it as some common problem, and why you don't see on the other machines.

BTW, I have just noticed that the OP of this thread is kevinr1985, but he's never responded. Are you guys working together on this issue? If not, it would be interesting to hear if he has any thoughts on all the things that you, I, BKBK, and Dave have offered. Maybe there is some difference in your situations. 

5) Finally, BKBK had proposed possible path/mapping issues, which you felt did not apply. But as the problem remains, let's press the point. Is it possible that your app has application mappings (in some application.cfc or a file called from it)? Could it be that some circumstance could cause the value of that mapping to change at one point in the code, such that something that is generated (as a template in the template cache, during that CF startup time) thinks it should use whatever mapping is defined at that time, but which is wrong.

Then later when you clear the template cache, the mapping it would use is "right"? That's something you could perhaps prove with some judicious use of cflog/writelog, to see what is the value of any mapping involved in the things that are generating the error.

[BKBK]

@Charlie Arehart hit the nail on the head. Or, should I say, nails. Each point he raises is worth exploring.

Could you please share your ORMSettings?

[Jim Priest]

Thanks Charlie!!    Yes Kevin and I work together. 🙂

It is weird  - that why I tried all sorts of different things with  the class files  - thinking the same way you are - if it runs - why isn't that 'good' file being saved and re-used.  

I have not tried clearing individual folders - but that might be worth trying just to see if I can narrow things down.

I know about the Admin API but not sure of a secure way to store and use the admin credentials.  It's on my radar to look at again but the Jenkins hack was a quick and dirty way to reset things on a schedule. 

As far as mappings we  have one for /gateway which I think was default in 2018 and then we have added one for /testbox.  Neither are used by our main application. 

[Charlie Arehart]

As for your last point, are you stating what mappings are in the cf admin? It seems so. I was referring instead to application level mappings. 

[Jim Priest]

For 'mappings' I'm not sure what you mean.  But in general our app has several sections and they are all similar with the same sort of MVC structure with similar beans.   Which is why this error is so puzzling.  Why does it bomb at this particular one each time?  And why does simply clearing the cache 'fix' it?

[Charlie Arehart]

As for app-level mappings, I refer to those which can be defined in application.cfc (or a file called from it), typically as an array in this.mappings. They have been supported in acf and lucee for some years. 

I'm asking first simply if you use them. If so, I can see a possibility for some race condition to have the same mapping be defined for different values at different times (unexpectedly). 

It's BECAUSE things are acting so strange for you that we are grasping at straws to find a possible explanation. There is one. It just has to be found. 

In fact, as for your other machines where this doesn't happen, there may also be some difference that you're not accounting for (beyond the docker and iis difference you'd mentioned), but it could also be a load thing. 

Can you make the problem happen on the currwnt machine without any load? 

[Jim Priest]

No mappings defined in application.cfc.

Issue does happen w/no load.  Last night I was trying some more ideas.  No one was using the machines except me. I restarted CF.  First request it spins and displays the error.