Possible race conditions when creating and updating a struct in the same request - coldfusion

Question

About a year ago I asked a question about errors I was getting in an app, that indicated a possible race condition:

Possible race condition creating Structs in ColdFusion

A year on, I'm still having issues with this and other apps where the same technique is employed and it seems that frankly, you cannot create and update a struct reliably in the same request. This of course seems ludicrous, so I must be doing something wrong - but I'd appreciate some help.

Here's an explanation of what's going on:

I have a function, instantiated in the Application scope, that accepts a comma separated list of IDs as a parameter.
The function hits the database requesting all the records with matching IDs
We then loop through the recordset, and create a locally scoped struct, dynamically named using the ID of the record, e.g. Local.myStruct['item_' & myrecordset.ID]
Finally we add data to this struct.

The issue is that very intermittently, the code will error on the last step, stating that the dynamically named struct that was created literally two lines previous, does not exist... Interestingly, the line of code in question is updating the struct, and so if it didn't exist, I'd expect it to simply create it - I wonder if using Array notation to set the value of dynamically named variables somehow behaves differently than using dot notation?

So, here's some code:

<cffunction name="GetPrices" access="public" returntype="struct">
    <cfargument name="ItemID"       type="string"   required="true" />
    <cfargument name="PriceBand"    type="string"   default="1"     />

    <cfset var Local = {} />

    <!--- Query the database for the part details --->
    <cfquery name="Local.GetParts" datasource="#this.sDSN#">
        SELECT  TOP 200
                [ItemID]
            ,   [Price1]
            ,   [Price2]
            ,   [Price3]
        FROM    [Items]

        WHERE   1 = 1

        <cfif ListLen(Arguments.ItemID) GT 1>
            AND ItemID IN (<cfqueryparam cfsqltype="cf_sql_integer" list="yes" value="#Arguments.ItemID#">)
        <cfelse>
            AND itemID = <cfqueryparam cfsqltype="cf_sql_integer" value="#Arguments.ItemID#">
        </cfif>
    </cfquery>

    <cfloop query="Local.GetParts">
        <cfset Local.ReturnStruct['item_' & Local.GetParts.ItemID] = {} />

        <cfset Local.ReturnStruct['item_' & Local.GetParts.itemID].CurrentPrice = Local.GetParts['price' & Arguments.PriceBand] />
    </cfloop>

    <cfreturn Local.ReturnStruct />

</cffunction>

The function would be called thus:

Variables.GetPrices = Application.com.Items.GetPrices(
        ItemID      = '8263,1996,324686,32,12746,297807,1763,37568,2359782,321,3525,563466,323'
    ,   PriceBand   = 2
)

As you can see, the function is varscoped, and in any case we're running CF10 where I'm lead to believe that an implicit Local scope is thread safe in a function. Var scoping is where we landed last year on this problem, but alas the problem persists. Can anyone offer any other suggestions?

Thanks

EDIT: As requested, here's an exmple of the errors I'm receiving:

Element item_61284 is undefined in a CFML structure referenced as part of an expression.

The item ID is different every time. It's probably worth noting that the code posted has been manipulated slightly for the purposes of the question - so the stacktrace below may show bits and pieces that can't be attributed to the code above.

I'm confident that nothing removed from the production code is relevant to the issue, as these symptoms occurr across tens of functions in multiple apps, wherever the same technique is used.

