Logging from C#

Deephaven's .NET logging integration capabilities allow applications written in C# (or CSharp) and other .NET languages to write streaming data into Deephaven binary log files. Like logging from Java applications, the process of setting up a .NET logger is largely driven by the table schema, and makes use of some common Deephaven logging components and generated code.

This integration is focused primarily on C# as the language to be used in the custom logger application, but, since the core logging functions are provided in a .NET assembly, it is also possible to use other .NET languages to generate the data being logged.

While it allows selection of logger languages, the schema editor does not yet contain full support for C# loggers. To define C# loggers, manual editing of schemas is likely to be needed.

Schema Setup

.NET integration allows for the definition of loggers based in C#. Like Java-based loggers, the logger properties are defined in the table's schema file. However, keep in mind that listeners are always implemented as Java code. While a Java logger can be defined together with its listener, the C# logger has to be in a separate Logger section of the schema document, as demonstrated below:

<Logger logFormat="1" loggerLanguage="C#" loggerPackage="com.illumon.iris.dxquotestock.gen">
    <LoggerImports>
      using com.dxfeed.api;
      using com.dxfeed.api.events;
      using static com.illumon.iris.dxfeed.DXStockExchangeMap;
    </LoggerImports>

    <SystemInput name="quote" type="com.dxfeed.api.events.IDxQuote" />
    <SystemInput name="timestamp" type="long" />

    <Column name="Date" intradayType="none" />
    <Column name="Timestamp" intradaySetter="timestamp" />
    <Column name="Sym" intradaySetter="quote.EventSymbol" />
    <Column name="BidTimestamp" intradaySetter="new DateTimeOffset(quote.BidTime).ToUnixTimeMilliseconds()" />
    <Column name="Bid" intradaySetter="quote.BidPrice" />
    <Column name="BidSize" intradaySetter="quote.BidSize" />
    <Column name="BidExchange" intradaySetter="getExchange(quote.BidExchangeCode)" />
    <Column name="AskTimestamp" intradaySetter="new DateTimeOffset(quote.AskTime).ToUnixTimeMilliseconds()" />
    <Column name="Ask" intradaySetter="quote.AskPrice" />
    <Column name="AskSize" intradaySetter="quote.AskSize" />
    <Column name="AskExchange" intradaySetter="getExchange(quote.AskExchangeCode)" />
  </Logger>

The example above is a portion of an example schema file. The table's column definitions and the listener properties used to interpret logged data when inserting new rows into the target table would be found elsewhere in the file.

Key properties when using C# logging:

  • SystemInput: These entries identify arguments that will be passed to the Log method. The names must be valid C# identifiers and the types must be valid C# variable types - either built-in types, or types included from LoggerImports.
  • logFormat: indicates the version number of the logged data. The Data Import Server (DIS) will expect to find a matching version listener when receiving data. For tables with only a single LoggerListener block, this property can be omitted. However, because a .NET logger will always be defined separately from its Java listener, this property will be required in the cases being discussed here. Note: it is possible to have multiple loggers that use the same logFormat value. The critical consideration is that the data actually generated by these different loggers must be in the same format – the same number, order, and types of columns in the binary log file.
  • loggerLanguage: indicates what language will be used when generating the logger code for this logger. Currently supported values are Java and C#. This property is case-insensitive. If this property is omitted, the logger will be handled as a Java logger. When generating C# logger files, they are written under a csharp directory, and given a .cs extension.
  • The LoggerImports: properties for C# are comparable to LoggerImports for Java loggers. However, C# requires the use of using statements instead of import statements. Although the core features can be used in other .NET languages, the code generation functionality of Deephaven currently produces only Java or C#. As such, any code elements included in the logger properties must be valid for the target language.

Another consideration when using a non-Java logger is serialization. For Java loggers, it is possible to implicitly serialize an object and log it as a BLOB (a block of binary data). The normal use of this functionality is to have an object whose class definition is available to both the Java logging application and to the Data Import Server (DIS). This allows the Data Import Server (DIS) to deserialize the object and present it in the same form as it existed before being logged. When the logger is running a different language, such shared object definitions are not possible. However, it is possible to log a non-Java object, and then have the logger extract properties from it, or even serialize it into a form that could be deserialized later in the DIS.

In the example above, a custom C# IDxQuote object is being logged, and the intradaySetters indicate how to handle its properties to map them into the data types expected for column data in the binary log file. This IDxQuote object is referred to by the name quote when it is referenced elsewhere in the logger properties.

