Logs - ElasticSearch

Help Insights
,
6

Hi @Felipe_Kotinda,

That is correct. The data flow is

Robot Execution log (Robot Machine) - .txt → Orchestrator log (Orchestrator Machine) - .txt →
Splunk Forwarder (on both Robot Machine and Orchestrator Machine) →
Splunk Index → Splunk Query → Splunk Dashboard / Report

One thing to note here is we use dedup (remove duplicates) in Splunk so that our dashboards do not contain results from both Robot and Orchestrator Logs.

Retentionpolicy is set to 1 year after which we still have access to the .txt files on robot and orchestrator machines. We can consume the .txt files again in the future. A rough estimate after close 8 months of robot execution (6 processes) our .txt log files are around 400 mb on DEV and around double that in production. Which is easy work for a tool like Splunk to parse.

All logs in Development and Production are also sent to a dedicated SQL in Dev and Prod environments, which we treat as a rainy day fund. If not Splunk, we can still can use the logs stored in SQL to create our dashboards in any other tool.

As you see, we try to keep a backup of everything. We never know when we might stop using Splunk. It is best to keep the logs as simple and in a basic format in auto backup drive within your organization. Gives you agility.

Starter help
Let me share our <target> and <rules> tag here as they are quite generic and not sensitive information. Anyone else wanting to customize NLog can use this as well and save a lot of time googling :slight_smile:

As a team of 3, it took us a while to get these following targets tweaked to our needs. The TotalExecutionTimeSeconds=${event-properties:item=totalExecutionTimeInSeconds} is brilliant to have. The below files lets us slice and dice our query based on Process / Host / Robot / Time / Message / QueueName.

Create two variables in web.config for Robot and Orchestrator logging directory like so.

<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" autoReload="true" throwExceptions="false" internalLogLevel="Off" internalLogFile="">
     <variable name="RobotLoggingDirectory" value="E:/Logs/UiPath/Robot" /> 
     <variable name="OrchestratorLoggingDirectory" value="E:/Logs/UiPath/Orchestrator" /> 
     <extensions>
     </extensions>
     <targets>
     </targets>
     <rules>
     </rules>
</nlog>

In the <targets> tag of web.config we log to SQL (This is usually a default in web.config file):

        <target xsi:type="Database" connectionStringName="Default" keepConnection="true">
          <commandText>
            INSERT INTO dbo.Logs (OrganizationUnitId, TenantId, TimeStamp, Level, WindowsIdentity, ProcessName, JobKey, Message, RawMessage, RobotName, MachineId, UserKey)
            VALUES (@organizationUnitId, @tenantId, @timeStamp, @level, @windowsIdentity, @processName, @jobId, @message, @rawMessage, @robotName, @machineId, @userKey)
          </commandText>
          <parameter name="@organizationUnitId" layout="${event-properties:item=organizationUnitId}" />
          <parameter name="@tenantId" layout="${event-properties:item=tenantId}" />
          <parameter name="@timeStamp" layout="${date:format=yyyy-MM-dd HH\:mm\:ss.fff}" />
          <parameter name="@level" layout="${event-properties:item=levelOrdinal}" />
          <parameter name="@windowsIdentity" layout="${event-properties:item=windowsIdentity}" />
          <parameter name="@processName" layout="${event-properties:item=processName}" />
          <parameter name="@jobId" layout="${event-properties:item=jobId}" />
          <parameter name="@message" layout="${message}" />
          <parameter name="@rawMessage" layout="${event-properties:item=rawMessage}" />
          <parameter name="@robotName" layout="${event-properties:item=robotName}" />
          <parameter name="@machineId" layout="${event-properties:item=machineId}" />
          <parameter name="@userKey" layout="${event-properties:item=userKey}" />
        </target>
      </target>

web.config RobotLogs to custom RobotLogFile:

<target type="File" name="robotLogFile" fileName="${RobotLoggingDirectory}/${shortdate}_Execution.log" layout="${date:format=yyyy-MM-dd HH\:mm\:ss.fff} RobotName=&quot;${event-properties:item=robotName}&quot; Message=&quot;${message}&quot; ProcessName=&quot;${event-properties:item=processName}&quot; Machine=&quot;${machinename}&quot; Level=&quot;${level}&quot; TotalExecutionTimeSeconds=${event-properties:item=totalExecutionTimeInSeconds} TenantID=&quot;${event-properties:item=tenantId}&quot;" keepFileOpen="true" openFileCacheTimeout="5" concurrentWrites="true" encoding="utf-8" writeBom="true" />

web.config OrchestratorLogs to custom OrchestratorLogFile:

