Entity Component Randomly failed to load, and calling ORMReload fails to re-cache file.

[Drew Dulgar]

Hello All,

I am running into the strangest behavior, and I am having a really hard time pinpointing whether this is a CF bug, or something more so on my side causing this issue.

Once in a great blue moon (this is a rare occurence), an entity component will fail to load from cache. Without touching the files (not updated or pushed to production), I will start receiving error messages (usually relating to a single component with the message: `CFC components.models.ModelName could not be initialized.`. This error happens the first time ORMExecuteQuery is run against the now not loaded component, rather than an overarching failure to load the component itself.

This issue just presented itself today and I really want to get a hold on it. We can't have production going down for this reason. Even though the "fix" is easy, it makes no sense to me.

Here is the timeline that happened up until this morning when the error randomly presented itself.

4/1/2015: All entities pushed to production. ORMReload called to rebulid the cache. Life is good, and everything works as expected.

4/2/2015 - 4/152015: No files have been updated, touched, or otherwise even looked at on production.

4/15/2015 at 10:00 AM. Production goes down. Error message is at the bottom of this post.

Attempts to Fix, but fail included:
- Executing ORMReload(); about 10 bazillion times
- Re-uploading Field.cfc/FieldValue.cfc and a few other relevant components.
- Executing ORMReload(); after uploading files

Actual "fix":
- Uploaded ALL files in my /models folder and executing ORMReload();

Keep in mind, no files were touched, updated, or even opened to be looked at. What is causing a entity component to, for what seems to be me, randomly fail. At the same point, why is the only way that I can fix the exception from occuring is to re-upload all of my entity components and things just work once again? It's also possible that this issue won't present itself for another month.

Some things that may be unqiue to my build and notes:
- every entity inherits from either BaseEntity.cfc OR AuditableEntity.cfc. AuditableEntity.cfc also inherits from BaseEntity.cfc.
- every entity implements two interfaces, IAuditable.cfc and IValidatable.cfc.
- The server was last restarted on 4/8/2015, so it has been up for 8 days and successfully reloaded the entity components.

Error message and Stack Trace:
-----------------------------
Detail Check if the persistent attribute in component is set to "true". Root cause - java.lang.NullPointerException
Message: CFC components.models.FieldValue could not be initialized.

Stack Trace:
java.lang.NullPointerException at coldfusion.runtime.InterfaceTemplateProxyCache.getTemplateProxyFromPath(InterfaceTemplateProxyCache.java:125) at coldfusion.runtime.TemplateProxyFactory.resolveSuperName(TemplateProxyFactory.java:998) at coldfusion.runtime.TemplateProxy.verifyInterfaceImpl(TemplateProxy.java:1231) at coldfusion.runtime.TemplateProxy.verifyInterfacesImpl(TemplateProxy.java:1064) at coldfusion.cfc.ComponentProxyFactory.getProxy(ComponentProxyFactory.java:62) at coldfusion.orm.hibernate.CFCTuplizer$CFCinstantiator.instantiate(CFCTuplizer.java:251) at coldfusion.orm.hibernate.CFCTuplizer$CFCinstantiator.instantiate(CFCTuplizer.java:227) at org.hibernate.tuple.entity.AbstractEntityTuplizer.instantiate(AbstractEntityTuplizer.java:606) at org.hibernate.persister.entity.AbstractEntityPersister.instantiate(AbstractEntityPersister.java:3888) at org.hibernate.impl.SessionImpl.instantiate(SessionImpl.java:1412) at org.hibernate.impl.SessionImpl.instantiate(SessionImpl.java:1401) at org.hibernate.loader.Loader.instanceNotYetLoaded(Loader.java:1342) at org.hibernate.loader.Loader.getRow(Loader.java:1251) at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:619) at org.hibernate.loader.Loader.doQuery(Loader.java:745) at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:270) at org.hibernate.loader.Loader.doList(Loader.java:2294) at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2172) at org.hibernate.loader.Loader.list(Loader.java:2167) at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:448) at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:363) at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:196) at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1258) at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102) at coldfusion.orm.hibernate.HibernatePersistenceManager._executeHQL(HibernatePersistenceManager.java:824) at coldfusion.orm.hibernate.HibernatePersistenceManager.executeHQL(HibernatePersistenceManager.java:753) at coldfusion.orm.hibernate.HibernatePersistenceManager.executeQueryWithNamedParams(HibernatePersistenceManager.java:628) at coldfusion.orm.ORMUtils._executeQuery(ORMUtils.java:346) at coldfusion.orm.ORMUtils._executeQuery(ORMUtils.java:311) at coldfusion.orm.ORMUtils.executeQuery(ORMUtils.java:303) at coldfusion.runtime.CFPage.ORMExecuteQuery(CFPage.java:8933) at cfUser2ecfc1092968104$funcGETHIERARCHYSYSTEMPERMISSIONS.runFunction(/mnt/dfsintranet/dfsintranet-32000/groups/na/dialerstrategy/PandI/Hierarchy/cfcs/models/User.cfc:685) at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:472) at coldfusion.filter.SilentFilter.invoke(SilentFilter.java:47) at coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke(UDFMethod.java:405) at coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:368) at coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:55) at coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:321) at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:220) at coldfusion.runtime.CfJspPage._invokeUDF(CfJspPage.java:2659) at cfUser2ecfc1092968104$funcINIT.runFunction(/mnt/dfsintranet/dfsintranet-32000/groups/na/dialerstrategy/PandI/Hierarchy/cfcs/models/User.cfc:43) at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:472) at coldfusion.filter.SilentFilter.invoke(SilentFilter.java:47) at coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke(UDFMethod.java:405) at coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:368) at coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:55) at coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:321) at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:220) at coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:655) at coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:444) at coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:414) at coldfusion.runtime.CFPage.___createObjectInternal(CFPage.java:10381) at coldfusion.runtime.CFPage._createObject(CFPage.java:10347) at cfApplication2ecfc216531884$funcSETUPUSERSESSION.runFunction(/mnt/dfsintranet/dfsintranet-32000/groups/na/dialerstrategy/PandI/Hierarchy/Application.cfc:369) at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:472) at coldfusion.filter.SilentFilter.invoke(SilentFilter.java:47) at coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke(UDFMethod.java:405) at coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:368) at coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:55) at coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:321) at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:220) at coldfusion.runtime.CfJspPage._invokeUDF(CfJspPage.java:2659) at cfApplication2ecfc216531884$funcONREQUESTSTART._factor0(/mnt/dfsintranet/dfsintranet-32000/groups/na/dialerstrategy/PandI/Hierarchy/Application.cfc:126) at cfApplication2ecfc216531884$funcONREQUESTSTART.runFunction(/mnt/dfsintranet/dfsintranet-32000/groups/na/dialerstrategy/PandI/Hierarchy/Application.cfc:103) at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:472) at coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke(UDFMethod.java:405) at coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:368) at coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:55) at coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:321) at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:220) at coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:655) at coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:444) at coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:414) at coldfusion.runtime.AppEventInvoker.invoke(AppEventInvoker.java:108) at coldfusion.runtime.AppEventInvoker.onRequestStart(AppEventInvoker.java:278) at coldfusion.filter.ApplicationFilter.invoke(ApplicationFilter.java:417) at coldfusion.filter.RequestMonitorFilter.invoke(RequestMonitorFilter.java:48) at coldfusion.filter.MonitoringFilter.invoke(MonitoringFilter.java:40) at coldfusion.filter.PathFilter.invoke(PathFilter.java:112) at coldfusion.filter.ExceptionFilter.invoke(ExceptionFilter.java:94) at coldfusion.filter.BrowserDebugFilter.invoke(BrowserDebugFilter.java:79) at coldfusion.filter.ClientScopePersistenceFilter.invoke(ClientScopePersistenceFilter.java:28) at coldfusion.filter.BrowserFilter.invoke(BrowserFilter.java:38) at coldfusion.filter.NoCacheFilter.invoke(NoCacheFilter.java:46) at coldfusion.filter.GlobalsFilter.invoke(GlobalsFilter.java:38) at coldfusion.filter.DatasourceFilter.invoke(DatasourceFilter.java:22) at coldfusion.filter.CachingFilter.invoke(CachingFilter.java:62) at coldfusion.CfmServlet.service(CfmServlet.java:219) at coldfusion.bootstrap.BootstrapServlet.service(BootstrapServlet.java:89) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210) at coldfusion.monitor.event.MonitoringServletFilter.doFilter(MonitoringServletFilter.java:42) at coldfusion.bootstrap.BootstrapFilter.doFilter(BootstrapFilter.java:46) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210) at com.intergral.fusionreactor.filter.FusionReactorFilter.doFilter(FusionReactorFilter.java:123) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:224) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:169) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:168) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:98) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118) at org.apache.catalina.ha.session.JvmRouteBinderValve.invoke(JvmRouteBinderValve.java:219) at org.apache.catalina.ha.tcp.ReplicationValve.invoke(ReplicationValve.java:333) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:414) at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:204) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:539) at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:298) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662)
------

