SMTP Logs not parsing correctly

Hi All,

I have got my two smtp servers sending their logs to Graylog via nxlog but something about he parsing of the data goes wrong and either the log isn’t processed or the fields are all jumbled.

Any help on what may be wrong would be great. Please see my logs/confs below.
Thanks.

NXLOG Log File

2017-03-28 11:17:40 INFO nxlog-ce-2.9.1716 started
2017-03-28 11:17:52 ERROR if-else failed at line 44, character 436 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; procedure 'parse_csv' failed at line 44, character 224 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; Not enough fields in CSV input, expected 11, got 8 in input 'e SMTPSVC1 WF15 25 - 250-mailserver.cmp.livemail.co.uk 33 31'
2017-03-28 11:20:40 ERROR if-else failed at line 44, character 436 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; procedure 'parse_csv' failed at line 44, character 224 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; Not enough fields in CSV input, expected 11, got 8 in input ''
2017-03-28 11:21:11 ERROR if-else failed at line 44, character 436 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; procedure 'parse_csv' failed at line 44, character 224 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; Not enough fields in CSV input, expected 11, got 8 in input ''
2017-03-28 11:22:10 ERROR if-else failed at line 44, character 436 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; procedure 'parse_csv' failed at line 44, character 224 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; Not enough fields in CSV input, expected 11, got 6 in input ''
2017-03-28 11:22:21 ERROR if-else failed at line 44, character 436 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; procedure 'parse_csv' failed at line 44, character 224 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; Not enough fields in CSV input, expected 11, got 5 in input ''
2017-03-28 11:23:35 ERROR if-else failed at line 44, character 436 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; procedure 'parse_csv' failed at line 44, character 224 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; Not enough fields in CSV input, expected 11, got 3 in input ''
2017-03-28 11:24:59 ERROR if-else failed at line 44, character 436 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; procedure 'parse_csv' failed at line 44, character 224 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; Not enough fields in CSV input, expected 11, got 7 in input ''
2017-03-28 11:25:27 ERROR if-else failed at line 44, character 436 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; procedure 'parse_csv' failed at line 44, character 224 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; Not enough fields in CSV input, expected 11, got 5 in input ''
2017-03-28 11:26:49 ERROR if-else failed at line 44, character 436 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; procedure 'parse_csv' failed at line 44, character 224 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; Not enough fields in CSV input, expected 11, got 3 in input ''

As you can see or some reason its not parsing the logs correctly and at time cutting off mid line as you can see in the nxlog above.

This is my conf on the server

define ROOT C:\Program Files (x86)\nxlog

Moduledir %ROOT%\modules
CacheDir %ROOT%\data
Pidfile %ROOT%\data\nxlog.pid
SpoolDir %ROOT%\data
LogFile %ROOT%\data\nxlog.log

<Extension gelf>
	Module 		xm_gelf
</Extension>

<Extension fileop>
	Module 		xm_fileop
</Extension>

 <Extension json>
    Module      xm_json
</Extension>

# Create the parse rule for IIS logs. You can copy these from the header of the IIS log file.
<Extension w3c>
    Module 			xm_csv
	Fields 			$date $time $c-ip $cs-username $s-sitename $s-computername $s-port $cs-method $cs-uri-query $sc-bytes $time-taken
    FieldTypes 		string, string, string, string, string, string, string, string, string, string, string
    Delimiter 		' '
    EscapeControl 	TRUE
    UndefValue 		-
</Extension>

<Input smtp>
    Module    	im_file
    File    	"C:\\Logs\\SMTPSVC1\\ex*.log"
    SavePos  	FALSE

	Exec		if $raw_event =~ /^#/ drop();                    \
                else                                             \
                {                                                \
                    w3c->parse_csv();                            \
                    $EventTime = parsedate($date + " " + $time); \
                    $SourceName = "SMTP";    					 \
                    $Message = to_json();    					 \
                }
</Input>

<Input eventlog>
    Module      im_msvistalog
</Input>