Two interesting examples of additional processing in the logger from the example above are BidTimestamp and BidExchange:

  • BidTimestamp is a DBDateTime column in Deephaven (aka DateTime). By default, Deephaven assigns a dbSetter for DBDateTime columns that expects a long signed value of milliseconds from epoch (1/1/1970). In the example, this default dbSetter is being used, which means the logger must provide this epoch milliseconds value. However, what the IDxQuote object provides is a C# DateTime object. To convert this to a long value of epoch milliseconds, the DateTime is first converted to a DateTimeOffset, and the ToUnixTimeMiliseconds method is executed against it. This returns the signed long value that the logger will write into the binary log file, and that the listener will then be able to use to create a new DBDateTime value.
  • BidExchange is a String column in the Deephaven database, and it stores standardized trading exchange short names. However, the IDxQuote object provides a single character value that needs to be mapped to these short names. In this case, the logger has included (using static com.illumon.iris.dxfeed.DXStockExchangeMap;) a mapping class that is called on the fly as quotes are logged to translate the single character into the standard short name. This mapping class must be made available to the logging application.

Deephaven Handling of C# Data Types

Deephaven binary log files support the following data types:

  • Boolean
  • byte
  • char
  • short
  • int
  • long
  • float
  • double
  • Blob
  • EnhancedString
  • Enum

Most of these are very similar to C# primitive types. For instance, a Long in a Deephaven log file is basically the same as a long in C#. The one difference for the primitive types is nullability. Boolean, Blob, decimal, and EnhancedString can log null values. The other types are not inherently nullable, but Deephaven provides a set of constants (available from the Null_Constants class in IrisBinaryLogWriter) to indicate when a primitive value is actually null. Null values are not written to the log file, but are instead indicated as null through a 0 presence bit for the corresponding column in the row. The check for a special null value of a primitive variable is done when the row details are calculated.

The C# fixed point "decimal" type is handled differently than other C# primitive types; since this is a special type not supported directly in Java, we encode it as a byte[] in the binary log. This means using an intradayType of "Blob" for the logger and listener. It is decoded into a BigDecimal in Java. Also as a consequence of the byte[] based encoding, null values can be directly stored.

If a C# application is using nullable primitive types, such as long?, the value must first be converted to a non-nullable long using Utils.ToIrisPrimitive(). For example:

double? x = 3.14;
double y = Utils.ToIrisPrimitive(x);

These functions can also be used in the schema when writing intradaySetters. These expressions will then be used in the generated code so that nullable types will be correctly converted to Deephaven primitives. For cases where a SystemInput uses a boxed type such as: <SystemInput name="total_volume" type="long?" />, and the intradaySetter is directly using this value: <Column name="Volume" intradaySetter="total_volume"/>, the code generation process will automatically apply Utils.ToIrisPrimitive() for the data logging calls. However, if an object's properties are being used for logging, and the properties are nullable primitive types, then the intradaySetter will need to use Utils.ToIrisPrimitive() as part of its expression, as demonstrated below.

<SystemInput name="event_data" type="com.demo.streaming.event" />
<Column name="Volume" intradaySetter="Utils.ToIrisPrimitive(event_data.total_volume)" />

Such handling is not necessary for bool?, string, decimal, or byte[], as these are nullable types for Deephaven log files.

  • Byte[] maps to Blob, and can be used for any block of binary data, including serialized objects. The size limit for a Blob is 2GB.
  • EnhancedString represents a UTF-8 or ISO-8859-1 encoded string, and also allows up to 2GB in length.
    • Note: Although the Byte[] and EnhancedString types allow large values, the binary log format itself limits rows to 1MB total length.
  • Enums allow more efficient storage for string values when the values are from a limited list. When creating an Enum column, an array of string values is passed as a fourth argument to the AddColumn method. The column Write method will then automatically log the ID of an Enum value when the string value is passed. An Enum column has a type of String in the schema, but also gets its list of possible values in the column definition: enum="January,February,March,April,May,June,July,August,September,October,November,December" When a logger is generated from the schema, the presence of an enum attribute for a String column will trigger the code generation to handle the column as an Enum column.

Integrating Deephaven Logging Into a .NET Application

These details assume the use of C# for the logging application. For other .NET languages, it will be necessary to either call methods from the generated C# file, port that file to the language being used, or use it as a template to write a custom non-C# logger.

