Prebuilt ML jobs fail

Elastic Security SIEM
1

Hi, I have an issue with starting prebuilt ML jobs that use winlogbeat* data.
The job logs show that lookback returned no data but actually I am pretty sure that it is as SIEM dashboard shows winlogbeat events coming from hosts.

Below is the job log:

2020-04-09 13:57:15
instance-0000000001
Job created
2020-04-09 13:57:18
instance-0000000003
Loading model snapshot [N/A], job latest_record_timestamp [N/A]
2020-04-09 13:57:18
instance-0000000001
Opening job on node [{instance-0000000003}{cCeb5IuqRWSRmhKQarMmgQ}{1p8ZxYK3Qhq2wnL_ZOcYSA}{10.11.150.63}{10.11.150.63:19329}{l}{logical_availability_zone=zone-0, server_name=instance-0000000003.c46ce8659d3247238c4a3b4dc0b9457a, availability_zone=eu-central-1b, ml.machine_memory=1073741824, xpack.installed=true, instance_configuration=aws.ml.m5, ml.max_open_jobs=20, region=eu-central-1}]
2020-04-09 13:57:19
instance-0000000001
Starting datafeed [datafeed-home_windows_anomalous_network_activity_ecs] on node [{instance-0000000003}{cCeb5IuqRWSRmhKQarMmgQ}{1p8ZxYK3Qhq2wnL_ZOcYSA}{10.11.150.63}{10.11.150.63:19329}{l}{logical_availability_zone=zone-0, server_name=instance-0000000003.c46ce8659d3247238c4a3b4dc0b9457a, availability_zone=eu-central-1b, ml.machine_memory=1073741824, xpack.installed=true, instance_configuration=aws.ml.m5, ml.max_open_jobs=20, region=eu-central-1}]
2020-04-09 13:57:19
instance-0000000003
Datafeed started (from: 2020-03-31T21:00:00.000Z to: 2020-04-09T10:50:25.168Z) with frequency [450000ms]
2020-04-09 13:57:19
instance-0000000003
Datafeed lookback retrieved no data
2020-04-09 13:57:19
instance-0000000003
Datafeed stopped
2020-04-09 13:57:19
instance-0000000003
Job is closing

Any suggestions on what could be the cause or how to diagnose further would be bey appreciated.

Sorry for quite a noob question but I'd like to get a deployment up and running before digging deep.

Thanks

2

Hi - please show us the output of these 3 commands in DevTools console:

GET _ml/anomaly_detectors/home_windows_anomalous_network_activity_ecs

GET _ml/datafeeds/datafeed-home_windows_anomalous_network_activity_ecs

GET _ml/datafeeds/datafeed-home_windows_anomalous_network_activity_ecs/_preview

3

Thanks for jumping in. Below is the output:

GET _ml/anomaly_detectors/home_windows_anomalous_network_activity_ecs