<target type="File" name="orchestratorLogFile" fileName="${OrchestratorLoggingDirectory}/${shortdate}_Execution.log" layout="${date:format=yyyy-MM-dd HH\:mm\:ss.fff} Message=&quot;${message}&quot; ProcessName=&quot;${event-properties:item=processName}&quot; Machine=&quot;${machinename}&quot; Level=&quot;${level}&quot; TotalExecutionTimeSeconds=${event-properties:item=totalExecutionTimeInSeconds} TenantID=&quot;${event-properties:item=tenantId}&quot;" keepFileOpen="true" openFileCacheTimeout="5" concurrentWrites="true" encoding="utf-8" writeBom="true" />

Nlog needs predefined rule set - here the order of the rules matter.

<rules>
      <logger name="Robot.*" ruleName="insightsRobotLogsRule" enabled="false" minlevel="Info" writeTo="insightsRobotLogs">
        <filters defaultAction="Ignore">
          <when condition="level >= LogLevel.Error or ends-with('${message}',' execution ended')" action="Log" />
        </filters>
      </logger>
	  <logger name="Robot.*" minlevel="Info" writeTo="robotLogFile" />
	  <logger name="*" minlevel="Info" writeTo="orchestratorLogFile" />
      <logger name="BusinessException.*" minlevel="Info" writeTo="businessExceptionEventLog" final="true" />
      <logger name="Robot.*" ruleName="primaryRobotLogsTarget" final="true" writeTo="database" />
      <logger name="Monitoring.*" writeTo="monitoring" minlevel="Warn" final="true" />
      <logger name="Quartz.*" minlevel="Warn" writeTo="eventLogQuartz" final="true" />
      <logger name="*" minlevel="Info" writeTo="eventLog" />
    </rules>

In Splunk
A query for Robot Runtime would be (we have a custom Message which reports robot runtime and also the QueueName)

index="YOUR_INDEX" host="YOUR_HOSTNAME" ProcessName="YOUR_PROCESS" Message="*The total execution time in seconds of dispatcher is :*QueueName :*" 
| dedup _time consecutive=true    ``` Remove Duplicates```
| rex "The total execution time in seconds of dispatcher is\s:\s(?<TotalExecutionTimeSecondsDis>\d{0,100})"   ``` Regex TotalExecutionTimeSecondsDis```
| convert auto("TotalExecutionTimeSecondsDis") as TotalExecutionTime   ``` Conver to double```
| eval SumExecutionTimeHours = sum(TotalExecutionTime)/(60*60)   ``` Convert to hours ```
| stats sum(SumExecutionTimeHours) as "TotalRobotExecutionTime"   ``` Sum hours ```
| fields TotalRobotExecutionTime  ``` Return only the required fields, ignore others ```

For advanced Splunk users, yes we can also use a single base query and build dashboards on it but not reports. This way Splunk has to parse the logs / index only once per refresh of the dashboards and not execute individual query for each panel in the dashboard. Our Splunk team recommended using base search.

Example of base search in Splunk

<search id="dispatcher">
    <query>
      index="YOUR_INDEX" host="$host_name$" ProcessName="Process_Dispatcher*" 
    </query>
    <earliest>$time_token.earliest$</earliest>
    <latest>$time_token.latest$</latest>
  </search>
  <search id="performer">
    <query>
      index="YOUR_INDEX" host="$host_name$" ProcessName="Process_Performer*" 
    </query>
    <earliest>$time_token.earliest$</earliest>
    <latest>$time_token.latest$</latest>
  </search>
  <row>

<panel>
      <single>
        <title>Robot Runtime (Hours)</title>
        <search base="performer">
          <query>
                   | dedup _time consecutive=true    ``` Remove Duplicates```
                   | rex "The total execution time in seconds of performer is\s:\s(?<TotalExecutionTimeSecondsDis>\d{0,100})"   ``` Regex TotalExecutionTimeSecondsDis```
                   | convert auto("TotalExecutionTimeSecondsDis") as TotalExecutionTime   ``` Conver to double```
                   | eval SumExecutionTimeHours = sum(TotalExecutionTime)/(60*60)   ``` Convert to hours ```
                   | stats sum(SumExecutionTimeHours) as "TotalRobotExecutionTime"   ``` Sum hours ```
                   | fields TotalRobotExecutionTime  ``` Return only the required fields, ignore others ```
         </query>
        </search>
        <option name="drilldown">none</option>
        <option name="height">84</option>
        <option name="numberPrecision">0.00</option>
        <option name="rangeColors">["0x53a051","0x0877a6","0xf8be34","0xf1813f","0xdc4e41"]</option>
        <option name="refresh.display">progressbar</option>
        <option name="underLabel">Timer</option>
      </single>
    </panel>
 </row>

Hope this helps you and others.

1 Like