After the schema file has been created or updated with the C# logger section, the logger code can be generated by running sudo /usr/illumon/latest/bin/iris generate_loggers on a Deephaven server where the schema is accessible. The .cs files for CSharp logger sections will be created under /etc/sysconfig/illumon.d/resources/csharp, by default, or under a csharp directory under the ILLUMON_JAVA_GENERATION_DIR, if this has been specified. There will be sub-directories from there based on each logger's loggerPackage attribute from the logger section of the schema.

In the custom application, which is creating or receiving events to be logged, a few changes will be needed:

  1. Ensure the logging application is targeting .NET 4.6.1 or later.
  2. Add a reference to IrisBinaryLogWriter.
  3. Add a reference to System.Numerics.
  4. Add the generated .cs file to the project.

In the logging application's code, initialize the logger. The logger will have several constructors with several optional parameters. These parameters include:

  • bool explicitFileName - If true, the filename is used as-is, and is not modified with a date/time stamp. The default is false.
  • string baseFileName - the file name to which a timestamp suffix will be added. This will be taken as a full file name if explicitFileName is true.
  • string loggingPath - the directory where the log files will be placed.
  • TimeSpan fileRolloverInterval - a timespan between 1 minute and 24 hours to dictate when the output log file should be rolled to a new file. The default is 1 hour. No rollover is applied when explicitFileName is true.
  • bool useQueue - If true, logged data will be added to a queue and an internal thread will write the data to disk. If false, the client must log data in a single thread. The default is true.
  • bool flush - This is a performance tuning parameter. If true, data is flushed to disk after every Write() call. If false, the client might want to call Flush() periodically. Flush() will be called automatically when the output file rolls over or when the logger is shutdown with Shutdown().
  • int fileBufferSize - This is a performance tuning parameter. Setting this to a value different than the default of 4096 can improve throughput on some underlying file systems.

For example:

QuoteStockLogger quoteLogger = new QuoteStockLogger("DXQuote.bin", "C:\\Temp\\", TimeSpan.FromMinutes(15));

This statement creates a new logger object from the generated code from the example schema above. Log files will be created under C:\Temp, and log file names will begin with DXQuote.bin. The logger itself will create a unique file name by adding date and time information to the provided base filename. The third argument indicates that the output file should be rolled to a new name every 15 minutes.

Once initialized, the logger object can be used to write events to the binary log file. For example:

quotelogger.Log(q, timestamp());

This statement will log an IDxQuote object, called "q", and a long value of epoch milliseconds obtained from the timestamp function (defined in an example application):

private long timestamp()
{
TimeSpan t = DateTime.UtcNow - new DateTime(1970, 1, 1);
return (long)t.TotalMilliseconds;
}

If you have not disabled the queue (by constructing the logger with useQueue=false), you may call Log from multiple threads. If the queue is not used, only a single thread may call the Log method.

When closing, the logging application should allow some time for the background thread to clear the logging event queue, if one is being used. This can be done explicitly by calling the Shutdown() method of the generated logger. This takes an argument, in milliseconds, for how long it should try to clear the queue. The default is 5000 milliseconds (5 seconds). If the queue is still not clear after the amount of time that was allowed, your exception handler will be called by the background thread. The logger exposes a QueueCount property to show how many items are in the queue waiting to be written to the log file. Logging applications can check and wait for this to go to 0 after they're finished logging, to ensure that the queue has sufficient time to clear. QueueCount will always be 0 if the queue is not in use. The logger also implements IDisposable, and Shutdown will be called by the Dispose method. So, another option is to use a using clause to ensure the queue has a chance to clear and that the file is closed.

Handling Exceptions from the Background Thread

When the queue is in use, a dedicated thread drains the queue and writes rows to the output file. If this thread encounters exceptional conditions, it will disallow further Log calls and attempt to drain the queue. The original exception and any additional exceptions encountered while shutting down will be reported by calling the registered exception handler. The callback might be called several times.

If you want to be notified of these errors, set a callback using SetExceptionCallback. This delegate method should halt the logging application. No further logging will be allowed after the callback is called.

For example:

// signal that logging should stop
volatile boolean stopLogging = false;

var coe = new LoggerQueue.ExceptionHandler((ex) =>
{
    stopOnError = true;
    MessageBox.Show("Logging Error: Exception: " + ex);
});
logger.SetExceptionCallback(coe);

Logging Process within the Generated Code