[Cameron Childress]

On Wed, Apr 15, 2015 at 1:43 PM, Drew Dulgar wrote:

This may be nothing but I note that the path starts with "components" here:

`CFC components.models.ModelName could not be initialized.`.

Then in the error stack trace it starts with "cfcs" here:

 

.runFunction(/mnt/dfsintranet/dfsintranet-32000/groups/na/dialerstrategy/PandI/Hierarchy/cfcs/models/User.cfc:685) at

I'm assuming you have a mapping for "components" pointing to "cfcs"?

I have seen a few situation situations where CF and/or Hibernate gets a path name wrong. I'd double check and make sure you are using the EXACT SAME full entity path name in all ORM CFC definitions and all ORMExecutes, etc...

More here:

https://groups.google.com/d/msg/mura-cms-developers/ZQ7LOa1m4rc/hdYK-6KLQ5MJ

-Cameron

--

Cameron Childress
--
p:   678.637.5072

im: cameroncf

facebook | twitter | google+

[Drew Dulgar]

Hi Cameron,

That is correct. There is a mapping that is setup to do

'/components' : '#appRoot#cfcs'

I'll take a look and see if there are any discrepancies. This issue also has never presented itself on Railo, only on ACF thus far. Although it may have just not had that very specific trigger that causes it to lose the pathing.

