tracker issue | What iT iS dESign studios

Title:

[ANeff] Bug for: NULL exceptions

| View in Tracker

Status/Resolution/Reason: Closed/Withdrawn/CannotReproduce

Reporter/Name(from Bugbase): Aaron Neff / ()

Created: 05/06/2018

Components: Logging

Versions: 2018

Failure Type: Others

Found In Build/Fixed In Build: 2018.0.01.308605 (PreRelease) /

Priority/Frequency: Normal /

Locale/System: / Windows 10 64 bit

Vote Count: 0

Issue: NULL exceptions

In coldfusion-out.log, I noticed 1,520 rows of this:

Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\accessmanager.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\administrator.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\Application.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\base.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\collections.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\customtags\l10n.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\customtags\resources\adminapi_en.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\customtags\resources\adminapi_ja.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\datasource.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\debugging.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\document.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\eventgateway.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\extensions.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\flex.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\mail.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\office.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\runtime.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\scheduler.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\security.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\serverinstance.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\servermonitoring.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\websocket.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_datasource\formatjdbcurl.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_datasource\getaccessdefaultsfromregistry.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_datasource\geturldefaults.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_datasource\setdsn.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_datasource\setmsaccessregistry.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_datasource\setsldatasource.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\Application.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\archivewrapper.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\CachingWrapper.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\chartingsettingswrapper.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\debugparamswrapper.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\dswrapper.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\gatewaywrapper.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\jvmsettingswrapper.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\loggingparamswrapper.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\mailsettingswrapper.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\mappingswrapper.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\memoryvarswrapper.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\schedulerwrapper.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\servermanager.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\serversettingswrapper.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi_servermanager\tuningparamswrapper.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\administrator\aboutcf.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\administrator\ajaxtree\jqueryFileTree.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\administrator\analyzer\featureview.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\administrator\analyzer\featureviewloader.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\administrator\analyzer\featureviewtop.cfm
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\administrator\analyzer\fileview.cfm

etc

etc

It looks like it's listing every descendant file under CFIDE and WEB-INF.

See attached .txt of all 1,520 rows.

Two issues:
1) The "null" isn't helpful
2) Logging a thousand file paths isn't helpful either?

Attachments:

Comments:

Related thread: https://forums.adobeprerelease.com/coldfusionpr/discussion/384/null-messages

Comment by Aaron N.

27694 | May 06, 2018 05:11:43 AM GMT

Aaron, 

We were unable to repro this issue. 
Can you please provide more details around the following,
 * Are you hitting this issue everytime server starts up
 * Was null support enabled before a server restart
 * Any configurations updated on the server 

Comment by Immanuel N.

29006 | May 08, 2018 08:16:04 AM GMT

Aaron, if you could check and confirm, it would be great!

Comment by Vamseekrishna N.

29007 | June 09, 2018 10:35:36 AM GMT

Hi Immanuel and Vamsee,

I'm sorry I did not see your message (Immanuel) because Tracker's email notification system has been broken since October.

I've compared the timestamp of these errors w/ the timestamps of my PR discussions. I see I was testing Aether's null support w/ cfqueryparam's null attribute at the time these errors were logged.

I'll see if I can remember what I was doing and follow-up.

It's really too bad that Tracker's email notification system's been broken! I wish I'd have seen Immanuel's message that same day. Can you please ask the Tracker team to fix email notifications?

Thanks!,
-Aaron

Comment by Aaron N.

29027 | June 13, 2018 07:58:10 AM GMT

To clarify, that was the only time these errors were logged. But, also, that was the only time I was testing cfqueryparam's null attribute. So.. there's an issue.. I just gotta spend time to narrow it down.

Thanks!,
-Aaron

Comment by Aaron N.

29028 | June 13, 2018 08:04:18 AM GMT

Thanks Aaron. We will look at this possibility as well.

Comment by Vamseekrishna N.

29033 | June 13, 2018 02:31:33 PM GMT

Hi Vamsee,

I've confirmed that cfqueryparam's null attribute had nothing to do w/ this issue.

audit.log reveals that I did not even create the DSN I'd used for cfqueryparam testing until 10 minutes _after_ these null messages were logged.

Additionally, IIS's log files reveal I wasn't even running any test scripts when these null messages were logged.

The error messages seem linked to some CF Admin activity. I'm trying to remember what I might've been doing on April 30th at that time... =P

Thanks!,
-Aaron

Comment by Aaron N.

29037 | June 14, 2018 06:54:04 AM GMT

Here are the coldfusion-out.log entries _before_ the null entries:

