tracker issue : CF-4201413

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

At startup of an instance, Server Monitoring ALWAYS starts irrespective of whether or not Monitoring is disabled. Result: unexpected exceptions and 100% CPU memory use

| View in Tracker

Status/Resolution/Reason: Closed/Withdrawn/CannotReproduce

Reporter/Name(from Bugbase): A. Bakia / A. Bakia ()

Created: 03/05/2018

Components: Performance, Server Monitoring

Versions: 2016,11.0

Failure Type: Others

Found In Build/Fixed In Build: 11,0,13,303668 /

Priority/Frequency: Normal / Unknown

Locale/System: English / Win 2012 Server x64

Vote Count: 0

Problem Description:
 Suppose that Server Monitoring is disabled for your instance. For example, in the ColdFusion Administrator or, alternatively, in the file /lib/neo-monitoring.xml by means of the settings

<var name="monitoringenabled">
 <boolean value="false"/>
 </var>
 <var name="ismonitoringserverenabled">
 <boolean value="false"/>
 </var>

However, when you start up the instance, Server Monitoring ALWAYS starts, too, wiithin seconds. Irrespective of whether or not you had disabled Monitoring.

You can see this in /logs/monitor.log. During startup, a line similar to the following is written to that log file:

"Information","localhost-startStop-1","05/28/15","03:40:49",,"Starting Monitoring Server on port 55475."

It appears that ColdFusion looks up the available port at random. Occassionally, the result is an error, similar to the following (in /logs/monitor.log):

"Information","localhost-startStop-1","02/22/18","03:34:09",,"Starting Monitoring Server on port 63651."
 "Error","localhost-startStop-1","02/22/18","03:34:30",,"Unable to establish loopback connection"

This error always initiates a chain reaction of errors and exceptions, such as:

"Unable to establish loopback connection" >> "Could not initialize class coldfusion.runtime.SessionTracker" >> "The Monitoring service is not available."

See attached excerpts from monitor.log, coldfusion-out.log and coldfusion-error.log

Invariably, the instance's CPU usage increases steadily towards 100% of total CPU. This forces us to restart the instance.

Steps to Reproduce:

1. Create a cluster of several ColdFusion instances. Disable Server Monitoring in the ColdFusion Administrator or, alternatively, in the file /lib/neo-monitoring.xml

2. Start them up or program them to start up as Windows services at the same time every day.

3. Inspect monitor.log daily.

Actual Result:
 You will see that the monitoring service starts whenever an instance starts up. Occasionally, this results in the error "Unable to establish loopback connection". This error kicks off a chain of further errors and exceptions. Within hours, it leads to 100% CPU usage, bringing the entire server to a standstill.

Expected Result:
 If Server Monitoring is disabled for a ColdFusion instance, then the Monitoring service SHOULD NOT start during the instance's startup.

Any Workarounds:
 Restart the affected instance.

See also:
 [https://forums.adobe.com/thread/2428175]
 [https://tracker.adobe.com/#/view/CF-3837342]

Attachments:

  1. March 05, 2018 00:00:00: Excerpt from coldfusion-error-log.txt
  2. March 05, 2018 00:00:00: Excerpt from coldfusion-out-log.txt
  3. March 05, 2018 00:00:00: Excerpt from monitor-log.txt
  4. March 05, 2018 00:00:00: neo-monitoring-xml.docx

Comments:

Typo: please read "Disable" in place of "Distable"
Comment by A. B.
79 | March 05, 2018 11:22:00 AM GMT
Typo: please read "errors" in place of "derrors"
Comment by A. B.
80 | March 05, 2018 04:23:31 PM GMT
did not observe the error reported by the user. If the port is occupied, it picks up a random port. throughout the time CF is starting the CPU usage (on a 4 core mc) hovers b/w 25 and 50%.  logged in cmd console: May 10, 2018 17:35:08 PM Information [localhost-startStop-1] - Starting Monitoring... May 10, 2018 5:35:10 PM org.eclipse.jetty.util.log.Log initialized INFO: Logging initialized @38264ms May 10, 2018 17:35:10 PM Error [localhost-startStop-1] - Address already in use: JVM_Bind May 10, 2018 17:35:11 PM Information [localhost-startStop-1] - Starting Monitoring Server on port 65261. May 10, 2018 5:35:11 PM org.eclipse.jetty.server.Server doStart INFO: jetty-9.3.6.v20151106 May 10, 2018 5:35:11 PM org.eclipse.jetty.server.handler.ContextHandler doStart INFO: Started o.e.j.s.ServletContextHandler@4d4da39d\{/,null,AVAILABLE} May 10, 2018 5:35:11 PM org.eclipse.jetty.server.AbstractConnector doStart INFO: Started ServerConnector@2e220543{HTTP/1.1,[http/1.1]} {0.0.0.0:65261} May 10, 2018 5:35:11 PM org.eclipse.jetty.server.Server doStart INFO: Started @39615ms May 10, 2018 17:35:11 PM Information [localhost-startStop-1] - Starting WebSocket...   corresponding log in exception.log: "Error","localhost-startStop-1","05/10/18","17:35:10",,"Address already in use: JVM_Bind" java.net.BindException: Address already in use: JVM_Bind at java.net.DualStackPlainSocketImpl.bind0(Native Method) at java.net.DualStackPlainSocketImpl.socketBind(DualStackPlainSocketImpl.java:106) at java.net.AbstractPlainSocketImpl.bind(AbstractPlainSocketImpl.java:387) at java.net.PlainSocketImpl.bind(PlainSocketImpl.java:190) at java.net.ServerSocket.bind(ServerSocket.java:375) at java.net.ServerSocket.<init>(ServerSocket.java:237) at java.net.ServerSocket.<init>(ServerSocket.java:128) at coldfusion.monitor.jetty.server.MonitoringServer.portCheck(MonitoringServer.java:237)  
Comment by Piyush K.
30064 | May 10, 2018 12:11:21 PM GMT
closing this based on the last two comments. looks like this was not reproducible. We can revisit this if the reported returns with additional input.
Comment by Piyush K.
30498 | March 13, 2019 05:17:42 PM GMT