Статьи

Создание значимых документов из журналов приложений, охватывающих несколько строк — часть 1

Вступление

При работе с журналами приложений одним из наиболее распространенных сценариев является чтение и обработка журналов, которые занимают несколько строк. Наиболее распространенным примером информации журнала, которая занимает несколько строк, являются те, которые генерируются Java и .NET. При обработке таких журналов с использованием таких инструментов, как Logstash, мы сталкиваемся с дилеммой. Выбор делается между обработкой каждой строки как отдельной записи и обработкой всех записей как части одного блока текста. Если мы будем рассматривать каждую строку отдельно, у нас возникнет проблема сопоставления всех записей в единую группу, которая может быть обработана. Если мы рассматриваем данные как один блок текста, любая бизнес-логика, которая зависит от этого текста, должна выполнять обработку текста и извлекать необходимую информацию.

В некоторой степени я рассмотрел эту дилемму в своей предыдущей статье под названием «Использование множественных операторов Grok для анализа трассировки стека Java (http://java.dzone.com/articles/using-multiple-grok-statements). Хотя эта статья была в определенной степени результатом моей неопытности с Logstash и, в частности, с плагином ‘mutiline’ (описанным в статье под названием ‘Logstash — Quirky’ multiline » (http://java.dzone.com/articles/ logstash-quirky-multiline-0)), дилемма продолжалась долгое время.

After a long search, I came across a working implementation of the ‘clone’ plugin in Logstash and I was finally able to generate documents from the log data, the way I wanted them. The Logstash construct that helped me achieve this is the ‘clone’ plugin. By using the ‘clone’ plugin, I was able to not only retain the (multiple line spanning) application log as a single block of text, but was also able to create separate documents – one record per line of the log file – from the single block of text. By storing duplicate information, I am now able to get the complete log at one stroke and also drill down into individual elements of the log, for detailed analysis and reporting.

I will cover the method used to achieve this, using a two part article series. In the first part, I will describe the script in portions. In the second part, I will describe how documents can be queried in Elasticsearch and also present the complete script.

Sample Input

For the purpose of this article, I will use a sample input (that spans multiple lines in the log file), as shown in Snippet 1. In this sample, each line that starts with ‘ERROR’ is part of the same log entry. Thus, this log entry spans 10 lines (including blank lines). In this article, I will cover how I parsed this input as a single block of text as well as how I separated that block into individual records.

INFO, 2015-04-09 06:05:48, Sync operation completed successfully for 2345 success

ERROR, 2015-04-09 06:06:18, Type: Application, Error message: Failed to execute the command 'UpdateCommand' for table 'Item'; the transaction was rolled back. Ensure that the command syntax is correct.

ERROR OCCURRED FOR: at SynchronizeDCM() method in using block.. For Unit Id = 20847 and SDM Source = 10.25.7.1

ERROR DETAILS STACK:  at Microsoft.Synchronization.Data.ChangeHandlerBase.CheckZombieTransaction(String commandName, String table, Exception ex)
  at Microsoft.Synchronization.Data.SqlServer.SqlChangeHandler.ApplyBulkChanges(DataTable dataTable)
  at Microsoft.Synchronization.SyncOrchestrator.Synchronize()
  at SyncService.SyncService.SynchronizeDCM(DataRow dr, String SessionId)

ERROR SOURCE: Microsoft.Synchronization

INFO, 2015-04-09 06:25:48, Sync operation completed successfully for 865 success

Snippet 1: Sample log

The Problem

Logs that span multiple lines create problems at the time of processing. The most common response in such cases is to treat all the lines as a single entity and read them into a single block of text. If treated as a single block of text, each application that deals with such data will have to extract relevant information from the block. Hence, the same processing logic will be repeated across multiple applications, it makes application maintenance a hazardous task.

If, instead of this approach, we treat each line of input as a separate record, we face a different challenge. Once such records are stored in a data store, we face a challenge in fetching all the related records. Usually, log entries that span multiple lines, do not have complete / adequate information on each line that will allow us to attach it to the main entry. Hence, once the ‘connectivity’ is broken at the time of parsing, it is nearly impossible to restore it at the data store level (unless additional data is used to establish and maintain the ‘connectivity’ at the time of record creation).

Patterns used in the script

As you might be aware, Logstash uses regular expression patterns to match the input and convert the data into relevant document attributes. We have defined some custom regular expressions, as given in Snippet 2. As the script description is quite detailed and lengthy, I have covered the regular expression before the script.

CUSTOM_ERROR Type: %{CUSTOM_TEXT:errorSource}, Error message:
CUSTOM_ERROR_LABEL_1 ERROR
CUSTOM_ERROR_LABEL_2 \[ERROR\]
CUSTOM_MAIN_LABEL \[main\]
CUSTOM_LABEL [a-zA-z]*
CUSTOM_LEADER_TEXT_ERROR_OCCURRED_FOR [E][R][R][O][R][ ][O][C][C][U][R][R][E][D][ ][F][O][R]
CUSTOM_LEADER_TEXT_ERROR_DETAILS_STACK [E][R][R][O][R][ ][D][E][T][A][I][L][S][ ][S][T][A][C][K]
CUSTOM_LEADER_TEXT_APPLICATION_PACKAGE_APP at%{SPACE}SyncService[.]
CUSTOM_LEADER_TEXT_APPLICATION_PACKAGE_AT at
CUSTOM_LEADER_TEXT_ERROR_SOURCE [E][R][R][O][R][ ][S][O][U][R][C][E]
CUSTOM_LEADER_TEXT_INFO [I][N][F][O]
CUSTOM_LABEL_SDM_SOURCE %{CUSTOM_LABEL}%{SPACE}%{CUSTOM_LABEL}%{SPACE}%{CUSTOM_LABEL}
CUSTOM_LABEL_BUSINESS_UNIT_ID %{CUSTOM_LABEL}%{SPACE}%{CUSTOM_LABEL}%{SPACE}%{CUSTOM_LABEL}
CUSTOM_LABEL_SYNC_OPERATION_COMPLETED [S][y][n][c][ ][o][p][e][r][a][t][i][o][n][ ][c][o][m][p][l][e][t][e][d][ ][s][u][c][c][e][s][s][f][u][l][l][y][ ][f][o][r]
CUSTOM_TIMESTAMP %{YEAR}-%{MONTHNUM}-%{MONTHDAY}%{SPACE}%{TIME}

Snippet 2: Regular expressions

The Script

In this section, we will describe the Logstash script that we have developed. For ease of explanation, we have presented each concept using a snippet of the script and the complete script is presented in a later section.

Processing ‘INFO’ entries

For people familiar with Logstash, the first part of the script is quite standard. In this part, we have used the ‘grok’ command to define patterns that are used for matching entries in the log file. In this case, the ‘grok’ pattern matches ‘INFO’ entries in the log file. The pattern also allows me to separate the string input into its constituent elements, to create a record (termed as ‘event’ in Logstash documentation). The constituent elements become attributes of the document when stored in a data store like Elasticsearch. The ‘grok’ statement is placed in the ‘filter’ section of the script. If the statement is parsed correctly, the timestamp that is read from the input is converted from a string into an equivalent date. This portion of the script is presented in Snippet 3.

filter {
  if [type] == "foolproof_log" {
    # read 'sync completed' info message
    grok {
      patterns_dir => "./patterns"
      match => { "message" => "%{CUSTOM_LEADER_TEXT_INFO:logLevel}[,]%{SPACE}%{CUSTOM_TIMESTAMP:logTimeString}[,]%{SPACE}%{CUSTOM_LABEL_SYNC_OPERATION_COMPLETED}%{SPACE}%{NUMBER:moduleID}%{GREEDYDATA:extraText}" }
      add_field => { "subType" => "infoSyncCompleted" }
      remove_tag => [ "_grokparsefailure" ]
    }

    if "_grokparsefailure" not in [tags] {
      mutate {
        gsub => [
          "logTimeString", ",", ";"
        ]
      }
      date {
        locale => "en"
        match => [ "logTimeString", "YYYY-MM-dd HH:mm:ss" ]
        target => "logTime"
      }
    }
  }
}

Snippet 3: INFO entries

Processing ‘ERROR’ entries

If input line is not an ‘INFO’ entry, we check if the input line is an ‘ERROR’ entry. Such lines begin with the word ‘ERROR’, followed by other text. As this entry spans multiple lines in the log file, we have used the ‘multiline’ plugin to read all such lines into a single block of text. As there are multiple such lines, we have used multiple regular expression patterns which are separated by the pipe (‘|’) character.

The ‘multiline’ plugin is followed by a ‘grok’ statement that uses the same pattern as the ‘multiline’, but adds a few fields to the record created by Logstash. These fields are used for later processing and for differentiation between records. This portion of the script is presented in Snippet 4.

filter {
  if [type] == "foolproof_log" {
    . . .

    if "_grokparsefailure" in [tags] {
      multiline {
        patterns_dir => "./patterns"
        pattern => "(%{CUSTOM_ERROR_LABEL_1:logLevel},%{SPACE}%{TIMESTAMP_ISO8601},%{SPACE}%{GREEDYDATA})|(%{CUSTOM_ERROR_LABEL_2}%{SPACE}%{TIMESTAMP_ISO8601}%{SPACE}%{GREEDYDATA})|(%{TIMESTAMP_ISO8601}%{SPACE}%{CUSTOM_MAIN_LABEL}%{SPACE}%{GREEDYDATA})"
        negate => true
        what => previous
      }

      grok {
        patterns_dir => "./patterns"
        match => [ "message", "%{CUSTOM_ERROR_LABEL_1:logLevel},%{SPACE}%{TIMESTAMP_ISO8601:logTimeString},%{SPACE}%{GREEDYDATA:mergedText}" ]
        remove_tag => [ "_grokparsefailure" ]
        add_field => { "recordType" => "master" }
        add_field => { "inputType" => "foolproof_log" }
      }
    }
  }
}

Snippet 4: Multiline

Removing the ‘mergedText’ field

The ‘grok’ statement has a ‘mergedText’ field, that will store (as a single block of text) all the data read from the log file. Though we have parsed this information, it is not really needed, as complete information is available in the ‘message’ field of the record. We have used data from the ‘message’ field, later in the script. Hence, we have used the ‘mutate’ plugin to remove the ‘mergedText’ field from the record, as presented in Snippet 5.

mutate {
    remove_field => [ "mergedText" ]
  }

Snippet 5: Removing ‘mergedText’

Cloning the record

After deleting the ‘mergedText’ field, we have a record that contains all the information we are interested in. Now is the most important aspect of the script. After having collected all log entries that span multiple lines into a single block of text, we am at the stage where I would like to create multiple records that contain granular information, form the record containing the single block of text. We have done this using the ‘clone’ plugin, as presented in Snippet 6.

 clone {
    clones => [ "cloned" ]
  }

Snippet 6: Clone the record (event in Logstash terminology)

The ‘clone’ plugin creates a duplicate of the record being processed by Logstash, and sends the duplicate entry through the filter pipeline once again.

Special handling for ‘cloned’ records

When the ‘clone’ plugin is used, Logstash send the duplicated entry for processing. This is done by applying all the constructs in the ‘filter’ plugin, from the beginning. Hence, we need to use a conditional statement, which will allow us to distinguish between an original entry and the cloned entry. We simply have to use a suitable conditional statement. In addition to adding a ‘cloned’ tag to the original entry, Logstash changes the ‘type’ of the cloned record to ‘cloned’. This change of type allows us to process cloned records differently, as presented in Snippet 7.

filter {
  if [type] == "foolproof_log" {
    if "cloned" not in [tags] {
      # read 'sync completed' info message

      # read multiline
    }
  }

  # split the 'cloned' multiline into separate parts for detailed processing
  if [type] == "cloned" {
    # processing logic to be added
  }
}

Snippet 7: Handling original and cloned records

Processing cloned records

When Logstash encounters the ‘clone’ plugin, it creates a duplicate of the record that it has processed till the clone plugin was reached. Logstash then applies all the commands in the ‘filter’ section – starting from the first command – to the cloned record. Duplicate records can be distinguished from other records, as Logstash changes its ‘type’ to ‘cloned’.

After cloning the record, the first step is to split the record into its constituent records (using the ‘split’ plugin), so that we can create meaningful documents from the large block of text. Before doing so, we need to replace one or more of the whitespace characters by a more easily identifiable character that can be used to split the block of text. This is done using the ‘mutate’ plugin. In this example, we have used the hash (‘#’) character as a line separator, as it does not appear anywhere in the log text.

The ‘split’ plugin splits the input data into multiple string (based on the separator character) and applies the rules that follow the ‘split’ plugin. To convert string data into meaningful records, we match the input to specific patterns using the ‘grok’ plugin, as is commonly done in Logstash. Using suitable patterns, we can convert the plain string input into documents with specific attributes that can be used for reporting and/or analytics. As an example, consider the first ‘grok’ command (after the ‘split’ plugin), which extracts the business unit ID and the source IP address from the input, into separate documents attributes. By doing so, it is possible, for example, to generate a report in Kibana that can list the business units that have generated errors in the last one month. This portion of the script is presented in Snippet 8.

 # split the 'cloned' multiline into separate parts for detailed processing
  if [type] == "cloned" {
    if [message] == "" {
      drop { }
    }

    if [logLevel] == "ERROR" {
      # this pattern patches the pattern of the multiline
      grok {
        patterns_dir => "./patterns"
        match => [ "message", "%{CUSTOM_ERROR_LABEL_1},%{SPACE}%{TIMESTAMP_ISO8601},%{SPACE}%{GREEDYDATA:mergedMessage}" ]
        remove_tag => [ "_grokparsefailure" ]
        remove_field => [ "message" ]
        remove_tag => [ "multiline" ]
        remove_field => [ "recordType" ]
      }

      mutate {
        add_field => { "recordType" => "child" }
      }

      ## we remove \n, \r and \t from 'mergedMessage' field.
      ## We remove these characters by replacing them by suitable alternative.
      ## we will then use the substituted chracter for splitting the multiline message into
      ## constituent messages
      mutate {
        gsub => [
          "mergedMessage", "\r\n", "#",
          "mergedMessage", "\n\n", "#",
          "mergedMessage", "\r\n\t", "#",
          "mergedMessage", "\n\t", "#",
          "mergedMessage", "\n  ", "#",
          "mergedMessage", "\n  ", "#",
          "mergedMessage", "\n", "#"
        ]
      }

      split {
        field => "mergedMessage"
        target => "splitText"
        terminator => "#"
      }

      # parse business unit id line
      grok {
        patterns_dir => "./patterns"
        match => { "splitText" => "%{CUSTOM_LEADER_TEXT_ERROR_OCCURRED_FOR}[:]%{SPACE}%{CUSTOM_TEXT_2:messge1}[.][.]%{SPACE}%{CUSTOM_LABEL_BUSINESS_UNIT_ID}%{SPACE}[=]%{SPACE}%{NUMBER:businessUnitID}%{SPACE}%{CUSTOM_LABEL_SDM_SOURCE}%{SPACE}[=]%{SPACE}%{IP:sourceIPAddress}%{GREEDYDATA:errorText}" }
        add_field => { "subType" => "errorOccurredFor" }
        remove_tag => [ "_grokparsefailure" ]
      }
      if "_grokparsefailure" not in [tags] {
        mutate {
          convert => [ "businessUnitID", "integer" ]
        }
      }

      # read first error line
      if "_grokparsefailure" in [tags] {
        grok {
          patterns_dir => "./patterns"
          match => { "splitText" => "%{SPACE}%{CUSTOM_ERROR}%{GREEDYDATA:messageText}" }
          add_field => { "subType" => "errorReason" }
          remove_tag => [ "_grokparsefailure" ]
        }
      }

      # read error stack details
      if "_grokparsefailure" in [tags] {
        grok {
          patterns_dir => "./patterns"
          match => { "splitText" => "%{CUSTOM_LEADER_TEXT_ERROR_DETAILS_STACK}[:]%{SPACE}%{GREEDYDATA:errorText}" }
          add_field => { "subType" => "stackTraceStart" }
          remove_tag => [ "_grokparsefailure" ]
        }
      }
      # read error source details
      if "_grokparsefailure" in [tags] {
        grok {
          patterns_dir => "./patterns"
          match => { "splitText" => "%{CUSTOM_LEADER_TEXT_ERROR_SOURCE}[:]%{SPACE}%{GREEDYDATA:errorSource}" }
          add_field => { "subType" => "errorSource" }
          remove_tag => [ "_grokparsefailure" ]
        }
      }
      # read application specific stack line
      if "_grokparsefailure" in [tags] {
        grok {
          patterns_dir => "./patterns"
          match => { "splitText" => "%{SPACE}%{CUSTOM_LEADER_TEXT_APPLICATION_PACKAGE_APP}%{GREEDYDATA:messageText}" }
          add_field => { "subType" => "stackTraceApp" }
          remove_tag => [ "_grokparsefailure" ]
        }
      }

      # read other stack lines
      if "_grokparsefailure" in [tags] {
        grok {
          patterns_dir => "./patterns"
          match => { "splitText" => "%{SPACE}%{CUSTOM_LEADER_TEXT_APPLICATION_PACKAGE_AT}%{SPACE}%{GREEDYDATA:messageText}" }
          add_field => { "subType" => "stackTraceOther" }
          remove_tag => [ "_grokparsefailure" ]
        }
      }
    }
  }

Snippet 8: Processing cloned records

The Result

When we parse the input using this Logstash script, it generates documents in the JSON format. The two records, which correspond to the ‘INFO’ entries from the log file, are presented in Snippet 9.

{
  "message" => "INFO, 2015-04-09 06:05:48, Sync operation completed successfully for 2345 success",
  "@version" => "1",
  "@timestamp" => "2015-06-10T03:49:21.131Z",
  "host" => "127.0.0.1",
  "type" => "foolproof_log",
  "logLevel" => "INFO",
  "logTimeString" => "2015-04-09 06:05:48",
  "moduleID" => "2345",
  "extraText" => " success",
  "subType" => "infoSyncCompleted",
  "logTime" => "2015-04-09T00:35:48.000Z"
}
{
  "message" => "INFO, 2015-04-09 06:25:48, Sync operation completed successfully for 865 success",
  "@version" => "1",
  "@timestamp" => "2015-06-10T03:49:21.332Z",
  "host" => "127.0.0.1",
  "type" => "foolproof_log",
  "logLevel" => "INFO",
  "logTimeString" => "2015-04-09 06:25:48",
  "moduleID" => "865",
  "extraText" => " success",
  "subType" => "infoSyncCompleted",
  "logTime" => "2015-04-09T00:55:48.000Z"
}

Snippet 9: Output — info records

The third record, presented in Snippet 10, is created by the ‘multiline’ plugin. The ‘message’ field of the record contains multiple lines from the log file as a single, contiguous block of text (each line separated by newline, tab and/or space characters, as per the log file).

{
  "message" => "ERROR, 2015-04-09 06:06:18, Type: Application, Error message: Failed to execute the command 'UpdateCommand' for table 'Item'; the transaction was rolled back. Ensure that the command syntax is correct.\nERROR OCCURRED FOR: at SynchronizeDCM() method in using block.. For Unit Id = 20847 and SDM Source = 10.25.7.1\nERROR DETAILS STACK:  at Microsoft.Synchronization.Data.ChangeHandlerBase.CheckZombieTransaction(String commandName, String table, Exception ex)\n  at Microsoft.Synchronization.Data.SqlServer.SqlChangeHandler.ApplyBulkChanges(DataTable dataTable)\n  at Microsoft.Synchronization.SyncOrchestrator.Synchronize()\n  at SyncService.SyncService.SynchronizeDCM(DataRow dr, String SessionId)\nERROR SOURCE: Microsoft.Synchronization",
  "@version" => "1",
  "@timestamp" => "2015-06-10T03:49:21.160Z",
  "host" => "127.0.0.1",
  "type" => "foolproof_log",
  "tags" => [
    [0] "multiline"
  ],
  "logLevel" => "ERROR",
  "logTimeString" => "2015-04-09 06:06:18",
  "recordType" => "master",
  "inputType" => "foolproof_log",
  "logTime" => "2015-04-09T00:36:18.000Z"
}

Snippet 10: Output — multiple lines read into single block of text

For the purpose of clarity, we have presented the ‘cloned’ records separately in Snippet 11. As you may note, each record is of type ‘cloned’. You will also notice that each record contains a portion of the multiline text block in the ‘mergedMessage’ field. Additionally, specific messages have been extracted from this field into the ‘splitText’ field, which can now be used for detailed reporting. It should be noted that in the second record, we have extracted the business unit ID and the source IP address, as specific fields from the larger message.

{
  "@version" => "1",
  "@timestamp" => "2015-06-11T09:08:51.734Z",
  "host" => "127.0.0.1",
  "type" => "cloned",
  "tags" => [],
  "logLevel" => "ERROR",
  "logTimeString" => "2015-04-09 06:06:18",
  "inputType" => "foolproof_log",
  "logTime" => "2015-04-09T00:36:18.000Z",
  "mergedMessage" => "Type: Application, Error message: Failed to execute the command 'UpdateCommand' for table 'Item'; the transaction was rolled back. Ensure that the command syntax is correct.#ERROR OCCURRED FOR: at SynchronizeDCM() method in using block.. For Unit Id = 20847 and SDM Source = 10.25.7.1#ERROR DETAILS STACK:  at Microsoft.Synchronization.Data.ChangeHandlerBase.CheckZombieTransaction(String commandName, String table, Exception ex)#at Microsoft.Synchronization.Data.SqlServer.SqlChangeHandler.ApplyBulkChanges(DataTable dataTable)#at Microsoft.Synchronization.SyncOrchestrator.Synchronize()#at SyncService.SyncService.SynchronizeDCM(DataRow dr, String SessionId)#ERROR SOURCE: Microsoft.Synchronization",
  "recordType" => "child",
  "splitText" => "Type: Application, Error message: Failed to execute the command 'UpdateCommand' for table 'Item'; the transaction was rolled back. Ensure that the command syntax is correct.",
  "errorSource" => "Application",
  "messageText" => "Failed to execute the command 'UpdateCommand' for table 'Item'; the transaction was rolled back. Ensure that the command syntax is correct.",
  "subType" => "errorReason"
}
{
  "@version" => "1",
  "@timestamp" => "2015-06-11T09:08:51.734Z",
  "host" => "127.0.0.1",
  "type" => "cloned",
  "tags" => [],
  "logLevel" => "ERROR",
  "logTimeString" => "2015-04-09 06:06:18",
  "inputType" => "foolproof_log",
  "logTime" => "2015-04-09T00:36:18.000Z",
  "mergedMessage" => "Type: Application, Error message: Failed to execute the command 'UpdateCommand' for table 'Item'; the transaction was rolled back. Ensure that the command syntax is correct.#ERROR OCCURRED FOR: at SynchronizeDCM()method in using block.. For Unit Id = 20847 and SDM Source = 10.25.7.1#ERROR DETAILS STACK:  at Microsoft.Synchronization.Data.ChangeHandlerBase.CheckZombieTransaction(String commandName, String table, Exception ex)#at Microsoft.Synchronization.Data.SqlServer.SqlChangeHandler.ApplyBulkChanges(DataTable dataTable)#at Microsoft.Synchronization.SyncOrchestrator.Synchronize()#at SyncService.SyncService.SynchronizeDCM(DataRow dr, String SessionId)#ERROR SOURCE: Microsoft.Synchronization",
  "recordType" => "child",
  "splitText" => "ERROR OCCURRED FOR: at SynchronizeDCM() method in using block.. For Unit Id = 20847 and SDM Source = 10.25.7.1",
  "messge1" => "at SynchronizeDCM() method in using block",
  "businessUnitID" => 20847,
  "sourceIPAddress" => "10.25.7.1",
  "subType" => "errorOccurredFor"
}
{
  "@version" => "1",
  "@timestamp" => "2015-06-11T09:08:51.734Z",
  "host" => "127.0.0.1",
  "type" => "cloned",
  "tags" => [],
  "logLevel" => "ERROR",
  "logTimeString" => "2015-04-09 06:06:18",
  "inputType" => "foolproof_log",
  "logTime" => "2015-04-09T00:36:18.000Z",
  "mergedMessage" => "Type: Application, Error message: Failed to execute the command 'UpdateCommand' for table 'Item'; the transaction was rolled back. Ensure that the command syntax is correct.#ERROR OCCURRED FOR: at SynchronizeDCM() method in using block.. For Unit Id = 20847 and SDM Source = 10.25.7.1#ERROR DETAILS STACK:  at Microsoft.Synchronization.Data.ChangeHandlerBase.CheckZombieTransaction(String commandName, String table, Exception ex)#at Microsoft.Synchronization.Data.SqlServer.SqlChangeHandler.ApplyBulkChanges(DataTable dataTable)#at Microsoft.Synchronization.SyncOrchestrator.Synchronize()#at SyncService.SyncService.SynchronizeDCM(DataRow dr, String SessionId)#ERROR SOURCE: Microsoft.Synchronization",
  "recordType" => "child",
  "splitText" => "ERROR DETAILS STACK:  at Microsoft.Synchronization.Data.ChangeHandlerBase.CheckZombieTransaction(String commandName, String table, Exception ex)",
  "errorText" => "at Microsoft.Synchronization.Data.ChangeHandlerBase.CheckZombieTransaction(String commandName, String table, Exception ex)",
  "subType" => "stackTraceStart"
}
{
  "@version" => "1",
  "@timestamp" => "2015-06-11T09:08:51.734Z",
  "host" => "127.0.0.1",
  "type" => "cloned",
  "tags" => [],
  "logLevel" => "ERROR",
  "logTimeString" => "2015-04-09 06:06:18",
  "inputType" => "foolproof_log",
  "logTime" => "2015-04-09T00:36:18.000Z",
  "mergedMessage" => "Type: Application, Error message: Failed to execute the command 'UpdateCommand' for table 'Item'; the transaction was rolled back. Ensure that the command syntax is correct.#ERROR OCCURRED FOR: at SynchronizeDCM() method in using block.. For Unit Id = 20847 and SDM Source = 10.25.7.1#ERROR DETAILS STACK:  at Microsoft.Synchronization.Data.ChangeHandlerBase.CheckZombieTransaction(String commandName, String table, Exception ex)#at Microsoft.Synchronization.Data.SqlServer.SqlChangeHandler.ApplyBulkChanges(DataTable dataTable)#at Microsoft.Synchronization.SyncOrchestrator.Synchronize()#at SyncService.SyncService.SynchronizeDCM(DataRow dr, String SessionId)#ERROR SOURCE: Microsoft.Synchronization",
  "recordType" => "child",
  "splitText" => "at Microsoft.Synchronization.Data.SqlServer.SqlChangeHandler.ApplyBulkChanges(DataTable dataTable)",
  "messageText" => "Microsoft.Synchronization.Data.SqlServer.SqlChangeHandler.ApplyBulkChanges(DataTable dataTable)"
,
  "subType" => "stackTraceOther"
}
{
  "@version" => "1",
  "@timestamp" => "2015-06-11T09:08:51.734Z",
  "host" => "127.0.0.1",
  "type" => "cloned",
  "tags" => [],
  "logLevel" => "ERROR",
  "logTimeString" => "2015-04-09 06:06:18",
  "inputType" => "foolproof_log",
  "logTime" => "2015-04-09T00:36:18.000Z",
  "mergedMessage" => "Type: Application, Error message: Failed to execute the command 'UpdateCommand' for table 'Item'; the transaction was rolled back. Ensure that the command syntax is correct.#ERROR OCCURRED FOR: at SynchronizeDCM() method in using block.. For Unit Id = 20847 and SDM Source = 10.25.7.1#ERROR DETAILS STACK:  at Microsoft.Synchronization.Data.ChangeHandlerBase.CheckZombieTransaction(String commandName, String table, Exception ex)#at Microsoft.Synchronization.Data.SqlServer.SqlChangeHandler.ApplyBulkChanges(DataTable dataTable)#at Microsoft.Synchronization.SyncOrchestrator.Synchronize()#at SyncService.SyncService.SynchronizeDCM(DataRow dr, String SessionId)#ERROR SOURCE: Microsoft.Synchronization",
  "recordType" => "child",
  "splitText" => "at Microsoft.Synchronization.SyncOrchestrator.Synchronize()",
  "messageText" => "Microsoft.Synchronization.SyncOrchestrator.Synchronize()",
  "subType" => "stackTraceOther"
}
{
  "@version" => "1",
  "@timestamp" => "2015-06-11T09:08:51.734Z",
  "host" => "127.0.0.1",
  "type" => "cloned",
  "tags" => [],
  "logLevel" => "ERROR",
  "logTimeString" => "2015-04-09 06:06:18",
  "inputType" => "foolproof_log",
  "logTime" => "2015-04-09T00:36:18.000Z",
  "mergedMessage" => "Type: Application, Error message: Failed to execute the command 'UpdateCommand' for table 'Item'; the transaction was rolled back. Ensure that the command syntax is correct.#ERROR OCCURRED FOR: at SynchronizeDCM() method in using block.. For Unit Id = 20847 and SDM Source = 10.25.7.1#ERROR DETAILS STACK:  at Microsoft.Synchronization.Data.ChangeHandlerBase.CheckZombieTransaction(String commandName, String table, Exception ex)#at Microsoft.Synchronization.Data.SqlServer.SqlChangeHandler.ApplyBulkChanges(DataTable dataTable)#at Microsoft.Synchronization.SyncOrchestrator.Synchronize()#at SyncService.SyncService.SynchronizeDCM(DataRow dr, String SessionId)#ERROR SOURCE: Microsoft.Synchronization",
  "recordType" => "child",
  "splitText" => "at SyncService.SyncService.SynchronizeDCM(DataRow dr, String SessionId)",
  "messageText" => "SyncService.SynchronizeDCM(DataRow dr, String SessionId)",
  "subType" => "stackTraceApp"
}
{
  "@version" => "1",
  "@timestamp" => "2015-06-11T09:08:51.734Z",
  "host" => "127.0.0.1",
  "type" => "cloned",
  "tags" => [],
  "logLevel" => "ERROR",
  "logTimeString" => "2015-04-09 06:06:18",
  "inputType" => "foolproof_log",
  "logTime" => "2015-04-09T00:36:18.000Z",
  "mergedMessage" => "Type: Application, Error message: Failed to execute the command 'UpdateCommand' for table 'Item'; the transaction was rolled back. Ensure that the command syntax is correct.#ERROR OCCURRED FOR: at SynchronizeDCM() method in using block.. For Unit Id = 20847 and SDM Source = 10.25.7.1#ERROR DETAILS STACK:  at Microsoft.Synchronization.Data.ChangeHandlerBase.CheckZombieTransaction(String commandName, String table, Exception ex)#at Microsoft.Synchronization.Data.SqlServer.SqlChangeHandler.ApplyBulkChanges(DataTable dataTable)#at Microsoft.Synchronization.SyncOrchestrator.Synchronize()#at SyncService.SyncService.SynchronizeDCM(DataRow dr, String SessionId)#ERROR SOURCE: Microsoft.Synchronization",
  "recordType" => "child",
  "splitText" => "ERROR SOURCE: Microsoft.Synchronization",
  "errorSource" => "Microsoft.Synchronization",
  "subType" => "errorSource"
}

Snippet 11: Output — cloned records

About Part 2

In the second part of the article, I will describe how documents can be queried in Elasticsearch and also present the complete script.

About the Author

Bipin Patwardhan is a Sr. Technical Architect with IGATE Global Solutions. He is part of the Future and Emerging Technologies group. The group explores new and emerging technologies including 3D printing, wearable computing, analytics and augmented reality. The group creates service lines for enterprises using these technologies. He was earlier leading the High Performance Computing Centre of Excellence (CoE) and the Big Data CoE in the group.