Synchronization service logfiles

Log files in general

When the service starts, the two log files are created; ciSync.log and the ciSync_Proxy.log. They are both created in %ProgramFiles%\CapaInstaller\Logs\Services. If any of the two files should happen to exist beforehand, they a renamed (a timestamp is added to the filename) and moved into the \History subdirectory.

The log file is, under normal circumstances, divided into three columns The first column is a timestamp down to the millisecond. It serves two purposes; First of all, it describes the exact time an event took place, which can be very useful when comparing two or more logs from different applications. Secondly, it gives a good indication of the time spent in between events, i.e different lines. This can often help in pinpointing problems.

The second column serves as a kind of header. Two similar events would have the same heading and that will make it easier to compare events. The second column is also special because related lined often are marked as such by indentation of the latter lines.

The third column mainly contains the results of what was written in the second column. This graphical buildup is intended to give a good overview of the content of the whole log file. If an error occurs when the error is written across the second and third columns. In that way, the 'cleanness' of the log file is broken, and the attention of the reader is immediately caught.

Be advised

eThe ciSync log file will grow all the time the service is running. When the size of the log file reaches 5MB, it is split. This means that a note, that the file was split, is written to the log, and it is then moved into the \History directory along with the other files. A new log file is created with a header stating that it is the continuation of the newly split file (complete with the new 'history-file name')

Cleaning up the log directory

Primarily, log files older than 30 days are uninteresting, and therefore they are deleted. Depending on the size of the installation, the number of servers, and the number of software packages and OS images, the logging that the service produces will vary. For this reason, there will be no more that 20 ciSync.log and 20 ciSync_Proxy.log files in the \History directory. If you have had an error for more that one month ago Once every 24 hours the \History directory is cleaned up.

Raising log events

If a child server connects to its parent server via a public URL, then it is very likely because there is a firewall between them. (that was a general idea when designing it anyway). Since the child server is unlikely to be placed outside (in the cold) it is probably behind a firewall as well. While we have means to deal with firewalls, so that a child server can approach its parent, there is no guarantee that a parent server or a person sitting by the parent server can connect to the child server. This makes it very difficult to watch the log files being produced by the child server.

Therefore the ciSync service will when connected to its parent on a public URL, relay all the lines written to the ciSync.log in real-time over the HTTP/HTTPS connection. At the parent server end of this mechanism a subdirectory named by the child's FQDN I created. In that directory the lines are written to a file called ciSync_Child_<FQDN>.log. The directory is managed with its own \History directory. As noted earlier, this only happens where the child server is connected to the parent server by the Public URL. However, this mechanism can bed forced upon a child server by the command line argument /raiselogevents. For more details about using command-line arguments, click here.

ciSync.log

ciSync.log
2011-10-17 07:45:37:561 - Application    : CapaInstaller Synchronization Service, version 4.2.3168.0, File date: 14-10-2011 13:19:51
2011-10-17 07:45:37:565 - Computer       : DEVTBS.capasystems.com
2011-10-17 07:45:37:640 - Operating sys  : Microsoft Windows 7 Enterprise, version 6.1.7601.65536 (64 bit)
2011-10-17 07:45:37:712 - User Account   : Nt Authority\System
2011-10-17 07:45:37:713 - Process ID     : 3560
2011-10-17 07:45:37:714 - Free memory    : Physical: 2.021 of 12.286 MB (16,5%). Virtual: 8.388.061 of 8.388.608 MB (100,0%)
2011-10-17 07:45:37:750 - Network state  : Connected