{
  "count" : 1,
  "jobs" : [
    {
      "job_id" : "home_windows_anomalous_network_activity_ecs",
      "job_type" : "anomaly_detector",
      "job_version" : "7.6.2",
      "groups" : [
        "siem",
        "winlogbeat",
        "network"
      ],
      "description" : "SIEM Winlogbeat: Looks for unusual processes using the network which could indicate command-and-control, lateral movement, persistence, or data exfiltration activity (beta)",
      "create_time" : 1586429834716,
      "finished_time" : 1586433685999,
      "analysis_config" : {
        "bucket_span" : "15m",
        "detectors" : [
          {
            "detector_description" : "rare by \"process.name\"",
            "function" : "rare",
            "by_field_name" : "process.name",
            "detector_index" : 0
          }
        ],
        "influencers" : [
          "host.name",
          "process.name",
          "user.name",
          "destination.ip"
        ]
      },
      "analysis_limits" : {
        "model_memory_limit" : "64mb",
        "categorization_examples_limit" : 4
      },
      "data_description" : {
        "time_field" : "@timestamp",
        "time_format" : "epoch_ms"
      },
      "model_snapshot_retention_days" : 1,
      "custom_settings" : {
        "created_by" : "ml-module-siem-winlogbeat",
        "custom_urls" : [
          {
            "url_name" : "Host Details by process name",
            "url_value" : "siem#/ml-hosts/$host.name$?_g=()&query=(query:'process.name%20:%20%22$process.name$%22',language:kuery)&timerange=(global:(linkTo:!(timeline),timerange:(from:'$earliest$',kind:absolute,to:'$latest$')),timeline:(linkTo:!(global),timerange:(from:'$earliest$',kind:absolute,to:'$latest$')))"
          },
          {
            "url_name" : "Host Details by user name",
            "url_value" : "siem#/ml-hosts/$host.name$?_g=()&query=(query:'user.name%20:%20%22$user.name$%22',language:kuery)&timerange=(global:(linkTo:!(timeline),timerange:(from:'$earliest$',kind:absolute,to:'$latest$')),timeline:(linkTo:!(global),timerange:(from:'$earliest$',kind:absolute,to:'$latest$')))"
          },
          {
            "url_name" : "Hosts Overview by process name",
            "url_value" : "siem#/ml-hosts?_g=()&query=(query:'process.name%20:%20%22$process.name$%22',language:kuery)&timerange=(global:(linkTo:!(timeline),timerange:(from:'$earliest$',kind:absolute,to:'$latest$')),timeline:(linkTo:!(global),timerange:(from:'$earliest$',kind:absolute,to:'$latest$')))"
          },
          {
            "url_name" : "Hosts Overview by user name",
            "url_value" : "siem#/ml-hosts?_g=()&query=(query:'user.name%20:%20%22$user.name$%22',language:kuery)&timerange=(global:(linkTo:!(timeline),timerange:(from:'$earliest$',kind:absolute,to:'$latest$')),timeline:(linkTo:!(global),timerange:(from:'$earliest$',kind:absolute,to:'$latest$')))"
          }
        ]
      },
      "model_snapshot_id" : "1586433685",
      "results_index_name" : "custom-home_windows_anomalous_network_activity_ecs",
      "allow_lazy_open" : true
    }
  ]
}

For

GET _ml/datafeeds/datafeed-home_windows_anomalous_network_activity_ecs

{
  "count" : 1,
  "datafeeds" : [
    {
      "datafeed_id" : "datafeed-home_windows_anomalous_network_activity_ecs",
      "job_id" : "home_windows_anomalous_network_activity_ecs",
      "query_delay" : "85551ms",
      "indices" : [
        "winlogbeat-*"
      ],
      "query" : {
        "bool" : {
          "filter" : [
            {
              "term" : {
                "event.action" : "Network connection detected (rule: NetworkConnect)"
              }
            },
            {
              "term" : {
                "agent.type" : "winlogbeat"
              }
            }
          ],
          "must_not" : [
            {
              "bool" : {
                "should" : [
                  {
                    "term" : {
                      "destination.ip" : "127.0.0.1"
                    }
                  },
                  {
                    "term" : {
                      "destination.ip" : "127.0.0.53"
                    }
                  },
                  {
                    "term" : {
                      "destination.ip" : "::1"
                    }
                  }
                ],
                "minimum_should_match" : 1
              }
            }
          ]
        }
      },
      "scroll_size" : 1000,
      "chunking_config" : {
        "mode" : "auto"
      },
      "delayed_data_check_config" : {
        "enabled" : true
      },
      "max_empty_searches" : 10
    }
  ]
}

And for

GET _ml/datafeeds/datafeed-home_windows_anomalous_network_activity_ecs/_preview

[ ]
4

Great, thanks for the info. How about the results of this:

GET winlogbeat-*/_search
{
  "size": 0, 
  "query": {
    "bool": {
      "filter": {
        "term": {
          "event.action": "Network connection detected (rule: NetworkConnect)"
        }
      }
    }
  }
}
5

Sorry, output is really huge, I truncated it to limits of one post.