coldfusion.runtime.UndefinedElementException: Element item_61284 is undefined in a CFML structure referenced as part of an expression. at coldfusion.runtime.CfJspPage.ArrayGetAt(CfJspPage.java:974) at coldfusion.runtime.CfJspPage._arrayGetAt(CfJspPage.java:985) at coldfusion.runtime.CfJspPage._arrayGetAt(CfJspPage.java:980) at cfparts2ecfc1041715109$funcREDACTED.runFunction(REDACTED.cfc:665) 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:518) at coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:660) at coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:469) at coldfusion.runtime.CfJspPage._invoke(CfJspPage.java:2373) at REDACTEDcfm969331649.runPage(REDACTED.cfm:43) at coldfusion.runtime.CfJspPage.invoke(CfJspPage.java:244) at coldfusion.tagext.lang.IncludeTag.doStartTag(IncludeTag.java:444) at coldfusion.runtime.CfJspPage._emptyTcfTag(CfJspPage.java:2799) at REDACTEDcfm522717774.runPage(REDACTED.cfm:83) at coldfusion.runtime.CfJspPage.invoke(CfJspPage.java:244) at coldfusion.tagext.lang.IncludeTag.doStartTag(IncludeTag.java:444) at coldfusion.runtime.CfJspPage._emptyTcfTag(CfJspPage.java:2799) at cfapplication2ecfc1345221948$funcONREQUEST.runFunction(REDACTED\Application.cfc:573) 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.onRequest(AppEventInvoker.java:300) at coldfusion.filter.ApplicationFilter.invoke(ApplicationFilter.java:424) 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.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 sun.reflect.GeneratedMethodAccessor63.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at com.intergral.fusionreactor.j2ee.filterchain.WrappedFilterChain.doFilter(WrappedFilterChain.java:97) at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doNext(FusionReactorRequestHandler.java:437) at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doHttpServletRequest(FusionReactorRequestHandler.java:311) at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doFusionRequest(FusionReactorRequestHandler.java:192) at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.handle(FusionReactorRequestHandler.java:472) at com.intergral.fusionreactor.j2ee.filter.FusionReactorCoreFilter.doFilter(FusionReactorCoreFilter.java:36) at sun.reflect.GeneratedMethodAccessor61.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at com.intergral.fusionreactor.j2ee.filterchain.WrappedFilterChain.doFilter(WrappedFilterChain.java:79) at sun.reflect.GeneratedMethodAccessor60.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at com.intergral.fusionreactor.agent.filter.FusionReactorStaticFilter.doFilter(FusionReactorStaticFilter.java:53) at com.intergral.fusionreactor.agent.pointcuts.NewFilterChainPointCut$1.invoke(NewFilterChainPointCut.java:41) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java) 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.valves.AccessLogValve.invoke(AccessLogValve.java:928) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118) 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.runWorker(Unknown Source) at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) at java.lang.Thread.run(Unknown Source)