The generated code uses schema information to set up the details of creating and using a log file. This includes the following steps:

  1. Creating the filename that will be used for this logging instance. This filename is then passed to the constructor for an IrisLogger object, where it will be used to open a BinaryWriter that will write into the file.
  2. Setting the logFormat version number for the log file.
  3. Optionally, but enabled by default, setting up a queue that will be used to offload logging activities from the client application (a background thread will process events from the queue and handle actually writing event data to disk).
  4. Adding column definitions for the logger object; calling AddColumn on the IrisLogger returns a ColumnWriter. The ColumnWriter object will then be used to write individual values to a column. A ColumnWriter takes care of such things as formatting bytes and encoding Strings.
  5. Writing the file's header information.
  6. Setting up the Log method that will add events to the queue as shown above. The Log method performs the following steps internally:
    1. Get a row object from queue, or from the Deephaven logger if the queue is disabled.
    2. Initialize the row by calling row.StartRow()
    3. Add data for all columns, in order, by calling writer.Write(row, value)
    4. Finalize the row by calling row.EndRow()
    5. Write the row by doing one of the following:
      • If using the queue, add the finished row to the write queue by calling loggerQueue.Log(row).
      • If not using the queue, write the row directly by calling irisLogger.WriteRow(row).

Logging Process without Generated Code

It is possible to manually write the code to log binary data using the IrisBinaryLogWriter package.

You will need to follow the steps below:

  1. Initialize the logger:
  • logger IrisLogger2 irisLogger = new IrisLogger2(...)
  • There are several constructors for IrisLogger2, which are documented above. The constructors allow a number of optional parameters to be passed.
  1. Get the logging queue if queueing is enabled:
  • LoggerQueue loggerQueue = irisLogger.GetLoggerQueue()

Once these initial elements are in place, the process of logging a row occurs, as detailed below:

  1. Get a Row object:
    1. If using the queue: Row row = loggerQueue.GetLogEvent(). This row object will be added to the queue later and written by the queue thread. You must get a new row object for every row to be logged.
    2. If not using the queue: Row row = irisLogger.GetRow() This row is a single reusable object that will be written synchronously to disk. Your single logging thread may reuse the same row object for all rows.
  2. Initialize the row by calling row.StartRow().
  3. Add all the values to the row by calling Write() on all ColumnWriter objects (returned from AddColumn) in sequence.
  4. Call row.EndRow() to finalize the object.
  5. Write or queue the row.
    1. If using the queue: loggerQueue.Log(row)
    2. If not using the queue: irisLogger.WriteRow(row)

Handling Exceptions

When the queue is in use, data is written on a separate thread. This thread could encounter an exceptional situation, such as when the filesystem is full. To get visibility to this, the application can register a callback. If the queue thread encounters exceptional conditions, it will disallow further Log calls and attempt to drain the queue. The original exception and any additional exceptions encountered while shutting down will be reported by calling the registered exception handler. The callback might be called several times.

To get notification of exceptions from the queue thread, define a delegate that implements LoggerQueue.ExceptionHandler, and register it using the SetExceptionHandler method on the generated logger class or on LoggerQueue.

/// <summary>
/// Handler for exceptions encountered on the queue thread.
/// The queue will terminate after this method is called.
/// Do not throw exceptions from this method.
///
/// Example usage:
///      volatile boolean errorSignal = false;
///      var coe = new LoggerQueue.ExceptionHandler((ex) =>
///     {f
///         errorSignal = true;
///         MessageBox.Show( "Exception: " + ex);
///     });
/// </summary>
/// <param name="e"></param>
public delegate void ExceptionHandler(Exception e);

This method should notify the application thread in some manner. For example:

// variable for inter-thread communication
static volatile bool queueTerminated = false;

// create the handler
var coe = new LoggerQueue.ExceptionHandler((ex) =>
{
    queueTerminated = true;
    MessageBox.Show("Exception: " + ex);
});

// example setup for generated logger
QuoteStockLogger quoteLogger = new QuoteStockLogger(...);
// assign the handler
quoteLogger.SetExceptionCallback(coe);

// example setup without generated logger
IrisLogger irisLogger = new IrisLogger(...);
LoggerQueue queue = irisLogger.GetLoggerQueue();
// assign the handler
queue.SetExceptionCallback(coe);

// your logging loop might have these features
while (!queueTerminated) {
    Row row = calculateData();
    queue.Log(row);
}