{
  "took" : 1,
  "timed_out" : false,
  "_shards" : {
    "total" : 1,
    "successful" : 1,
    "skipped" : 0,
    "failed" : 0
  },
  "hits" : {
    "total" : {
      "value" : 10000,
      "relation" : "gte"
    },
    "max_score" : 1.0,
    "hits" : [
      {
        "_index" : "winlogbeat-7.6.2-2020.04.08-000001",
        "_type" : "_doc",
        "_id" : "yOngWXEBbUnuSl8v2Em6",
        "_score" : 1.0,
        "_source" : {
          "@timestamp" : "2020-04-08T06:15:16.995Z",
          "winlog" : {
            "event_id" : 4688,
            "channel" : "Security",
            "provider_name" : "Microsoft-Windows-Security-Auditing",
            "api" : "wineventlog",
            "version" : 2,
            "process" : {
              "thread" : {
                "id" : 320
              },
              "pid" : 4
            },
            "task" : "Process Creation",
            "keywords" : [
              "Аудит успеха"
            ],
            "opcode" : "Сведения",
            "provider_guid" : "{54849625-5478-4994-a5ba-3e3b0328c30d}",
            "record_id" : 89184,
            "computer_name" : "dbi-721-1w10",
            "event_data" : {
              "TargetDomainName" : "NT AUTHORITY",
              "CommandLine" : """C:\WINDOWS\system32\svchost.exe -k LocalService -p -s SstpSvc""",
              "MandatoryLabel" : "S-1-16-16384",
              "ProcessId" : "0x2d8",
              "TokenElevationType" : "%%1936",
              "TargetUserSid" : "S-1-5-19",
              "SubjectUserName" : "DBI-721-1W10$",
              "SubjectDomainName" : "WORKGROUP",
              "TargetUserName" : "LOCAL SERVICE",
              "SubjectLogonId" : "0x3e7",
              "TargetLogonId" : "0x3e5",
              "SubjectUserSid" : "S-1-5-18"
            }
          },
          "host" : {
            "ip" : [
              "fe80::e1a0:dd82:9c5a:8a0d",
              "169.254.138.13",
              "fe80::ed41:40fd:aea:3b3d",
              "169.254.59.61",
              "fe80::ed9b:9f5a:d2da:36a6",
              "192.168.2.9",
              "fe80::81f:5981:bd5:884e",
              "169.254.136.78"
            ],
            "mac" : [
              "bc:5f:f4:ec:14:c8",
              "02:00:4c:4f:4f:50",
              "00:1e:8c:d6:3b:39",
              "00:1a:7d:da:71:07"
            ],
            "name" : "dbi-721-1w10",
            "hostname" : "dbi-721-1w10",
            "architecture" : "x86_64",
            "os" : {
              "version" : "10.0",
              "family" : "windows",
              "name" : "Windows 10 Pro",
              "kernel" : "10.0.18362.720 (WinBuild.160101.0800)",
              "build" : "18363.720",
              "platform" : "windows"
            },
            "id" : "7cf7e3d3-41ea-4876-b28c-cfe477f04698"
          },
          "tags" : [
            "Home",
            "WorkPC",
            "StephenT"
          ],
          "fields" : {
            "env" : "Home"
          },
          "user" : {
            "domain" : "WORKGROUP",
            "id" : "S-1-5-18",
            "name" : "DBI-721-1W10$"
          },
          "process" : {
            "pid" : 3712,
            "executable" : """C:\Windows\System32\svchost.exe""",
            "parent" : {
              "executable" : """C:\Windows\System32\services.exe""",
              "name" : "services.exe"
            },
            "name" : "svchost.exe",
            "args" : [
              "C:\\WINDOWS\\system32\\svchost.exe",
              "-k",
              "LocalService",
              "-p",
              "-s",
              "SstpSvc"
            ],
            "command_line" : """C:\WINDOWS\system32\svchost.exe -k LocalService -p -s SstpSvc"""
          },
          "agent" : {
            "ephemeral_id" : "668b18a0-c8e1-4648-b96b-adb415b49255",
            "hostname" : "dbi-721-1w10",
            "id" : "3ce4b11f-891a-44be-84f7-9d0d7654f342",
            "version" : "7.6.2",
            "name" : "ST_WorkPC",
            "type" : "winlogbeat"
          },
          "event" : {
            "action" : "created-process",
            "created" : "2020-04-08T13:00:34.141Z",
            "kind" : "event",
            "code" : 4688,
            "provider" : "Microsoft-Windows-Security-Auditing",
            "module" : "security",
            "category" : "process",
            "type" : "process_start"
          },
          "log" : {
            "level" : "сведения"
          },
          "message" : """Создан новый процесс.

Субъект-создатель:
	ИД безопасности:		S-1-5-18
	Имя учетной записи:		DBI-721-1W10$
	Домен учетной записи:		WORKGROUP
	ИД входа:		0x3E7

Целевой субъект:
	ИД безопасности:		S-1-5-19
	Имя учетной записи:		LOCAL SERVICE
	Домен учетной записи:		NT AUTHORITY
	ИД входа:		0x3E5

Сведения о процессе:
	ИД нового процесса:		0xe80
	Имя нового процесса:	C:\Windows\System32\svchost.exe
	Тип повышения прав маркера:	%%1936
	Обязательная метка:		S-1-16-16384
	ИД процесса-создателя:	0x2d8
	Имя процесса-создателя:	C:\Windows\System32\services.exe
	Командная строка процесса:	C:\WINDOWS\system32\svchost.exe -k LocalService -p -s SstpSvc

В поле "Тип повышения прав маркера" указан тип маркера, назначенного новому процессу в соответствии с политикой управления учетными записями.

Тип 1 соответствует полному маркеру без удаления привилегий и отключения групп. Полный маркер используется, только если управление учетными записями отключено либо пользователь имеет встроенную учетную запись "Администратор" или учетную запись службы.

Тип 2 соответствует расширенному маркеру без удаления привилегий и отключения групп. Расширенный маркер используется, если управление учетными записями включено и пользователь запускает программу в качестве администратора. Кроме того, он применяется, если приложение настроено таким образом, что всегда требует привилегии администратора или максимальные привилегии, а пользователь состоит в группе администраторов.

Тип 3 соответствует ограниченному маркеру с удалением привилегий администратора и отключением групп администраторов. Ограниченный маркер используется, когда управление учетными записями включено, приложению не требуются привилегии администратора и пользователь не запускает программу в качестве администратора.""",
          "ecs" : {
            "version" : "1.4.0"
          }
        }
      },
      {
        "_index" : "winlogbeat-7.6.2-2020.04.08-000001",
        "_type" : "_doc",
        "_id" : "yengWXEBbUnuSl8v2Em6",
        "_score" : 1.0,
        "_source" : {
          "@timestamp" : "2020-04-08T06:15:17.019Z",
          "event" : {
            "provider" : "Microsoft-Windows-Security-Auditing",
            "action" : "created-process",
            "created" : "2020-04-08T13:00:34.141Z",
            "kind" : "event",
            "code" : 4688,
            "module" : "security",
            "category" : "process",
            "type" : "process_start"
          },
          "log" : {
            "level" : "сведения"
          },
          "message" : """Создан новый процесс.

Субъект-создатель:
	ИД безопасности:		S-1-5-18
	Имя учетной записи:		DBI-721-1W10$
	Домен учетной записи:		WORKGROUP
	ИД входа:		0x3E7

Целевой субъект:
	ИД безопасности:		S-1-0-0
	Имя учетной записи:		-
	Домен учетной записи:		-
	ИД входа:		0x0

Сведения о процессе:
	ИД нового процесса:		0xe98
	Имя нового процесса:	C:\Program Files (x86)\Common Files\VMware\SerialPortRedirection\Client\vmwsprrdpwks.exe
	Тип повышения прав маркера:	%%1936
	Обязательная метка:		S-1-16-16384
	ИД процесса-создателя:	0x2d8
	Имя процесса-создателя:	C:\Windows\System32\services.exe
	Командная строка процесса:	"C:\Program Files (x86)\Common Files\VMware\SerialPortRedirection\Client\vmwsprrdpwks.exe"

В поле "Тип повышения прав маркера" указан тип маркера, назначенного новому процессу в соответствии с политикой управления учетными записями.

Тип 1 соответствует полному маркеру без удаления привилегий и отключения групп. Полный маркер используется, только если управление учетными записями отключено либо пользователь имеет встроенную учетную запись "Администратор" или учетную запись службы.

Тип 2 соответствует расширенному маркеру без удаления привилегий и отключения групп. Расширенный маркер используется, если управление учетными записями включено и пользователь запускает программу в качестве администратора. Кроме того, он применяется, если приложение настроено таким образом, что всегда требует привилегии администратора или максимальные привилегии, а пользователь состоит в группе администраторов.

Тип 3 соответствует ограниченному маркеру с удалением привилегий администратора и отключением групп администраторов. Ограниченный маркер используется, когда управление учетными записями включено, приложению не требуются привилегии администратора и пользователь не запускает программу в качестве администратора.""",
          "winlog" : {
            "channel" : "Security",
            "api" : "wineventlog",
            "process" : {
              "thread" : {
                "id" : 96
              },
              "pid" : 4
            },
            "task" : "Process Creation",
            "version" : 2,
            "event_data" : {
              "TargetUserSid" : "S-1-0-0",
              "TargetUserName" : "-",
              "ProcessId" : "0x2d8",
              "TargetLogonId" : "0x0",
              "SubjectUserSid" : "S-1-5-18",
              "TargetDomainName" : "-",
              "TokenElevationType" : "%%1936",
              "MandatoryLabel" : "S-1-16-16384",
              "CommandLine" : "\"C:\\Program Files (x86)\\Common Files\\VMware\\SerialPortRedirection\\Client\\vmwsprrdpwks.exe\"",
              "SubjectUserName" : "DBI-721-1W10$",
              "SubjectDomainName" : "WORKGROUP",
              "SubjectLogonId" : "0x3e7"
            },
            "event_id" : 4688,
            "computer_name" : "dbi-721-1w10",
            "keywords" : [
              "Аудит успеха"
            ],
            "provider_name" : "Microsoft-Windows-Security-Auditing",
            "record_id" : 89185,
            "opcode" : "Сведения",
            "provider_guid" : "{54849625-5478-4994-a5ba-3e3b0328c30d}"
          },
          "tags" : [
            "Home",
            "WorkPC",
            "StephenT"
          ],
          "fields" : {
            "env" : "Home"
          },
          "ecs" : {
            "version" : "1.4.0"
          },
          "host" : {
            "id" : "7cf7e3d3-41ea-4876-b28c-cfe477f04698",
            "ip" : [
              "fe80::e1a0:dd82:9c5a:8a0d",
              "169.254.138.13",
              "fe80::ed41:40fd:aea:3b3d",
              "169.254.59.61",
              "fe80::ed9b:9f5a:d2da:36a6",
              "192.168.2.9",
              "fe80::81f:5981:bd5:884e",
              "169.254.136.78"
            ],
            "mac" : [
              "bc:5f:f4:ec:14:c8",
              "02:00:4c:4f:4f:50",
              "00:1e:8c:d6:3b:39",
              "00:1a:7d:da:71:07"
            ],
            "hostname" : "dbi-721-1w10",
            "architecture" : "x86_64",
            "name" : "dbi-721-1w10",
            "os" : {
              "name" : "Windows 10 Pro",
              "kernel" : "10.0.18362.720 (WinBuild.160101.0800)",
              "build" : "18363.720",
              "platform" : "windows",
              "version" : "10.0",
              "family" : "windows"
            }
          },
          "user" : {
            "id" : "S-1-5-18",
            "name" : "DBI-721-1W10$",
            "domain" : "WORKGROUP"
          },
          "process" : {
            "command_line" : "\"C:\\Program Files (x86)\\Common Files\\VMware\\SerialPortRedirection\\Client\\vmwsprrdpwks.exe\"",
            "pid" : 3736,
            "executable" : """C:\Program Files (x86)\Common
6

Hmm...you didn't run the query that I asked. I can tell because:

a) I asked for the size to be 0 so as for you to not expose the details of your data, and
b) asked for the data to be filtered for a specific value of event.action that is "Network connection detected (rule: NetworkConnect)" because that's what the ML job's datafeed does. The example output you provided clearly shows a value of event.action to be "created-process"

I asked for that specific information because I suspected that you don't really have any (or very few) events in your index of the type that the ML job is looking for. I was hoping the query I suggested would prove or disprove that theory.

7

Yep, it looks like you are right. I've copy-pasted the query from e-mail and it looks like it did not run correctly. Sorry for that.

Below is the output I believe you were looking for:

{
  "took" : 1,
  "timed_out" : false,
  "_shards" : {
    "total" : 1,
    "successful" : 1,
    "skipped" : 0,
    "failed" : 0
  },
  "hits" : {
    "total" : {
      "value" : 10000,
      "relation" : "gte"
    },
    "max_score" : null,
    "hits" : [ ]
  }
}
8

One more request, if you please. What is the output of the following:

GET winlogbeat-*/_search
{
  "size": 0, 
  "query": {
    "bool": {
      "filter": {
        "term": {
          "event.action": "Network connection detected (rule: NetworkConnect)"
        }
      }
    }
  },
  "aggs": {
    "per_day": {
      "date_histogram": {
        "field": "@timestamp",
        "calendar_interval": "1d"
      }
    }
  }
}

I just want to see the number of these kinds of events per day in your index...

9

Hi Rich,

Here you are.

{
  "took" : 74,
  "timed_out" : false,
  "_shards" : {
    "total" : 1,
    "successful" : 1,
    "skipped" : 0,
    "failed" : 0
  },
  "hits" : {
    "total" : {
      "value" : 10000,
      "relation" : "gte"
    },
    "max_score" : null,
    "hits" : [ ]
  },
  "aggregations" : {
    "per_day" : {
      "buckets" : [
        {
          "key_as_string" : "2020-04-09T00:00:00.000Z",
          "key" : 1586390400000,
          "doc_count" : 26969
        },
        {
          "key_as_string" : "2020-04-10T00:00:00.000Z",
          "key" : 1586476800000,
          "doc_count" : 29353
        },
        {
          "key_as_string" : "2020-04-11T00:00:00.000Z",
          "key" : 1586563200000,
          "doc_count" : 15209
        },
        {
          "key_as_string" : "2020-04-12T00:00:00.000Z",
          "key" : 1586649600000,
          "doc_count" : 1281
        },
        {
          "key_as_string" : "2020-04-13T00:00:00.000Z",
          "key" : 1586736000000,
          "doc_count" : 17642
        },
        {
          "key_as_string" : "2020-04-14T00:00:00.000Z",
          "key" : 1586822400000,
          "doc_count" : 19292
        },
        {
          "key_as_string" : "2020-04-15T00:00:00.000Z",
          "key" : 1586908800000,
          "doc_count" : 13685
        },
        {
          "key_as_string" : "2020-04-16T00:00:00.000Z",
          "key" : 1586995200000,
          "doc_count" : 29048
        },
        {
          "key_as_string" : "2020-04-17T00:00:00.000Z",
          "key" : 1587081600000,
          "doc_count" : 25390
        },
        {
          "key_as_string" : "2020-04-18T00:00:00.000Z",
          "key" : 1587168000000,
          "doc_count" : 8313
        },
        {
          "key_as_string" : "2020-04-19T00:00:00.000Z",
          "key" : 1587254400000,
          "doc_count" : 4896
        },
        {
          "key_as_string" : "2020-04-20T00:00:00.000Z",
          "key" : 1587340800000,
          "doc_count" : 4937
        }
      ]
    }
  }
}
10

Thanks for this - it seems apparent that you have plenty of historical data (well at least from April 9)

Can you try starting/running the datafeed again, and choose April 9th as the starting date?

11

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.