Have you tried using `cflock` to prevent the race condition? I realize the docs say you don't need to but those docs have been wrong before... It could be worth a shot to see if the issue goes away. Obviously you will need to consider/test for performance degradation with the locking. — Miguel-F, Dec 10 '14 at 18:43
Since you're on CF10, you should really stop using `` and just use `local` scope. I'm not sure if it will help, but CF used to do some magic when it sees `var local = {}` and maybe that magic affected your code. — Henry, Dec 10 '14 at 20:04
Henry beat me to it. Either `VAR` a variable *or* use the `local` scope. Not both. (but that is just coding style: it is not a consideration as far as your problem goes. — Adam Cameron, Dec 10 '14 at 20:07
There is no race condition here, @Miguel-F. Whatever the OP's issue is, it is not that. — Adam Cameron, Dec 10 '14 at 20:09
Can you copy and paste the *exact* error message into your question, please? And can you not combine those two assignments into one: `` — Adam Cameron, Dec 10 '14 at 20:10
Thanks for the comments, chaps. I've added some error details as requested. With regard to the discussion of ``, the code was initially developed for CF8. I understand CF10 has removed the need for this, though it's still a deeply ingrained habit - is there any evidence of it causing a problem in a CF10 environment? — Gary Stanton, Dec 10 '14 at 22:54
@AdamCameron, yes, there's no reason not to combine the two assignments in the code above, and I guess it might resolve the problem here - but not explain why the problem occurrs in the first place. The production code has a few other bits and pieces going on that make it less viable to do this... the code posted has been manipulated a bit for the sake of the question, but I have this problem in lots of functions using the same technique, so I'm confident nothing removed is relevant to the issue. — Gary Stanton, Dec 10 '14 at 22:58
Right. You need to post ALL the code in that function. And do me a favour. Change that struct literal `{}` to a `structNew()` and retest. — Adam Cameron, Dec 10 '14 at 23:50
It won't cause a problem, but you shouldn't write unnecessary code. Why would you? Why defend a habit that is simply to write code you don't need? — Adam Cameron, Dec 11 '14 at 07:12
I'm reluctant to post production code publicly for security reasons (and because it's messy!) but I can chuck it up on pastebin for a bit if necessary - I've changed the struct literal as suggested. The error is very intermittent though so it'll take a while to know if it's helped. With regard to the var local habit, you're right of course - but I still have clients on CF8 and wherever possible I include functions in a library I use internally across projects; so if it doesn't hurt to keep that code in there, it makes the code more portable. — Gary Stanton, Dec 11 '14 at 10:30
Ugh... just noticed another function that exhibits the same problem has always used `StructNew()`, so seems unlikely that this change will fix the issue. The embarrassing production code, such as it is, is here for the next hour: http://pastebin.com/BLEMxAfP - and will error on line 88. Drop me comment if it's expired before you see it. — Gary Stanton, Dec 11 '14 at 10:53
As an aside, IMO it is more readable to create a separate variable for the current "item", and use it, rather than doing a structure look-up (by some long key) multiple times on each iteration. Here is a [psuedo example](http://pastebin.com/agm2vvnE) of what I mean. Frankly my reason for suggesting it is solely to improve readability, but given the specific error in this case, it *might* even help. Obviously though, that still does not answer the question of why your current code does not work. — Leigh, Dec 11 '14 at 19:46
Well, after five days of running with `StructNew()` instead of `{}`, I've yet to see another error. So it would seem that Adam's suggestion has resolved my issue. A few things concern me though, firstly I can't see why this should make a difference. If it does, surely this is indicative of a deeper issue, presumably a bug, in CF? Secondly I'm still having a similar problem in a different function where `StructNew()` has always been used, so perhaps the real issue lies elsewhere. Either way, I'm happy for now. Thanks for all the help and suggestions. Adam, do you want to put this in an answer? — Gary Stanton, Dec 16 '14 at 09:34
Weird. @AdamCameron - I would not think expect there to be any difference between creating an empty structure via `{}` versus `structNew()`. Did you suggest it under the "just for grins" category - or do you know something we don't? ;-) — Leigh, Dec 20 '14 at 20:47
@Leigh: there have been *numerous* parser bugs with implicit struct and array notation. Most were cleaned out in CF9, but I've seen a few since. I was just wanting to factor it out as a consideration. I was not suggesting it as a permanent change. — Adam Cameron, Dec 20 '14 at 21:21
@AdamCameron - Yes, I remember some bugs in CF8. But the ones I recall usually involved more than just initializing an empty structure or array. That is why I was not expecting `structNew` to have any impact. Not in this specific case anyway. — Leigh, Dec 21 '14 at 00:31
@Leigh there was def at least one bug in which any struct/array literal usage caused the next line of code to not be parsed or compiled at all. But only when it's within some other block-level construct like an `if`. It's as crazy as that. — Adam Cameron, Dec 21 '14 at 00:40
@AdamCameron - Oh good grief. I will have to take another look through the bug db tomorrow. Moving away from the old flash interface was an improvement, but it is still quite arduous since you can only search one version at a time.. — Leigh, Dec 21 '14 at 04:35
@Leigh, I just use Google, using a `site:` search. It takes some of the pain out of the exercise. https://www.google.co.uk/webhp#q=site:bugbase.adobe.com+struct+literal — Adam Cameron, Dec 21 '14 at 09:35
Doubt anyone's likely to come across this question anymore, but my problems persist and are legion. The original error returned after a few days, and similar symptoms are present all over the app and with increasing regularity. I can literally create a variable with and reference it two lines later, and it'll be gone. Intermittently, of course. I'm getting more and more concerned that CF is simply broken. — Gary Stanton, Feb 16 '15 at 17:16
I have a similar issue I believe. While different as it's a query, it's pretty straight forward and makes no sense, to me currently, what the issue is. http://stackoverflow.com/questions/37716733/coldfusion-scoping-issues-passing-returning-values-from-a-function Mine is not as wide spread but happens in the location in my post often enough to be annoying but not often enough to be a deal breaker. I can't recreate it on demand and load doesn't seem to be a factor. — Leeish, Jun 09 '16 at 04:52

score 1 · Answer 1 · answered Mar 20 '15 at 17:49

Gary, I feel your pain because I too have experienced all kinds of crazy CF errors that "shouldn't be possible". I spent literally years battling intermittent failures in the Transfer ORM which I just recently learned was due to the fact that xmlSearch() is not thread-safe!

So, let me share a couple of strategies which will not solve your problem but will help you get closer to diagnosing the underlying cause of the issue:

Use duplicate() to eliminate thread-safety issues

The solution to my XML case above was to wrap the results of xmlSearch() in a duplicate(). It may not be the issue here but you might try breaking apart the generation of the struct key from the usage like:

<cfloop query="Local.GetParts">
    <cfset local.id = "item_" & duplicate(Local.GetParts.ItemID) />
    <cfset Local.ReturnStruct[local.id] = {CurrentPrice: Local.GetParts['price' & Arguments.PriceBand]} />
</cfloop>

Use a sanity check with cflog

This is probably my best strategy because it tells you the condition that CF is in when it's about to barf. Try something like:

<cfloop query="Local.GetParts">
    <cfset Local.ReturnStruct['item_' & Local.GetParts.ItemID] = {} />
    <cftry>
        <cfset Local.ReturnStruct['item_' & Local.GetParts.itemID].CurrentPrice = Local.GetParts['price' & Arguments.PriceBand] />
         <cfcatch type="any">
             <cflog file="crazy.log" text="GetParts: #currentRow#/#local.getParts.recordCount#, KeyCount: #structKeyCount(local.ReturnStruct)#, keys: #structKeyList(local.ReturnStruct)#" />
         </cfcatch>
    </cftry>
</cfloop>

<cfreturn Local.ReturnStruct />

The idea being that when you encounter an unexpected error, log everything you think that might help you deduce information about where you're at. Bonus: this won't actually throw an error to the user.

PS - one thing I noticed is if your query doesn't return results, Local.ReturnStruct would be undefined. I personally would define it at the start of the function like: <cfset local.returnStruct = {} />

score 0 · Answer 2 · answered Dec 10 '14 at 21:15

I don' think CFLOCK will do the trick here. Try this instead:

<cfloop query="Local.GetParts">
    <cfif !structKeyExists( Local.ReturnStruct, "item_" & Local.GetParts.ItemID )>
        <cfset Local.ReturnStruct['item_' & Local.GetParts.ItemID] = { CurrentPrice = 0 } />
    </cfif>
    <cfset structInsert( Local.ReturnStruct['item_' & Local.GetParts.itemID], CurrentPrice, Local.GetParts['price' & Arguments.PriceBand] )>
</cfloop>

Why use structInsert()?

structInsert(structure, key, value [, allowoverwrite ])

The default value for allowoverwrite is false. Using standard dot notation, you can't get this level of control. Is it possible that your query is returning one or more records with the same value for ItemID? This would also set the key CurrentPrice with a default value.

score 0 · Answer 3 · answered Dec 11 '14 at 00:24

I would try modifying this line:

<cfset Local.ReturnStruct['item_' & Local.GetParts.itemID].CurrentPrice = Local.GetParts['price' & Arguments.PriceBand] />

To:

<cfset Local.ReturnStruct['item_' & Local.GetParts.itemID] = {
    CurrentPrice = Local.GetParts['price' & Arguments.PriceBand]
}>

It will ask CF to do less magic for you (i.e. create an empty struct with key CurrentPrice).

Possible race conditions when creating and updating a struct in the same request - coldfusion

3 Answers3

Linked