<Output graylog>
    Module      om_udp
    Host        graylog.mydomain.com
    Port        12201
    OutputType	GELF
</Output>

<Output test>
    Module      om_udp
    Host        graylog.mydomain.com
    Port        12203
	OutputType	GELF
</Output>  
  
<Route eventlog>
    Path        eventlog => graylog
</Route>

<Route iis-to-graylog>
	Path		smtp => test
</Route>

Hey all,

This is still not working as it should. Any suggestions of where the problem may lie beyond that its parsing wrongly would be great.

Its really frustrating as I am getting some logs but not all and some but not all of what I am getting are correct, others completely wrong.
Thanks.

Hej Matt

did you ask at the nxlog community? Maybe they have some better insides how to handle this in NXLOG.

Hi Jan,

Yes I did but without much luck, the main person that was helping me ultimately just suggested I pay for commercial support but not really what i am looking for. I will try refreshing the thread and get some more from them.

If anyone here has any input from using nxlog and graylog I would really appreciate the input.

To me it seems that nxlog complains that you require log file to have 11 fields on each line, but the log source sends log lines that have 3 to 8 lines only. So I would look at the log file at the log source and check if it really has the format you expect it to have.

Your module comment says it is the format used by IIS but you use it to read SMTP logs. So I would suspect that.

Thanks @jtkarvo

I agree with what you see as the problem.

Here is a bit of the source logs with addresses removed.

And yet another question. Why do you parse to json before sending with GELF? If you just want to store log in Graylog, you do not need to parse to json; GELF input works as is.

The way I have done it was just through online research.

I actually took an IIS log nxlog conf and reworked it for SMTP as they appear to use the same log format/type.

If you could suggest a better way please do explain a little, I would love to get it working.

… those lines would indeed have all 11 lines (after the comment lines were dropped).

Looking at your error messages, it seems that only some lines have errors. I wonder if these come from log rotation?

every line, bar those commented out, have 11 fields. if there is no data then the - is used as specified in the conf as the UndefValue

Yes, looking at the log example, it seems the IIS approach would be fine.

I would just myself remove the to_json();

… and check what the log rotation settings on the server are (and should one use nxlog xm_fileop module for a scheduled log rotation).

Thanks for the suggestion.

So if I remove the to_json() what would it be replaced with? The $message field would still need something i assume?

Module im_file File "C:\\Logs\\SMTPSVC1\\ex*.log" SavePos FALSE

Exec if $raw_event =~ /^#/ drop();
else
{
w3c->parse_csv();
$EventTime = parsedate($date + " " + $time);
$SourceName = “SMTP”;
$Message = to_json();
}

There is no need to replace it with anything. The message is automatically filled. You make a format conversion from the original log line to a JSON formatted log line with that statement. If you remove the format conversion, the $message field will contain the original log line.

Like this

   >  <Input smtp>
        Module    	im_file
        File    	"C:\\Logs\\SMTPSVC1\\ex*.log"
        SavePos  	FALSE
    	Exec		if $raw_event =~ /^#/ drop();                    \
                    else                                             \
                    {                                                \
                        w3c->parse_csv();                            \
                        $EventTime = parsedate($date + " " + $time); \
                        $SourceName = "SMTP";    					 \
                        $Message = ;    					 \
                    }
    </Input>

If I do that I get this…

2017-04-03 11:52:22 ERROR module 'smtp' has configuration errors, not adding to route 'iis-to-graylog' at C:\Program Files (x86)\nxlog\conf\nxlog.conf:69
2017-04-03 11:52:22 ERROR route iis-to-graylog is not functional without input modules, ignored at C:\Program Files (x86)\nxlog\conf\nxlog.conf:69
2017-04-03 11:52:22 WARNING not starting unused module smtp
2017-04-03 11:52:22 WARNING not starting unused module test
2017-04-03 11:52:22 INFO nxlog-ce-2.9.1716 started

No, just remove the whole line.

Its working as a config but I still get the errors :frowning:

define ROOT C:\Program Files (x86)\nxlog

