Logging

servedat produces a log of individual transactions, errors, and state changes.  This information is vital to diagnosing problems, and can also be used to generate usage statistics and inform other processes of the state of transactions.

Logging output normally consists of UTF-8 encoded character lines in the format described below.  Enabling Debugging may cause non-UTF-8 data to be written to the logs.  See the Unicode section for more information about ExpeDat character encoding.

Log Locations

When servedat is run from a terminal or command shell, logs are sent to stderr by default.

Windows: If servedat is run as a Windows Service, it will default to writing diagnostics to
"C:\Documents and Settings\All Users\Application Data\DEI\servedat.log" on Windows XP or
"C:\ProgramData\DEI\servedat.log" on Vista, Windows 7, or later.
You can use the enclosed "Shortcut to servedat.log" link to open the log file, if it exists.

All Others: If servedat is run as a root daemon in unix it will default to writing diagnostic output to the file /var/log/servedat.log or /var/adm/servedat.log, depending on the platform.

If you wish to redirect logs to a file or pipe, use the -l command line option or the LogFile configuration variable.  The argument can be a pathname, or the number "1" to specify stdout, or the number "2" to specify stderr.  For example, the following commands both redirect output to the file "/tmp/servedat.log".

# servedat -l 1 >> /tmp/servedat.log C 20130711 14:40:01.522 servedat 1.15.0 "July 2013" DEI [38412] C 20130711 14:40:01.522 Switching logs to <stdout> # servedat -l /tmp/servedat.log C 20130711 14:40:28.843 servedat 1.15.0 "July 2013" DEI [38415] C 20130711 14:40:28.843 Switching logs to /tmp/servedat.log

The -l and LogFile options are processed as soon as they are found, so multiple declarations may cause the logfile to change multiple times during startup.  Since command line options are processed first and have priority over configuration files, the best practice is to use "-l" to send logging output to your intended destination as soon as possible.

Line Format

Each line of diagnostic output takes the following form:

[Type] [Date] [Time] [Message]

Type A single character denoting the type of message:
C Comment or Configuration note.
D Diagnostic output.
E General server error.
F The final disposition of an action.  There will be exactly one of these per action.
I Initiation of an action which has not yet completed.  There will be at most one of these per action.
M Message from one of the MTP libraries.
P A progress update for an ongoing transaction.  These occur at intervals of LogProgress seconds.
S A status update showing server load and transaction counts.  These occur at intervals of LogStatus seconds while the server is active.  See the Monitoring section for details.
T Message from one of the application toolkit libraries.
V Version and process id, displayed once at each startup.
W Warning or detailed error regarding an action in progress.
Date Eight characters giving the year, month, and day as YYYYMMDD
Time Twelve characters giving the hour, minute, seconds, and milliseconds in localtime as HH:MM:SS.mmm
Message The message format will vary for C, D, E, M, and WI, P, F, and S type messages conform to the format below.

Particular attention should be paid to all E, M, T, and W messages as these may indicate improper operation.

Initiation, Progress, Final, and Status log messages (I, P F, and S) share the same initial format:

DocID SEND|GET Client User Encrypt "Path" "Action"

DocID An 8 character hexidecimal transaction identifier.  No two transactions can have the same DocID at the same time, and IDs will not be reused for a long time.
SEND|GET Incoming documents are be labeled "SEND".  Outgoing documents and most actions are labeled "GET".
Client The IP address and UDP port number of the client application, separated by a colon.
User The username used for authentication, or "-" if none was provided.
Encrypt The content encryption method, or "-" if none was used.
Path The pathname of the local file target.  This may be absolute or relative to the applicable home directory.
Action For packaging, action, or handler requests, the specifier used to process the document will appear here.  File maintenance actions, will be indicated by a "*", such as "*dl" for a deletion action.  Compressed data transfers are indicated by "zli".
P lines occur at intervals of LogProgress seconds during each transaction and have additional fields in the form:   Progress Size "Duration (Speed)" Load
Progress The amount of network data transferred up to this point.
Size The full size of the data, if this is known.  Transactions involving compression, streaming, packaging, or actions may set this field to 0.
Duration The time elapsed so far.
Speed The average network speed since the last update.
Load The current server load.
F lines occur at the end of each transaction and have additional fields in the form:   Transfer (Class,Error) "Comment"
Transfer The amount of network data transferred up to the point of the log.  If an error has occurred, this value may only be approximate or it may be given as "-" if a value is not known.  Note that if a transfer is compressed or resumed, the amount here may be much less than the size of the file on disk.
Class Zero for successes, otherwise an MTP/IP error class, indicating the source of the error.  Most errors will be class "-4", indicating that servedat itself is reporting the error.
Error Zero for successes, otherwise an MTP/IP error code, indicating the type of error.  See DEI Tech Note 0013 for information about error classes and codes.
Comment A human readable string describing the result.  On success it will show the time elapsed and overall transfer rate.  On failure, it will show an error message.
S lines occur at intervals of LogStatus seconds while the server is active and have additional comma separated fields labeled as follows:
Load Current: The current number of active transactions.
MaxConfig: The peak load since the last configuration reload.
MaxStart: The peak load since the last restart.
TotalStart: The total number of transactions attempted since startup.
Errors: The number of server errors since startup.
If this number is non-zero, look for 'E' logs and correct any problems.  Approximately equals the number of 'E' log entries.
Failures: The number of transactions which started, but then failed before completion.
Warnings: The number of server or transaction warnings issued since startup.  Approximately equals the number of 'W' log entries.
Denials: The number of transactions which were rejected due to authentication or other configuration issues.