It just seems weird to me that it would find the components no problem, then randomly lose the path... and yet the issue can only be resolved if the files are reuploaded.

In-fact, today, when the issue presented itself. I copied down the models folder to the local desktop, and all I did was pushed that same folder back up to production. This means not a single file was updated in content. After ORMReload() was called, everything loaded as expected.

[Cameron Childress]

On Wed, Apr 15, 2015 at 6:53 PM, Drew Dulgar wrote:

This issue also has never presented itself on Railo, only on ACF thus far.

Yup - I only see the path problem on ACF too. Railo doesn't have the problem.

 

Although it may have just not had that very specific trigger that causes it to lose the pathing.

Me either. When I've seen this is works then doesn't work. No real reason.

 

It just seems weird to me that it would find the components no problem, then randomly lose the path... and yet the issue can only be resolved if the files are reuploaded.

My theory is that touching the files and running ormReload() causes ACF to forget all it knows and go scrounging around for meta information again, resetting whatever wrongness it knew about before. So that's also consistent with this behavior - I've seen this problem on ACF for years.

-Cameron

[John Whish]

I've not experienced this myself, but a couple of things to consider:

- Have you got the Save Class Files option in CF enabled?

- What happens if you choose to persist the .hbmxml files (savemapping setting)

--
You received this message because you are subscribed to the Google Groups "cf-orm-dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email to cf-orm-dev+...@googlegroups.com.
To post to this group, send email to cf-or...@googlegroups.com.
Visit this group at http://groups.google.com/group/cf-orm-dev.
For more options, visit https://groups.google.com/d/optout.

[Drew Dulgar]

> My theory is that touching the files and running ormReload() causes ACF to forget all it knows and go scrounging around for meta information again, resetting whatever wrongness it knew about before. So that's also consistent with this behavior - I've seen this problem on ACF for years.

Sounds like a good theory thus far. I did take a look and all of my pathings are consistent. The init method actually exists as part of BaseEntity.cfc, and it is nothing more than a simple.

public any function init() {
return this;
}

The entities themselves are never invoked through any other method other than ORM Methods (enityLoad, entityLoadByPK, ORMExecuteQuery etc).

> - Have you got the Save Class Files option in CF enabled?

I do not have access to the CF administrator. This setting is most likely set to whatever the default value is (CF 10).

> - What happens if you choose to persist the .hbmxml files (savemapping setting)

That is a can of worms all of it's own. I haven't tried doing that on my production environment, but on my dev environment I had a really hard time getting the hbmxml files to properly rebuild after an ORMReload call, so I stopped messing with it, deleted the files and went back to the more CF standard way of caching the entity components.

Thanks for the thoughts guys,
Will keep digging around.