Extract value from message field ( runtime fields)

Hello everyone,

Currently, I have an OpenVPN log that is sent from the server to elastic... from what I see the fields are pretty generic and the most important one is "message", it has all the information and I can't parse it.

The most straightforward alternative is to go to "Index Patterns" and create a new field and then create a "runtime fields" script... but apparently, I can't find a convention to extract specific values ​​from the message field because it throws me several errors...

Does anyone have an example of something like this done and working?

I mean create a field called "test" for example and create a "runtime fields" script that extracts a value from the message field and displays it

thanks

Hi @jplopezy Welcome to the community!

The easiest way to help would be to provide a couple sample of the log lines and what you want the result to look like (in detail)

Runtime is pretty good but perhaps you should consider and ingest pipeline and parse the message field.

Provide the before (message) and after (parsed) and perhaps someone can help you.

@stephenb

Thanks for the prompt response.

I paste an example log line

cat /var/log/openvpnas.log | grep CN / message field from log

127.0.0.1:52118 VERIFY OK: depth=0, /CN=username'

Expectation of result :

new field with this value : username

How could I create a field that extracts the username of that line from the message?

thanks

Ok please provide a couple FULL samples in text (anonymized)... screen shot does no good...

Also I will say it again an ingest pipeline would probably put you in a better position long term (faster queries etc)

But sure you can start with a runtme but several full line in text not screen shot...

Is the message field the full above or just partial... be clear help us help you :slight_smile:

@stephenb

ok

--------------------------------------LOG EXAMPLE ---------------------------------------------

