tracker issue : CF-4206279

select a category, or use search below
(searches all categories and all time range)
Title:

local var is `null` right after being assigned the result of a function that can't return `null` in theory

| View in Tracker

Status/Resolution/Reason: Open//

Reporter/Name(from Bugbase): Alexandre P. / ()

Created: 12/06/2019

Components: Language

Versions: 2018

Failure Type: Crash

Found In Build/Fixed In Build: 2018,0,05,315699 /

Priority/Frequency: Normal / Not Reproducible

Locale/System: / Win 2016

Vote Count: 0

Problem Description: 

Local function variable is `null` right after being assigned the result of a function that can't return `null` in theory. The issue happens once a day at most: the first time the specific process is ran. This error never occurred in ColdFusion 11 and started to occur right after we migrated to ColdFusion 2018. 

With the following code...

LetterTemplateRepository.cfc:

	<cffunction name="allAvailableGiven" access="public" returntype="LetterTemplate[]">
		<cfargument name="officer" type="Officer" required="yes">
		<cfargument name="oqdMainFileRequestTypeSelection" type="RequestTypeSelection" required="no">
		
		<cfset var availableTemplates = []>
		
		<cfloop collection="#templates#" item="local.typeCode">
			<cfset var template = templates[typeCode]>
			
			<cfif template.getAvailabilitySpec().isSatisfiedBy(argumentcollection = arguments)>
				<cfset arrayAppend(availableTemplates, template)>
			</cfif>
		</cfloop>
		
		<cfscript>
			arraySort(availableTemplates, function (a, b) {
				return compare(a.getName(), b.getName());
			});
		</cfscript>
		
		<!--- TODO: Remove that null check, only there to try debug error #304529 --->
		<cfif isNull(availableTemplates)>
			<cfthrow message="null would be returned: that shouldn't ever happen!">
		</cfif>
		
		<cfreturn availableTemplates>
	</cffunction>

LetterService.cfc:

       <cffunction name="allLetterTemplatesAvailableGiven" access="public" returntype="LetterTemplate[]">
		<cfargument name="officer" type="Officer" required="yes">
		<cfargument name="oqdMainFileRequestTypeSelection" type="RequestTypeSelection" required="no">
		
		<cfset var templates = letterTemplateRepository.allAvailableGiven(argumentcollection = arguments)>
		
		<!--- TODO: Remove that null check, only there to try debug error #304529 --->
		<cfif isNull(templates)>
			<cfthrow message="null returned by repository: that shouldn't ever happen!">
		</cfif>
		
		<cfreturn templates>
	</cffunction>

The custom exception "null returned by repository: that shouldn't ever happen!" is thrown and I don't see how that's possible, especially when there's a null check right before returning the value from `allAvailableGiven` which doesn't evaluate to true and that `allAvailableGiven` always returns an array.

Please note that `LetterService.allLetterTemplatesAvailableGiven` is called from a module invoked with cfmodule as you can see in the stacktrace below.

