tracker issue : CF-4202301

select a category, or use search below
(searches all categories and all time range)
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: 13.0

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