2019-09-23T17:42:15+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:42:15 2019 lan-with-inet_AUTOLOGIN/Hide-my-ip:5287 SIGTERM[soft,remote-exit] received, client-instance exiting'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 TLS: Initial packet from [AF_INET]Hide-my-ip:7305 (via [AF_INET]172.31.39.10%eth0), sid=bf88a737 3fad61b9'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 VERIFY OK: depth=1, /CN=OpenVPN CA'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 VERIFY OK: nsCertType=CLIENT'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 VERIFY OK: depth=0, /CN=lan-with-inet_AUTOLOGIN'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: IV_GUI_VER=ovpnmi_1.0.0'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: IV_VER=3.2__qa:d87f5bbc04)'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: IV_PLAT=win'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: IV_NCP=2'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: IV_TCPNL=1'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: IV_PROTO=2'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: IV_LZO=1'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: IV_LZO_SWAP=1'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: IV_LZ4=1'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: IV_LZ4v2=1'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: IV_COMP_STUB=1'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: IV_COMP_STUBv2=1'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: IV_AUTO_SESS=1'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: UV_ASCLI_VER=2.7.1.101'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: UV_PLAT_REL=Windows_10_Enterprise_6.3.18362'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 peer info: IV_HWADDR=2c:56:dc:49:bf:34'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: "Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 TLS: Username/Password authentication deferred for username '' "
2019-09-23T17:49:32+0000 [stdout#info] ::.[usersvc.py, Line 571] Client created.::
2019-09-23T17:49:32+0000 [stdout#info] **** CLIENT_CONNECT User=u'lan-with-inet', CN=u'lan-with-inet_AUTOLOGIN', DID/CID=('1', 3), SerList=()
2019-09-23T17:49:32+0000 [stdout#info] FORCE_UNIQUE True
2019-09-23T17:49:32+0000 [stdout#info] CC_CMDS
2019-09-23T17:49:32+0000 [stdout#info] compress stub-v2
2019-09-23T17:49:32+0000 [stdout#info] push "compress stub-v2"
2019-09-23T17:49:32+0000 [stdout#info] push "redirect-gateway def1"
2019-09-23T17:49:32+0000 [stdout#info] push "redirect-gateway bypass-dhcp"
2019-09-23T17:49:32+0000 [stdout#info] push "redirect-gateway autolocal"
2019-09-23T17:49:32+0000 [stdout#info] ifconfig-push 172.27.232.5 255.255.248.0
2019-09-23T17:49:32+0000 [stdout#info] push "route-gateway 172.27.232.1"
2019-09-23T17:49:32+0000 [stdout#info] push "dhcp-option DNS 172.31.0.2"
2019-09-23T17:49:32+0000 [stdout#info] push "register-dns"
2019-09-23T17:49:32+0000 [stdout#info] push "block-ipv6"
2019-09-23T17:49:32+0000 [stdout#info] ACTIONS
2019-09-23T17:49:32+0000 [stdout#info] <ActionIPT u'iptables -t filter -R AS0_OUT 1 -d 172.27.232.5 -j AS0_U_LANWITHI_OUT'>
2019-09-23T17:49:32+0000 [stdout#info] <ActionEffect func=<function <lambda> at 0x7fbd3911fcf8> type='mod_inc'>
2019-09-23T17:49:32+0000 [stdout#info] UNDO_ACTIONS
2019-09-23T17:49:32+0000 [stdout#info] <ActionEffect func=<function <lambda> at 0x7fbd388eb500> type='dynamic_ip'>
2019-09-23T17:49:32+0000 [stdout#info] <ActionIPT 'iptables -t filter -R AS0_OUT 1 -d 0.0.0.0'>
2019-09-23T17:49:32+0000 [stdout#info] <ActionEffect func=<function <lambda> at 0x7fbd3911f8c0> type='mod_dec'>
2019-09-23T17:49:32+0000 [stdout#info] ****
2019-09-23T17:49:32+0000 [stdout#info] AUTH SUCCESS {'status': 0, 'reason': 'AuthTrue: autologin certificate auth succeeded', 'serial_list': [], 'user': u'lan-with-inet', 'proplist': {u'prop_autologin': u'true', u'prop_force_lzo': u'false', u'pvt_password_digest': '[redacted]', u'type': u'user_compile', u'prop_autogenerate': u'true'}, 'common_name': u'lan-with-inet_AUTOLOGIN', 'serial': '4'} cli=u'win'/u'3.2__qa:d87f5bbc04)'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: "Mon Sep 23 17:49:32 2019 MANAGEMENT: CMD 'client-auth 3 0'"
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 [lan-with-inet_AUTOLOGIN] Peer Connection Initiated with [AF_INET]Hide-my-ip:7305 (via [AF_INET]172.31.39.10%eth0)'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 lan-with-inet_AUTOLOGIN/Hide-my-ip:7305 OPTIONS IMPORT: compression parms modified'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 lan-with-inet_AUTOLOGIN/Hide-my-ip:7305 MULTI: Learn: 172.27.232.5 -> lan-with-inet_AUTOLOGIN/Hide-my-ip:7305'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 lan-with-inet_AUTOLOGIN/Hide-my-ip:7305 MULTI: primary virtual IP for lan-with-inet_AUTOLOGIN/Hide-my-ip:7305: 172.27.232.5'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: "Mon Sep 23 17:49:32 2019 lan-with-inet_AUTOLOGIN/Hide-my-ip:7305 PUSH: Received control message: 'PUSH_REQUEST'"
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: "Mon Sep 23 17:49:32 2019 lan-with-inet_AUTOLOGIN/Hide-my-ip:7305 SENT CONTROL [lan-with-inet_AUTOLOGIN]: 'PUSH_REPLY,explicit-exit-notify,topology subnet,route-delay 5 30,dhcp-pre-release,dhcp-renew,dhcp-release,route-metric 101,ping 12,ping-restart 50,compress stub-v2,redirect-gateway def1,redirect-gateway bypass-dhcp,redirect-gateway autolocal,route-gateway 172.27.232.1,dhcp-option DNS 172.31.0.2,register-dns,block-ipv6,ifconfig 172.27.232.5 255.255.248.0,peer-id 0,auth-tokenSESS_ID,cipher AES-256-GCM' (status=1)"
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: "Mon Sep 23 17:49:32 2019 lan-with-inet_AUTOLOGIN/Hide-my-ip:7305 Data Channel: using negotiated cipher 'AES-256-GCM'"
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: "Mon Sep 23 17:49:32 2019 lan-with-inet_AUTOLOGIN/Hide-my-ip:7305 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key"
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: "Mon Sep 23 17:49:32 2019 lan-with-inet_AUTOLOGIN/Hide-my-ip:7305 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key"
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 lan-with-inet_AUTOLOGIN/Hide-my-ip:7305 IP packet with unknown IP version=0 seen'

And you only want to extract the username from the these 2 logs... after the /CN=
And the rest of the logs... no user field?

2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 VERIFY OK: depth=1, /CN=OpenVPN CA'
2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 VERIFY OK: depth=0, /CN=lan-with-inet_AUTOLOGIN'

For the moment I want to know how to do that... once I understand it I can do it myself... as I said... I just want an example

Thanks... I appreciate you patience and detail, and I am happy to provide an example / solutions, I have just learned that we will both get to and answer quicker if I have a good understanding exactly what you are looking for... your initial post was not enough detail.

To add a runtime field that you want to search on you have to add it to the mappings see here and some examples... and remember it is added as a field not to the _source so you will be able to search on it, use it in visualizations and access but it will not be in the _source json

My index is named

discuss-openvpn

I indexed your data into the message field and then I added this

This is THE most Brute Force way to do this ... there are probably more elegant ways.. but as you said you just wanted and example.

This basically will parse use the grok and for the lines that do not match the username field is not created for those that do.. username will be emitted

PUT discuss-openvpn/_mappings
{
  "runtime": {
    "username": {
      "type": "keyword",
      "script": """
        String username=grok('%{GREEDYDATA:leading_data}/CN=%{DATA:username}\'').extract(doc["message"].value)?.username;
        if (username != null) emit(username); 
      """
    }
  }
}

Then when I search for this and note it is in the fields not _source

GET discuss-openvpn/_search
{
  "fields": [
    "*"
  ],
  "query": {
    "exists": {
      "field": "username"
    }
  }
}

#results

{
  "took": 4,
  "timed_out": false,
  "_shards": {
    "total": 1,
    "successful": 1,
    "skipped": 0,
    "failed": 0
  },
  "hits": {
    "total": {
      "value": 2,
      "relation": "eq"
    },
    "max_score": 1,
    "hits": [
      {
        "_index": "discuss-openvpn",
        "_id": "uYPrgIIBkiWX4SWKF193",
        "_score": 1,
        "_source": {
          "@timestamp": "2022-08-09T00:57:30.000Z",
          "message": "2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 VERIFY OK: depth=1, /CN=OpenVPN CA'"
        },
        "fields": {
          "@timestamp": [
            "2022-08-09T00:57:30.000Z"
          ],
          "message": [
            "2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 VERIFY OK: depth=1, /CN=OpenVPN CA'"
          ],
          "username": [
            "OpenVPN CA"
          ]
        }
      },
      {
        "_index": "discuss-openvpn",
        "_id": "u4PrgIIBkiWX4SWKoF-7",
        "_score": 1,
        "_source": {
          "@timestamp": "2022-08-09T00:57:30.000Z",
          "message": "2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 VERIFY OK: depth=0, /CN=lan-with-inet_AUTOLOGIN'"
        },
        "fields": {
          "@timestamp": [
            "2022-08-09T00:57:30.000Z"
          ],
          "message": [
            "2019-09-23T17:49:32+0000 [stdout#info] [OVPN 1] OUT: 'Mon Sep 23 17:49:32 2019 Hide-my-ip:7305 VERIFY OK: depth=0, /CN=lan-with-inet_AUTOLOGIN'"
          ],
          "username": [
            "lan-with-inet_AUTOLOGIN"
          ]
        }
      }
    ]
  }
}

And it also shows up in Discover

@stephenb

Thanks for all the information.. I'm learning a lot.

What I don't understand is if when I create a new index I have to reference the origin of the data...

Following your example I generated an index with just

"PUT discuss-openvpn"

and then the PUT you sent me...

After that I create an "index pattern" and associate the index "discuss-openvpn" to it and everything seems fine but I don't see the logs... as if the "logs-*" type wasn't referenced

I'm missing something?

thanks

The discuss-openvpn index is just my example...

You need to replace that with the actual name of your indices...

What / how are you ingesting the logs?

What version are you on?

What is the result of running

GET _cat/indices/?v

@stephenb

On the openvpn server I have the "elastic 7.15.1" agent installed that takes the logs from "/var/log/openvpnas.log"...

On the kibana side, I have an index called "logs-*" that shows me everything... but I wouldn't like to touch that for its integrity but I don't know how to create a new index that points to those agent logs

thanks

That is not an index... that is an index pattern,,, 2 different but related items
an index pattern is an "alias" that points to a collection of actual indices.

I am not asking you to create an index.

You asked how to create a runtime field, I am showing you... you add a runtime field TO an existing index.

Go to Kibana -> Dev Tools and run

GET _cat/indices/?v

That is a read only command... which will list the actual indices... not the index pattern.

I can also show you how to add the runtime field to the index pattern, which then the runtime field will only show in visualizations and discover that use the index pattern not searches etc as it is not actually added to the indices.... perhaps that is what you want ... instead...

There is a reason I ask a lot of question when people are just getting started :slight_smile:

So which do you want to do

a) Add a runtime field to and index ... which provides more flexibilty but involves updating / adding the runtime field to each index

b) Add the runtime field to the index-pattern logs-* so that you can see it in Discover and Visualizations and KQL but will not be available in DSL queries (detailed / low level queries)

@stephenb

Sorry... maybe I got confused.

Option "a" I want to create an "index API" from scratch that points to the logs of the agent that I mentioned... what you showed me was the most important thing and it was what I needed but I realized that I should create a new index api so as not to touch the existing ones.

thanks,

Well I think you are trying to create a new index, not an Index API (index API is an existing set of REST interfaces as defined by Elasticsearch see here. ..

And index is the collection or logs / documents stored in elasticsearch ...that is managed via the Index APIs

So back to choice a) Does that that means you want to load the logs data into a new / different index so you can test with it? if so you have 2 choices

a1) Reload the data into a new / another index from scratch using the same method which the data was originally loaded
a2) Pick one of the actual indices and Reindex (i.e. make a copy of it) then work with that.

Which do you want? (so this is getting to be more than just show me a runtime field)

OR you can add a runtime field to an existing index which is non destructive but it does mean adding to its mapping / schema ..

So what is your next choice?

Plus you did not show me the output of which we will need if you choose a2) and really it will help overall.

Go to Kibana -> Dev Tools and run

GET _cat/indices/?v

@stephenb

Unfortunately, I don't have access to "_cat/indices/" they have little faith in me hahaha.

I think I've understood... on the one hand, I generated a new index, then I added the runtime to that index (PUT with gork script).

Finally, generate an "Index pattern" that has the index and the data stream.

When I go to discover I can see the logs but the "username" field does not bring me anything

What am I doing wrong?

You are mixing / not quite getting the concepts.

You are adding a runtime field to an empty index, then you are adding that empty index to an index pattern, and expecting the runtime field that is ONLY on the empty index to work on all the other indices you did not add the runtime field too ... it will not work.

So now I will be prescriptive... as you are much closer to option b so lets do that to start.

First delete the empty index you created...

DELETE openvpn-dashboard

Then delete your open Index Pattern

Then recreate and index pattern lets use logs-openvpn-* and Add Field

Then setup the runtime field

the code

String username=grok('%{GREEDYDATA:leading_data}/CN=%{DATA:username}\'').extract(doc["message"].value)?.username;
if (username != null) emit(username); 

Then Discover with your new index pattern,,,
You should see the fields

If you are going to be working with elasticsearch and kibana perhaps it would be of benefit to take some of the free training vids / webinars and or the getting started docs etc.

Perhaps Learn about Index, Index Template, Mappings, Data Streams, Data Types, Index Pattern/ Data Views etc

@stephenb

I remember that I tried that but there it gave me an error because of the type of format...

Where was that error on Doscover?

That is because your logs message field is a special type match_only_text that does not support grok / runtime fields... so all this is for not.. nothing I can do about that... or at least nothing obvious.

Can you show the lists of fields on your index patterns?

List of fields index patterns:

so I can't use "runtime field" for the message field which is of type text? is there a plan b?

Discover:

what do you think about this option?

Not Possible, You have to do that before you index the data ... not after ... you can not change the mapping of a field i.e. the datatype after it has been indexed...

If you already have data that is indexed ... you can not change the type... period.
You can add runtime fields but they need do not operate on all types of data.

Per Here

The runtime section can be any of these data types:

  • boolean
  • composite
  • date
  • double
  • geo_point
  • ip
  • keyword
  • long
  • lookup