Following is a sample of servedat log output illustrating the format:

V 20130711 14:47:03.371 servedat 1.15.0 "July 2013" DEI [38513] (1771) C 20130711 14:47:03.372 (C)2013 Data Expedition, Inc.(R) US Pat. 7158479,7313627,7404003,7630315,8014289 C 20130711 14:47:03.372 servedat - 1.15.0 July 2013 - DEI, DOC-1.15.0 MTP-osx-3.15.11 810 C 20130711 14:47:03.372 00000001: ExpeDat-1.15A Data Expedition Inc. - DataExpedition.com, Internal C 20130711 14:47:03.372 Serving files from: /Library/WebServer/Documents/downloads/ S 20130711 14:47:03.372 Load Current: 0, MaxConfig: 0, MaxStart: 0, TotalStart: 0, Errors: 0, Failures: 0, Warnings: 0, Denials: 0 I 20130711 14:47:16.786 E98E9CA1 GET 70.164.67.175:55296 - AES "tst/" "" F 20130711 14:47:16.788 E98E9CA1 GET 70.164.67.175:55296 - AES "tst/" "" 261 (0,0) "0.00 seconds (8.04 megabits/sec)" I 20130711 14:47:25.410 E98E9CA2 GET 70.164.67.175:53048 - AES "tst/test5mb.dat" "" F 20130711 14:47:25.527 E98E9CA2 GET 70.164.67.175:53048 - AES "tst/test5mb.dat" "" 5242880 (0,0) "0.12 seconds (358 megabits/sec)"

Log Filtering

By default, servedat does NOT log successful initiation or completion of bulk data transfers.  This is done to improve performance for high-rate activities such as SyncDat synchronizations or directory transfers.  The level of filtering can be set using the LogFilter configuration variable or the -F command line option.  The default filtering level is 2.

0 No filtering: at least one line of output will be logged for every transaction.
1 Initiation of bulk transactions will not be logged.
2 Success reports for bulk transactions will also be suppressed.  Bulk errors will still be reported.
3 All initiation lines and bulk successes will be suprressed.
4 Only errors will be logged.
5 Only server and non-bulk errors will be logged.
6 Only server errors will be logged

Log Rotation

On unix systems, sending the HUP signal to a running servedat process will cause it to restart and reload all of its configuration settings.  This includes closing the existing log file and opening a new one, which can be useful for log rotation.  Note that any active transactions will be immediately terminated by such a restart.

Diagnostics

If you experience difficulties configuring or communicating with the server, the servedat logs will provide important information about what happened.  Each time servedat is started, it will display a V line indicating its version, process id, and network port.  Whenever a logfile is specified or diagnostic output is enabled, servedat will also display a list of all configuration settings and their origins.  For example:

D 20130711 14:56:33.365 Confguration settings: D 20130711 14:56:33.365 [-a] Aggression 128 System D 20130711 14:56:33.365 [-A] AuthFile 13 System /etc/svpasswd D 20130711 14:56:33.365 [-b] StreamSize 8192 Default D 20130711 14:56:33.365 [-c] Capacity 10 License D 20130711 14:56:33.365 [-d] Debug 0 System D 20130711 14:56:33.365 [-F] LogFilter 2 Default D 20130711 14:56:33.365 [-l] LogFile 3 Default /var/log/servedat.log D 20130711 14:56:33.365 [-I] LogProgress 300 Default D 20130711 14:56:33.365 [-J] LogStatus 600 Default D 20130711 14:56:33.365 [-M] FileMode 420 Default D 20130711 14:56:33.365 [-p] Port 8080 Default D 20130711 14:56:33.365 [-S] SysAuth 1 System D 20130711 14:56:33.365 AllowEncrypt 1 Default D 20130711 14:56:33.365 HomeDir 39 System /Library/WebServer/Documents/downloads/

Please send a copy of all relevant log lines with any support request.  Be sure to include the startup lines include the V line and the configuration settings.  When in doubt, compress and email the entire file!