Gotcha: vCloud Stops Logging After 5.5.x to 5.6.x SP Upgrade

!(/images/2015/10/log-jam.jpg)This is something to look out for if you are upgrading from vCloud Director 5.5.x to 5.6.x SP and if you have altered the syslog settings of your cells…This little gotcha nearly caused a couple of our production vCloud Director Cells to fail due to insufficient storage on the their file systems. Prior to our alerting warning us about an low disk space alert on the cells I couldn’t remember any issues with disk space and vCD Guest Systems since I first started with vCD in 2011…as is normally the case storage space is generally consumed by logs that don’t rotate or grow unexpectedly…so I went looking in the vCD Logs directory under /opt/vmware/vcloud-director/logsAnd sure enough I found that the (http://www.mikelaverick.com/2013/01/part-43-my-vcloud-journey-journal-monitoring-vcloud-director-components-syslog-firewalls/) had ballooned to 17GB and had not rotated since the date of the upgrade to 5.6.4

-
# ls -la | grep jmx
-rw------- 1 vcloud vcloud 17631159544 Oct 7 08:57 jmx.log
-rw------- 1 vcloud vcloud 23882585 Jul 23 03:50 jmx.log.1
-rw------- 1 vcloud vcloud 23838783 Jul 22 18:50 jmx.log.10
-rw------- 1 vcloud vcloud 23882652 Jul 23 02:50 jmx.log.2
-rw------- 1 vcloud vcloud 23882134 Jul 23 01:50 jmx.log.3
-rw------- 1 vcloud vcloud 23882510 Jul 23 00:50 jmx.log.4
-rw------- 1 vcloud vcloud 23881609 Jul 22 23:50 jmx.log.5
-rw------- 1 vcloud vcloud 23869479 Jul 22 22:50 jmx.log.6
-rw------- 1 vcloud vcloud 23857176 Jul 22 21:50 jmx.log.7
-rw------- 1 vcloud vcloud 23846127 Jul 22 20:50 jmx.log.8
-rw------- 1 vcloud vcloud 23845626 Jul 22 19:50 jmx.log.9

After getting a support ticket raised it was found that the vCD container debug logs where not even rolling…in fact there was no debug log activity on the cells (except for the cell.log) since the upgrade. Looking at the log4j.properties file under /opt/vmware/vcloud-director/etc it looked like everything was in order and that the logs should be rotating after the file hit 20MB however it was obvious that this wasn’t happening.

- # appender for JMX Dump logs
# Comment/Uncomment to start/stop creating JMX data in separate log file.
log4j.logger.com.vmware.vcloud.monitoring.jmx=INFO, jmx
log4j.additivity.com.vmware.vcloud.monitoring.jmx=false
log4j.appender.jmx=org.apache.log4j.RollingFileAppender
log4j.appender.jmx.File=logs/jmx.log
log4j.appender.jmx.MaxFileSize=20000KB
log4j.appender.jmx.MaxBackupIndex=10
log4j.appender.jmx.layout=com.vmware.vcloud.logging.CustomPatternLayout
log4j.appender.jmx.layout.ConversionPattern=%d{ISO8601} | %-8.8p | %-25.50t | %-30.50c{1} | %m%n
# set the following value to OFF to turn off JMX dump.
log4j.appender.jmx.threshold=INFO
# end JMX dump section

Working with VMware Support we came across (http://pubs.vmware.com/vcd-56/index.jsp#com.vmware.vcloud.install.doc_56/GUID-CEF834DA-1FF5-4819-9D24-88DE6F005C78.html?resultof=%2522%2572%2570%256d%256e%2565%2577%2522%2520) section of the Install and Upgrade guide where it talks about

(Optional) Update logging properties.

After an upgrade, new logging properties are written to the file /opt/vmware/vcloud-director/etc/log4j.properties.rpmnew

Option	Action
If you did not change existing logging properties	Copy this file to /opt/vmware/vcloud-director/etc/log4j.properties.
If you changed logging properties	Merge /opt/vmware/vcloud-director/etc/log4j.properties.rpmnew file with the existing /opt/vmware/vcloud-director/etc/log4j.properties. Merging these files preserves your changes.

Sure enough our log4j.properties file had been altered to add some custom logging formats and targets and in each of the directories there was the log4j.properties.rpmnew file. That is to say there are new logging properties that come with vCD 5.6.x SP and if you had altered the file prior to upgrade those additions meant the logging broke. As suggested above all that needed to be done was to merge both files, or append the customer entries to the bottom of the .rpmnew version and save that as log4j.properties and restart the cells. Once I did this the debug logs started to flow again and the jmx.log file was rotated allowing me to shrink/delete the file consuming the storage. References: http://pubs.vmware.com/vcd-56/index.jsp#com.vmware.vcloud.install.doc_56/GUID-CEF834DA-1FF5-4819-9D24-88DE6F005C78.html?resultof=%2522%2572%2570%256d%256e%2565%2577%2522%2520