PARTIAL STACKTRACE (JSON):
            [{
			"ClassLoaderName": null,
			"FileName": "ThrowTag.java",
			"ModuleVersion": null,
			"NativeMethod": false,
			"ClassName": "coldfusion.tagext.lang.ThrowTag",
			"LineNumber": 87,
			"MethodName": "doStartTag",
			"ModuleName": null
		}, {
			"ClassLoaderName": null,
			"FileName": "CfJspPage.java",
			"ModuleVersion": null,
			"NativeMethod": false,
			"ClassName": "coldfusion.runtime.CfJspPage",
			"LineNumber": 4276,
			"MethodName": "_emptyTag",
			"ModuleName": null
		}, {
			"ClassLoaderName": null,
			"FileName": "D:\\inetpub\\wwwroot\\CHARITIES\\CTS\\cfc\\letter\\LetterService.cfc",
			"ModuleVersion": null,
			"NativeMethod": false,
			"ClassName": "cfLetterService2ecfc1715661650$funcALLLETTERTEMPLATESAVAILABLEGIVEN",
			"LineNumber": 75,
			"MethodName": "runFunction",
			"ModuleName": null
		}, {
			"ClassLoaderName": null,
			"FileName": "UDFMethod.java",
			"ModuleVersion": null,
			"NativeMethod": false,
			"ClassName": "coldfusion.runtime.UDFMethod",
			"LineNumber": 553,
			"MethodName": "invoke",
			"ModuleName": null
		}, {
			"ClassLoaderName": null,
			"FileName": "UDFMethod.java",
			"ModuleVersion": null,
			"NativeMethod": false,
			"ClassName": "coldfusion.runtime.UDFMethod$ReturnTypeFilter",
			"LineNumber": 484,
			"MethodName": "invoke",
			"ModuleName": null
		}, {
			"ClassLoaderName": null,
			"FileName": "UDFMethod.java",
			"ModuleVersion": null,
			"NativeMethod": false,
			"ClassName": "coldfusion.runtime.UDFMethod$ArgumentCollectionFilter",
			"LineNumber": 447,
			"MethodName": "invoke",
			"ModuleName": null
		}, {
			"ClassLoaderName": null,
			"FileName": "FunctionAccessFilter.java",
			"ModuleVersion": null,
			"NativeMethod": false,
			"ClassName": "coldfusion.filter.FunctionAccessFilter",
			"LineNumber": 95,
			"MethodName": "invoke",
			"ModuleName": null
		}, {
			"ClassLoaderName": null,
			"FileName": "UDFMethod.java",
			"ModuleVersion": null,
			"NativeMethod": false,
			"ClassName": "coldfusion.runtime.UDFMethod",
			"LineNumber": 398,
			"MethodName": "runFilterChain",
			"ModuleName": null
		}, {
			"ClassLoaderName": null,
			"FileName": "UDFMethod.java",
			"ModuleVersion": null,
			"NativeMethod": false,
			"ClassName": "coldfusion.runtime.UDFMethod",
			"LineNumber": 371,
			"MethodName": "runFilterChain",
			"ModuleName": null
		}, {
			"ClassLoaderName": null,
			"FileName": "UDFMethod.java",
			"ModuleVersion": null,
			"NativeMethod": false,
			"ClassName": "coldfusion.runtime.UDFMethod",
			"LineNumber": 597,
			"MethodName": "invoke",
			"ModuleName": null
		}, {
			"ClassLoaderName": null,
			"FileName": "TemplateProxy.java",
			"ModuleVersion": null,
			"NativeMethod": false,
			"ClassName": "coldfusion.runtime.TemplateProxy",
			"LineNumber": 837,
			"MethodName": "invoke",
			"ModuleName": null
		}, {
			"ClassLoaderName": null,
			"FileName": "TemplateProxy.java",
			"ModuleVersion": null,
			"NativeMethod": false,
			"ClassName": "coldfusion.runtime.TemplateProxy",
			"LineNumber": 643,
			"MethodName": "invoke",
			"ModuleName": null
		}, {
			"ClassLoaderName": null,
			"FileName": "CfJspPage.java",
			"ModuleVersion": null,
			"NativeMethod": false,
			"ClassName": "coldfusion.runtime.CfJspPage",
			"LineNumber": 3506,
			"MethodName": "_invoke",
			"ModuleName": null
		}, {
			"ClassLoaderName": null,
			"FileName": "CfJspPage.java",
			"ModuleVersion": null,
			"NativeMethod": false,
			"ClassName": "coldfusion.runtime.CfJspPage",
			"LineNumber": 3481,
			"MethodName": "_invoke",
			"ModuleName": null
		}, {
			"ClassLoaderName": null,
			"FileName": "D:\\inetpub\\wwwroot\\CHARITIES\\CTS\\modules\\new_acknowledgement_letter.cfm",
			"ModuleVersion": null,
			"NativeMethod": false,
			"ClassName": "cfnew_acknowledgement_letter2ecfm885677734",
			"LineNumber": 17,
			"MethodName": "runPage",
			"ModuleName": null
		}]

Steps to Reproduce:

Unfortunately, I've been unable to reproduce the problem on demand no matter what I've tried. 

Here's the gist of what I've explored in the same environment the error occured in:

- Issue all the exact same HTTP requests that preceded the error in the same order and the same user for a given day within a ~5sec range of the request causing the error
- Run the problematic process concurrently 100 times (no failures)

I ran the above test cases in the following contexts:

- After the application was already started
- After calling applicationStop()
- After clearing the components & template caches
- With a different application name & location

None of the tests failed so there's no way for me to produce a minimal test case, but while I can't explain nor demonstrate how the problem occurs it has to be a ColdFusion bug, because it boils down to `var a = b()`, where b can't return `null` in theory, but `a` will still end up being null.

Actual Result:

The local variable `templates` in `LetterService.allLetterTemplatesAvailableGiven` is `null` after being assigned a value that can theorically not be null.

Expected Result:

The `templates` variable should be an array.

Any Workarounds:

Haven't tried/found any workaround. I'm thinking of perhaps re-trying the variable assignement a few times if the variable is null, but the fact I can't reproduce the problem on demand at all makes it very difficult to debug.

Next debugging steps:

I'm thinking of making all variables `final` in these functions to see if it changes anything or try to put an assignment retry loop in case the variable is found to be null. I'll also put a scheduled task to invoke the process early in the morning every day see if it always fails, but other than that I'm starting to run out of ideas...

Attachments:

Comments:

Please note that I've discovered the CF-4205911 bug because of this one, given that all functions were annotated with `returntype="LetterTemplate[]"`, but `null` still managed to find it's way up the chain.
Comment by Alexandre P.
31932 | December 06, 2019 07:14:10 PM GMT
Adding a retry loop allows to work around the problem for now, but it doesn`t make any sense. All services are stateless and immutable. <cfloop condition="isNull(templates) and ++i lte 5"> <cfset sleep(100)> <cfset templates = letterTemplateRepository.allAvailableGiven(argumentcollection = arguments)> </cfloop>
Comment by Alexandre P.
31943 | December 10, 2019 04:18:45 PM GMT