Debugging test.log-expected.json

Elastic Stack Beats
1

I'm trying to create a module for filebeat. The tests involving test.log and test.log-expected.json are failing. I'm having a hard time figuring out why.

Are there files in build that would give hints? Is there a way to get the test (I'm doing make testsuite) to save the results of ingesting test.log so I can compare?

Yes, I know about the grok debugger(s) available. Testing in logstash resulted in some fields I want to drop (e.g., host, message, @version). I'm also using the date processor to use the parsed timestamp from the log as @timestamp. So, I'm not completely sure what fields should appear and in what format (i.e., @timestamp). Being able to see what's generated and compared to test.log-expected.json would be a huge help.

Many thanks in advance....

P.S. I set up the dev environment within the past few weeks, so the version should be current.

P.P.S. In case it's helpful, here are my ingest/pipeline.json, test.log, and test.log-expected.json:

ingest/pipeline.json:

{
    "description": "Pipeline for parsing module_name request logs",
    "processors": [
        {
            "grok": {
                "field": "message",
                "patterns": [
                    "%{IPORHOST:clientip} %{USER:ident} %{USER:auth} \\[%{HTTPDATE:timestamp}\\] \"(?:%{WORD:verb} %{NOTSPACE:request}(?: HTTP/%{NUMBER:httpversion})?|%{DATA:rawrequest})\" %{NUMBER:response} (?:%{NUMBER:resp_time_ms:integer}|-) (?:%{NUMBER:bytes:integer}|-)"
                ]
            }
        },
        {
            "date" : {
                "field" : "timestamp",
                "formats" : ["dd/MMM/yyyy:HH:mm:ss Z"]
            }
        },
        {
            "remove": {
                "field": ["message", "@version", "host", "timestamp"]
            }
        }
    ],
    "on_failure" : [{
        "set" : {
        "field" : "error.message",
        "value" : "{{ _ingest.on_failure_message }}"
        }
    }]
}

test.log:

4.79.43.180 - - [24/Dec/2019:18:35:04 +0000] "GET /poll.rest?userId=10637&muxId=4P7OKlCVKTXBOgfP&seq=2 HTTP/1.1" 200 11 30002
4.79.43.180 - - [24/Dec/2019:18:35:34 +0000] "GET /poll.rest?userId=10637&muxId=4P7OKlCVKTXBOgfP&seq=2 HTTP/1.1" 200 11 30002
4.79.43.180 - - [24/Dec/2019:18:36:04 +0000] "GET /poll.rest?userId=10637&muxId=4P7OKlCVKTXBOgfP&seq=2 HTTP/1.1" 200 11 30001
4.79.43.180 - - [24/Dec/2019:18:36:34 +0000] "GET /poll.rest?userId=10637&muxId=4P7OKlCVKTXBOgfP&seq=2 HTTP/1.1" 200 11 30001
4.79.43.180 - - [24/Dec/2019:18:37:04 +0000] "GET /poll.rest?userId=10637&muxId=4P7OKlCVKTXBOgfP&seq=2 HTTP/1.1" 200 11 30001

test.log-expected.json:

[
    {
        "verb": "GET",
        "ident": "-",
        "resp_time_ms": 11,
        "bytes": 30002,
        "httpversion": "1.1",
        "request": "/poll.rest?userId=10637&muxId=4P7OKlCVKTXBOgfP&seq=2",
        "@timestamp": "2019-12-24T18:35:04Z",
        "auth": "-",
        "clientip": "4.79.43.180",
        "response": "200"
    },
    {
        "verb": "GET",
        "ident": "-",
        "resp_time_ms": 11,
        "bytes": 30002,
        "httpversion": "1.1",
        "request": "/poll.rest?userId=10637&muxId=4P7OKlCVKTXBOgfP&seq=2",
        "@timestamp": "2019-12-24T18:35:34Z",
        "auth": "-",
        "clientip": "4.79.43.180",
        "response": "200"
    },
    {
        "verb": "GET",
        "ident": "-",
        "resp_time_ms": 11,
        "bytes": 30001,
        "httpversion": "1.1",
        "request": "/poll.rest?userId=10637&muxId=4P7OKlCVKTXBOgfP&seq=2",
        "@timestamp": "2019-12-24T18:36:04Z",
        "auth": "-",
        "clientip": "4.79.43.180",
        "response": "200"
    },
    {
        "verb": "GET",
        "ident": "-",
        "resp_time_ms": 11,
        "bytes": 30001,
        "httpversion": "1.1",
        "request": "/poll.rest?userId=10637&muxId=4P7OKlCVKTXBOgfP&seq=2",
        "@timestamp": "2019-12-24T18:36:34Z",
        "auth": "-",
        "clientip": "4.79.43.180",
        "response": "200"
    },
    {
        "verb": "GET",
        "ident": "-",
        "resp_time_ms": 11,
        "bytes": 30001,
        "httpversion": "1.1",
        "request": "/poll.rest?userId=10637&muxId=4P7OKlCVKTXBOgfP&seq=2",
        "@timestamp": "2019-12-24T18:37:04Z",
        "auth": "-",
        "clientip": "4.79.43.180",
        "response": "200"
    }
]
2

Hi @Jim_Ivey!

I think that the best approach to go with is to run the tests for your very specific module. I will provide the commands to do it using nginx module as an example (run inside /beats/filebeat folder):

1. make python-env
2. source ./build/python-env/bin/activate
3. make filebeat.test
4. INTEGRATION_TESTS=1 BEAT_STRICT_PERMS=false TESTING_FILEBEAT_MODULES=nginx nosetests tests/system/test_modules.py

Also you will need to run Elasticsearch locally which you can easily do using Docker:
docker run -p 9200:9200 -p 9300:9300 -e "discovery.type=single-node" docker.elastic.co/elasticsearch/elasticsearch:7.4.0

Let me know if this works for you.

ps: there is work in progress to update developer-guides with such information :slight_smile:

C.

3

Awesome! I'll try it in a few minutes.

This should go here as you guys write it up: Testing

P.S. Just now saw your P.S. Again, awesome!

P.P.S. I still have 4 dockers running from make testsuite. I'm not sure whether to kill them all before starting Elasticsearch locally. I'll leave them there the first time, and kill them if there seems to be a problem.

4

_Update: _ One of the docker containers running from make testsuite is elasticsearch, so, yeah, I had to kill that one. I also had elasticsearch running locally. I had to kill it with sudo service elasticsearch stop.

I'm now able to rapidly (relatively) iterate testing. Awesome! Thanks so much!

1 Like
5

Also @Jim_Ivey have in mind that if the Module you are creating is for a well known service it would be really interesting to consider making it a first class citizen of the upstream project. Just let us know.

C.

6

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