Apr 29, 2018 22:56:31 PM Information [main] - ColdFusion: application services are now available
04/29 22:56:32 INFO Macromedia Flex Build: 87315.134646
Apr 29, 2018 22:56:33 PM Information [Thread-13] - PDFg service manager http://127.0.0.1:8991/PDFgServlet/ registered.
Apr 29, 2018 23:00:00 PM Information [DefaultQuartzScheduler_Worker-1] - Task default.myTask triggered.
Apr 29, 2018 23:00:00 PM Information [DefaultQuartzScheduler_Worker-1] - Starting HTTP request {URL='http://www.mysite.com', method='get'}
Apr 29, 2018 23:00:00 PM Information [DefaultQuartzScheduler_Worker-1] - HTTP request completed  {Status Code=200 ,Time taken=400 ms}
Apr 29, 2018 23:01:17 PM Information [http-nio-8500-exec-3] - Session rotated successfully.
Apr 30, 2018 00:00:00 AM Information [DefaultQuartzScheduler_Worker-2] - Task default.myTask triggered.
Apr 30, 2018 00:00:00 AM Information [DefaultQuartzScheduler_Worker-2] - Starting HTTP request {URL='http://www.mysite.com', method='get'}
Apr 30, 2018 00:00:00 AM Information [DefaultQuartzScheduler_Worker-2] - HTTP request completed  {Status Code=200 ,Time taken=572 ms}
Apr 30, 2018 00:03:22 AM Information [scheduler-2] - Run Client Storage Purge
Apr 30, 2018 01:00:00 AM Information [DefaultQuartzScheduler_Worker-3] - Task default.myTask triggered.
Apr 30, 2018 01:00:00 AM Information [DefaultQuartzScheduler_Worker-3] - Starting HTTP request {URL='http://www.mysite.com', method='get'}
Apr 30, 2018 01:00:01 AM Information [DefaultQuartzScheduler_Worker-3] - HTTP request completed  {Status Code=200 ,Time taken=1585 ms}
Apr 30, 2018 01:10:22 AM Information [scheduler-0] - Run Client Storage Purge
Apr 30, 2018 01:11:58 AM Information [http-nio-8500-exec-8] - Session rotated successfully.
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\accessmanager.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\administrator.cfc
Apr 30, 2018 01:27:31 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\CFIDE\adminapi\Application.cfm
[etc]

Here are the coldfusion-out.log entries _after the null entries:

[etc]
Apr 30, 2018 01:30:38 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\WEB-INF\exception\java\security\AccessControlException.cfm
Apr 30, 2018 01:30:38 AM Error [http-nio-8500-exec-1] - null C:\ColdFusion2018\cfusion\wwwroot\WEB-INF\exception\udf.cfm
Apr 30, 2018 01:35:58 AM Error [http-nio-8500-exec-6] - '' Can not decode string ""993D057CE43599B7_vckuK29mbH5J6e1coDLg30JosHNidn/h31kaPKGM9O14dwmdGjS1rq kzDh03KckfpVHBhehLLga /BAN2Euzw====="".
Apr 30, 2018 01:36:02 AM Information [http-nio-8500-exec-3] - Session rotated successfully.

And audit.log has these entries for around that same time:

"Information","http-nio-8500-exec-7","04/29/18","22:51:06","CFADMIN","User admin logged in."
"Information","http-nio-8500-exec-3","04/29/18","23:01:17","CFADMIN","User admin logged in."
"Information","http-nio-8500-exec-8","04/30/18","01:11:58","CFADMIN","User admin logged in."
"Information","http-nio-8500-exec-3","04/30/18","01:36:02","CFADMIN","User admin logged in."

I see the next CF restart was at 01:49:00

Note: Those null messages came in 3 batches. 1st batch (at 01:27:xx) had [http-nio-8500-exec-1], 2nd batch (at 01:28:xx) had [http-nio-8500-exec-6] and 3rd batch (at 01:30:xx) had [http-nio-8500-exec-1] again.

Possibly 2 threads competing for something? Dunno. *shrug* I don't have any clue as to what I was doing in CF Admin that triggered those null messages. If this happens again I'll enable the Tomcat Access logs and see if I can determine what CF Admin activity it was.

I guess just close this as cannot reproduce for now? I'll follow-up if this happens again :) I've spent a fair amount of time researching this, and I don't think I can be of more help until this happens again - if it ever does.

Note: This occurred when CF Admin had the bug wherein session timeout is always 20min after sign-in instead of 20min of idle time. If you notice, I'd logged-in to CF Admin at 01:11, so 20min after would've been 01:31. And these null errors occurred w/in the last 90 seconds of that 20min window. Whatever that may mean =)

Thanks!,
-Aaron

Comment by Aaron N.

29038 | June 14, 2018 07:17:52 AM GMT

Thanks Aaron. We will close this for now and will reopen this in case the issue occurs again.

Comment by Vamseekrishna N.

29039 | June 14, 2018 08:23:34 AM GMT

tracker issue : CF-4202301

[ANeff] Bug for: NULL exceptions