2011-10-17 07:45:37:901 - Startup delay  : |...25%...50%...75%..100%|
2011-10-17 07:45:42:951 - Settings       : Loading C:\Program Files\CapaInstaller\Services\Synchronization\ciSync Settings.xml
2011-10-17 07:45:42:963 - Command line   : /startupdelay=5
2011-10-17 07:45:42:965 -   Read from    : registry
2011-10-17 07:45:42:968 - Debug mode     : False
2011-10-17 07:45:45:036 - SQL server     : srvsql.capasystems.com\dev
2011-10-17 07:45:45:037 -   Database     : cms_TBS
2011-10-17 07:45:45:039 -   Auth.        : WCF
2011-10-17 07:45:45:040 -   Internal url : http://devtbs.CapaSystems.com:8036
2011-10-17 07:45:45:041 -   Public url   : https://devtbs.CapaSystems.com:8037
2011-10-17 07:45:49:451 -   Connected    : http://devtbs.CapaSystems.com:8036/dalwcf
2011-10-17 07:45:49:553 - Service ID     : 8
2011-10-17 07:45:49:566 - Service GUID   : 3796af0b-c034-495d-94ad-8b36e2588df8
2011-10-17 07:45:49:634 - Server role    : f5e33bd7-39a0-4f6b-8a51-150dcd28fef4: CMS Server (devtbs)
2011-10-17 07:45:49:718 - Firewall ports : http port 8036, https port 8037
2011-10-17 07:45:49:903 -   Public       : Port 8036 is open and enabled
2011-10-17 07:45:50:066 -   Domain       : Port 8036 is open and enabled
2011-10-17 07:45:50:224 -   Private      : Port 8036 is open and enabled
2011-10-17 07:45:50:404 -   Public       : Port 8037 is open and enabled
2011-10-17 07:45:50:570 -   Domain       : Port 8037 is open and enabled
2011-10-17 07:45:50:735 -   Private      : Port 8037 is open and enabled
2011-10-17 07:45:50:773 - Certificate
2011-10-17 07:45:50:774 -   Name         : *.capasystems.com
2011-10-17 07:45:50:776 -   Store        : Personal
2011-10-17 07:45:50:777 -   Thumbprint   : D34bec93f092c728643435b1655bb99ad58ab4d8
2011-10-17 07:45:50:911 -   Binding      : Certificate already bound to port 8037
2011-10-17 07:45:50:912 - Servicehosts
2011-10-17 07:45:50:948 -   Opened       : http://devtbs.capasystems.com:8036/general
2011-10-17 07:45:50:955 -   Opened       : http://devtbs.capasystems.com:8036/transfer
2011-10-17 07:45:50:966 -   Opened       : https://devtbs.capasystems.com:8037/general
2011-10-17 07:45:50:970 -   Opened       : https://devtbs.capasystems.com:8037/transfer
2011-10-17 07:45:50:994 - Loopback test
2011-10-17 07:45:51:055 -   Http url     : Succeded: http://devtbs.capasystems.com:8036
2011-10-17 07:45:51:079 -   Https url    : Succeded: https://devtbs.capasystems.com:8037
2011-10-17 07:45:53:114 -   Public url   : Failed: https://devtbs2.capasystems.com:8037 (It is not uncommon that a public url is inaccessible from the inside of the firewall)
2011-10-17 07:45:53:279 - Parent server
2011-10-17 07:45:53:299 -   Connecting   : http://ws09.capasystems.com:8036 (Internal url)
2011-10-17 07:45:53:315 -     Connected  : http://ws09.capasystems.com:8036/general
2011-10-17 07:45:53:320 -     Connected  : http://ws09.capasystems.com:8036/transfer
2011-10-17 07:45:53:447 - Auto update
2011-10-17 07:45:53:459 -   Equal        : ciSync on ws09.capasystems.com is equal to current version
2011-10-17 07:45:53:484 - Timers
2011-10-17 07:45:53:485 -   Cleanup      : 24 hours
2011-10-17 07:45:53:486 -   Schedule     : 10 seconds
2011-10-17 07:45:53:489 -   SyncCom      : 1 minute
2011-10-17 07:45:53:490 -   Application  : 1 minute
2011-10-17 07:45:53:491 -   System       : 1 minute
2011-10-17 07:45:53:492 -   Parent       : 10 seconds
2011-10-17 07:45:53:493 -   Heartbeat    : 10 seconds
2011-10-17 07:45:53:559 - Initialized
2011-10-17 07:45:53:560