Moduledir %ROOT%\modules
CacheDir %ROOT%\data
Pidfile %ROOT%\data\nxlog.pid
SpoolDir %ROOT%\data
LogFile %ROOT%\data\nxlog.log

<Extension gelf>
	Module 		xm_gelf
</Extension>

<Extension fileop>
	Module 		xm_fileop
</Extension>

<Extension json>
    Module      xm_json
</Extension>

# Create the parse rule for IIS logs. You can copy these from the header of the IIS log file.
<Extension w3c>
    Module 			xm_csv
	Fields 			$date $time $c-ip $cs-username $s-sitename $s-computername $s-port $cs-method $cs-uri-query $sc-bytes $time-taken
    FieldTypes 		string, string, string, string, string, string, string, string, string, string, string
    Delimiter 		' '
	QuoteChar 		'"'
    EscapeControl 	FALSE
    UndefValue 		-
</Extension>

<Input smtp>
    Module    	im_file
    File    	"C:\\inetpub\\logs\\SMTPSVC1\\ex*.log"
    SavePos  	TRUE

	Exec		if $raw_event =~ /^#/ drop();                    \
                else                                             \
                {                                                \
                    w3c->parse_csv();                            \
                    $EventTime = parsedate($date + " " + $time); \
                    $SourceName = "SMTP";    					 \
                }
</Input>

<Input eventlog>
    Module      im_msvistalog
</Input>


<Output graylog>
    Module      om_udp
    Host        graylog.mydomain.com
    Port        12201
    OutputType	GELF
</Output>

<Output test>
    Module      om_udp
    Host        graylog.mydomain.com
    Port        12203
	OutputType	GELF
</Output>  
  
<Route eventlog>
    Path        eventlog => graylog
</Route>

<Route iis-to-graylog>
	Path		smtp => test
</Route>
2017-04-03 12:02:18 ERROR if-else failed at line 43, character 385 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; procedure 'parse_csv' failed at line 43, character 224 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; Not enough fields in CSV input, expected 11, got 8 in input ''
2017-04-03 12:02:26 ERROR if-else failed at line 43, character 385 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; procedure 'parse_csv' failed at line 43, character 224 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; Not enough fields in CSV input, expected 11, got 3 in input ''
2017-04-03 12:02:32 ERROR if-else failed at line 43, character 385 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; procedure 'parse_csv' failed at line 43, character 224 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; Not enough fields in CSV input, expected 11, got 2 in input ''
2017-04-03 12:02:43 ERROR if-else failed at line 43, character 385 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; procedure 'parse_csv' failed at line 43, character 224 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; Not enough fields in CSV input, expected 11, got 8 in input ''
2017-04-03 12:02:49 ERROR if-else failed at line 43, character 385 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; procedure 'parse_csv' failed at line 43, character 224 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; Not enough fields in CSV input, expected 11, got 7 in input ''

To me it seems this if-else construct is not working for some reason and nxlog actually gives also the commented lines to parse_csv. If you try something like this, will it work?

Exec if $raw_event =~ /^#/ drop();
Exec if $raw_event !~ /^#/
{
w3c->parse_csv();
$EventTime = parsedate($date + " " + $time);
$SourceName = “SMTP”;
}

Also, you could add some debug command to the first line, in addition to the drop(), to see if the condition is triggered at all.

Btw., after removing the to_json, do the log lines look OK in Graylog? If so, then you should also be able to remove a JSON extractor from the input, if you have one, as the GELF input has automatically the fields extracted by nxlog.

Thanks so much for your effort.

With that code added it does run but i still get this in the nxlog log

2017-04-03 12:58:01 ERROR if-else failed at line 41, character 116 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; procedure 'parse_csv' failed at line 41, character 47 in C:\Program Files (x86)\nxlog\conf\nxlog.conf. statement execution has been aborted; Not enough fields in CSV input, expected 11, got 8 in input 'onnectionCommand SMTPSVC1 WF9 25 QUIT - 4 1563

As you can see, it is cutting mid word.