3WoO: Watching for Potentially Malicious Domains with OSSEC

I like logs, lots and lots of logs. When I find out certain logging capabilities aren't turned on I get confused. When I find out that they're turned on but not monitored I get angry.

DNS has been a thorn at a few places I've done work for in the recent past. There are requirements to record and monitor DNS queries, but no one seems to have a good solution. The general purpose of monitoring DNS was to look for malware that used DNS to connect to outside sites for data exfiltration. It may sound lame (not to me), but it can be quite effective depending on the intelligence you have on the threats most important to your organization.

Using snort to monitor DNS queries and responses has provided less than perfect results. Usually the sensor is placed in such a way that only recursive lookups are seen, so we end up with a bunch of alerts blaming the DNS server itself.

This post will help document part of a plan to monitor DNS. This only covers the major *nix daemons, not Windows (if someone gets me Windows logs I'll work on that too). It also only monitors the queries, not the responses. I had something that worked with bro-ids to monitor responses, but I haven't been able to test it in quite a while. I'm planning on waiting for the next major bro-ids release to update it. This method can also be worked around in a number of ways (including using domain names that aren't known to be bad, or subdomains not in the list), but it's a start.

I've tested this method with both bind and unbound, but should work with any software that logs these queries and an appropriate OSSEC decoder.

The first step is to turn on the proper logging.

Setting up the unbound.conf is simple:

log-queries: yes

Configuring named.conf is a bit more difficult:

logging {

        channel "default2" {
                syslog local7;
                severity info;
        };

        category lame-servers { null; };
        category "queries" { "default2"; };
        category "unmatched" { "default2"; };
};

I just have to make sure my syslogd is watching for local7 alerts, and writing them to a file. Configuring OSSEC to watch this logfile is pretty simple. On my system I just add the following to ossec.conf:

<localfile>
  <log_format>syslog</log_format>
  <location>/var/log/local7</location>
</localfile>

After making the logging changes to your dns daemon you'll have to restart it. Make sure logs are being populated with client queries.

Example unbound logs (differences in timestamps are from rsyslog vs OpenBSD's syslogd):

2011-10-26T15:46:15.508083-04:00 arrakis unbound: [8113:0] info: 127.0.0.1 www.ossec.net. A IN
2011-10-26T15:45:54.895874-04:00 arrakis unbound: [8113:0] info: 127.0.0.1 www.google.com. A IN
2011-10-26T15:46:48.366164-04:00 arrakis unbound: [8113:0] info: 127.0.0.1 caladan.example.com. A IN
2011-10-26T15:47:24.372937-04:00 arrakis unbound: [8113:0] info: 127.0.0.1 wallach9.example.com. A IN
2011-10-26T15:47:24.373670-04:00 arrakis unbound: [8113:0] info: 127.0.0.1 wallach9.be.example.com. A IN

And bind:

Oct 26 16:07:08 ix named[14044]: client 192.168.17.9#22193: query: www.ossec.net IN A +
Oct 26 16:05:51 ix named[14044]: client 192.168.1.9#19095: query: wallach9.example.com IN A +
Oct 26 16:05:51 ix named[14044]: client 192.168.1.9#26269: query: wallach9.be.example.com IN A +
Oct 26 16:03:21 ix named[14044]: client 192.168.1.16#38892: query: www.google.com IN A +

Let's look at these logs in ossec-logtest. bind first:

[root@zanovar ossec]# /var/ossec/bin/ossec-logtest
2011/10/26 16:07:46 ossec-testrule: INFO: Reading local decoder file.
2011/10/26 16:07:46 ossec-testrule: INFO: Started (pid: 11804).
ossec-testrule: Type one log per line.

Oct 26 16:07:08 ix named[14044]: client 192.168.17.9#22193: query: www.ossec.net IN A +


**Phase 1: Completed pre-decoding.
       full event: 'Oct 26 16:07:08 ix named[14044]: client 192.168.17.9#22193: query: www.ossec.net IN A +'
       hostname: 'ix'
       program_name: 'named'
       log: 'client 192.168.17.9#22193: query: www.ossec.net IN A +'

**Phase 2: Completed decoding.
       decoder: 'named'
       srcip: '192.168.17.9'
       url: 'www.ossec.net'

The domain name is decoded in the url section. Let's try the unbound log:

[root@zanovar ossec]# /var/ossec/bin/ossec-logtest
2011/10/26 16:11:47 ossec-testrule: INFO: Reading local decoder file.
2011/10/26 16:11:47 ossec-testrule: INFO: Started (pid: 11805).
ossec-testrule: Type one log per line.

2011-10-26T15:46:15.508083-04:00 arrakis unbound: [8113:0] info: 127.0.0.1 www.ossec.net. A IN


**Phase 1: Completed pre-decoding.
       full event: '2011-10-26T15:46:15.508083-04:00 arrakis unbound: [8113:0] info: 127.0.0.1 www.ossec.net. A IN'
       hostname: 'arrakis'
       program_name: 'unbound'
       log: '[8113:0] info: 127.0.0.1 www.ossec.net. A IN'

**Phase 2: Completed decoding.
       No decoder matched.

There is no unbound decoder currently. That's easy to fix. (in case there are any errors in the HTMLization of the decoders below feel free to grab this file)
Add the following to /var/ossec/etc/local_decoder.xml:

<decoder name="unbound">
  <program_name>^unbound</program_name>
</decoder>

<decoder name="unbound-info">
  <parent>unbound</parent>
  <prematch offset="after_parent">^\p\d+:\d+\p info: </prematch>
  <regex offset="after_prematch">^(\S+) (\S+) \S+ \S+$</regex>
  <order>srcip, url</order>
</decoder>

And this is how it decodes now:

[root@zanovar ossec]# /var/ossec/bin/ossec-logtest
2011/10/26 16:17:16 ossec-testrule: INFO: Reading local decoder file.
2011/10/26 16:17:16 ossec-testrule: INFO: Started (pid: 11810).
ossec-testrule: Type one log per line.

2011-10-26T15:46:15.508083-04:00 arrakis unbound: [8113:0] info: 127.0.0.1 www.ossec.net. A IN


**Phase 1: Completed pre-decoding.
       full event: '2011-10-26T15:46:15.508083-04:00 arrakis unbound: [8113:0] info: 127.0.0.1 www.ossec.net. A IN'
       hostname: 'arrakis'
       program_name: 'unbound'
       log: '[8113:0] info: 127.0.0.1 www.ossec.net. A IN'

**Phase 2: Completed decoding.
       decoder: 'unbound'
       srcip: '127.0.0.1'
       url: 'www.ossec.net.'

We're one step closer to having this all work. The next step is to decide on which domain names you want to alert on. I use a number of sources and a bad python script (seriously bad, you can't have it) to create a list of suspicious domains.
I use lists from Malware Domain List, DNS-BH - Malware Domain Blocklist (please donate!), and abuse.ch Zeus Tracker. I also have a list setup for domains I hear about that may not be on these other lists, and some other lists I don't pull via the script. A quick note about the DNS-BH site: That site is primarily a source for creating a DNS blackhole. This can keep your systems from ever getting to these bad sites (redirect them to a "honeypot" system to see what traffic they try to pass). I definitely recommend doing this, it's almost a free bit of security. It's also easy to setup in both bind and unbound/nsd. I've configured both to do this, so if anyone is interested let me know!
Of course, if you're worried about RAM usage this may not be the best idea:

  PID USERNAME PRI NICE  SIZE   RES STATE     WAIT      TIME    CPU COMMAND
14044 named      2    0 1088M  885M sleep/1   select   34:53  0.00% /usr/sbin/named

  PID USERNAME PRI NICE  SIZE   RES STATE     WAIT      TIME    CPU COMMAND
19753 _nsd       2    0  296M  249M idle      select    0:03  0.00% /usr/sbin/nsd -c /etc/nsd.conf

After collecting a list of possibly malicious domains, you'll want to create a CDB list. CDB is a key-value database format. It's great for lists that are fairly static. There's no way to add or remove items from the database, you have to recompile it from scratch. Recompiling these lists is pretty simple and quick, so it isn't much of an issue
The format is also simple:

key: value

My lists generally look like:

DOMAIN: Suspicious Domain

After this, move the list to your ossec directory, I keep mine in /var/ossec/lists. Next we configure OSSEC to use the list by adding them to the rules section:

<rules>
  ...
    <list>lists/blocked.txt.cdb</list>
    <list>lists/userlist.txt.cdb</list>
    <include>local_rules.xml</include>
</rules>

Compiling the lists is easy, and if the files haven't changed since the last recompile ossec-makelists will notify you that they don't need to be recompiled. When a list is updated you should not have to restart the OSSEC processes, they should pick up the changes automatically.

# /var/ossec/bin/ossec-makelists
 * File lists/blocked.txt.cdb does not need to be compiled
 * File lists/userlist.txt.cdb does not need to be compiled
# rm /var/ossec/lists/userlist.txt.cdb
# /var/ossec/bin/ossec-makelists
 * File lists/blocked.txt.cdb does not need to be compiled
 * File lists/userlist.txt.cdb need to be updated

The last piece will be creating a rule to use the list. These are the rules I have for unbound, but the bind rules look very similar:

   <rule id="40000" level="0" noalert="1">
    <decoded_as>unbound</decoded_as>
    <description>Grouping for unbound.</description>
  </rule>

  <rule id="40001" level="10">
    <if_sid>40000</if_sid>
    <list field="url">lists/blocked.txt</list>
    <description>DNS query on a potentially malicious domain.</description>
  </rule>

The list item compares the decoded url to the keys in blocked.txt.cdb database. If there is a match rule 40001 fires, if that url isn't in the database then it doesn't fire.
Hopefully this post gave you some ideas. There's more you can do with lists, so take a look at the documentation (more here).
Just a little teaser, I'm planning on another documentation post tomorrow or Friday. Stay tuned!

OSSEC Rules 101

As I've already written about decoders, it's time to cover rules. Rules are phase 3 in our 3 phase plan (pre-decoding, decoding, and rules). The syntax guide for writing rules can be found in the OSSEC documentation: here.

I will still be using the ossec-logtest progam to help illustrate the rules. I'll also be starting with the same log message as before:


Oct 8 14:15:33 fedora11 sshd[11773]: Failed password for ddp from 172.16.51.1 port 56588 ssh2


Just to refresh your memory, the beginning of the message gets chopped off during pre-decoding and decoding, so we will be left with "Failed password for ddp from 172.16.51.1 port 56588 ssh2" as the material for creating a rule. Here is the output of feeding the above message through ossec-logtest:


**Phase 1: Completed pre-decoding.
full event: 'Oct 8 14:15:33 fedora11 sshd[11773]: Failed password for ddp from 172.16.51.1 port 56588 ssh2'
hostname: 'fedora11'
program_name: 'sshd'
log: 'Failed password for ddp from 172.16.51.1 port 56588 ssh2'

**Phase 2: Completed decoding.
decoder: 'sshd'
dstuser: 'ddp'
srcip: '172.16.51.1'

This will be out reference for writing the rules.

There are a number of ways for OSSEC to evaluate a log message to determine the rule that will be triggered. Much like decoders the first rule that matches will be triggered, so the order of the rules is important. Since OpenSSH is a reasonably complicated group of applications, there will probably be a few rules associated with it (much like there are a number of decoders). 

All OSSEC rules start the same way:
<rule id="NUMBER" level="NUMBER">

The id is just an identification number to reference the rule. The level determines the severity of the event, and can be any number between 0 and 15. Here's a handy wiki entry detailing the various severity levels.

Since I am using examples that are already in place I can just use the id and level of the real rule:
<rule id="5700" level="0" noalert="1">

The option 'noalert="1"' means that this rule will never trigger an alert. We are going to use this rule to group all ssh rules together, so we don't want any sshd event we do not yet have a rule for to trigger Rule 5700.

It can be helpful to write a rule to help identify sshd log messages. We can do this a number of ways, but since we have an sshd decoder already, we'll match on the decoder.
  <decoded_as>sshd</decoded_as>

With this option, the rule will catch all log events that are decoded (in Phase 2) as sshd. Now we will add a description to this rule to help us understand it better later, and close the rule out:
  <description>SSHD messages grouped.</description>
<./rule>

Here's the rule all together:
<rule id="5700" level="0" noalert="1">
  <decoded_as>sshd</decoded_as>
  <description>SSHD messages grouped.</description>
</rule>

This is the first rule in the sshd_rules.xml file. Above it is the line:
<group name="syslog,sshd,">

This creates two groups called "sshd" and "syslogd." These groups can be used in rules and reports. More on this later.

With rule 5700 in place my log message would match it, but not report itself as matching it (because of the noalert="1" option). So I need another rule to match the specific message I'm seeing. We'll start it the same way as the last message, and add another option:
<rule id="5716" level="5">
  <if_sid>5700</if_sid>

As  you may be able to guess, this is the 17th rule in sshd_rules.xml (5700-5716). It's classified as a level 5 rule because one mistyped password may not be a big deal.

The <if_sid> option is similar to the <parent> option in decoders, this rule will only be checked if rule 5700 matched the log message. This should help optimize the ruleset, and not force OSSEC to check too many unrelated rules when a log message comes in.

The next thing we want to do is somehow match the log message. We'll add the following to do just that:
  <match>^Failed|^error: PAM: Authentication</match>

What this line does is tries to match its value to the log message. Remember the "^" symbol from the decoder post? If not, the symbol means that the character immediately following it should be the first character in the log message. The pipe symbol, "|", is a logical "or." In this case the value "^Failed" or "^error: PAM: Authentication" can match in the rule. Without the pipe we'd have to create two rules, one for each string. Using the pipe means we can be lazy and only write one rule to handle both possible messages.

So with this <match> option we're looking for the first part of the log message to be either "Failed" or "error." With the above log message we do indeed see "Failed." Remember that we are only dealing with the log section, as given to us in the decoding phase (Failed password for ddp from 172.16.51.1 port 56588). So this <match> will match our log message.

We want to be able to identify what is happening, and the description is what will be sent in the alert. Here is the description:
  <description>SSHD authentication failed.</description>

We also want to be able to search for these types of events (mis-typed passwords) for reports, so we'll also add a group to identify it as an authentication failure and close out the rule:
  <group>authentication_failed,</group>
</rule>

This group will be in addition to the main groups posted above. The complete group listing for this rule will be "syslog,sshd,authentication_failed."

Here is the complete rule:
<rule id="5716" level="5">
  <if_sid>5700</if_sid>
  <match>^Failed|^error: PAM: Authentication</match>
  <description>SSHD authentication failed.</description>
  <group>authentication_failed,</group>
</rule>

**Phase 1: Completed pre-decoding.
       full event: 'Oct  8 14:15:33 fedora11 sshd[11773]: Failed password for ddp from 172.16.51.1 port 56588 ssh2'
       hostname: 'fedora11'
       program_name: 'sshd'
       log: 'Failed password for ddp from 172.16.51.1 port 56588 ssh2'

**Phase 2: Completed decoding.
       decoder: 'sshd'
       dstuser: 'ddp'
       srcip: '172.16.51.1'

**Phase 3: Completed filtering (rules).
       Rule id: '5716'
       Level: '5'
       Description: 'SSHD authentication failed.'
**Alert to be generated.


As I mentioned above one failed login may not be a big deal. Bob mis-types his password at least once a day. But what happens if a bot out there is trying to brute force a password? That's a big deal, and something that should be reported. Here's a full rule to help group rule 5716 events:
<rule id="5720" level="10" frequency="6">
  <if_matched_sid>5716</if_matched_sid>
  <same_source_ip />
  <description>Multiple SSHD authentication failures.</description>
  <group>authentication_failures,</group>
</rule>

Since this is multiple attempts using the wrong password the level is now set to 10. Frequency is an option I haven't introduced yet. Frequency specifies how many times a rule must match before this rule will fire. In this case a failed login has to happen 6 times before rule 5720 will match.

<if_matched_sid> is similar to <if_sid>. There may be a difference, but I don't really know it. When creating rules with the frequency option, use <if_matched_sid>.

<same_source_ip /> just tells OSSEC that the 6 failed attempts must come from the same source IP address. If Bob, Lisa, Angela, Todd, Jason, and Herbert all mistype their passwords at the same time from different systems we don't want this alert to fire.

The rest of the rule is pretty standard so I'm not going to explain it.

Frequency can be very useful, and even combined with a couple of other options. Here is another brute force rule dealing with bad ssh logins:
<rule id="5712" level="10" frequency="6" timeframe="120" ignore="60">
  <if_matched_sid>5710</if_matched_sid>
  <description>SSHD brute force trying to get access to </description>
  <description>the system.</description>
  <same_source_ip />
  <group>authentication_failures,</group>
</rule>

In addition to frequency this rule also uses timeframe and ignore. These options are pretty simple. In this rule a user has to match rule 5710 6 times in a timeframe of 120 seconds. If that 6th event is 121 seconds after the first, this rule will not match. After rule 5712 has fired it will not fire again for 60 seconds thanks to the ignore option. This is to help keep you from getting a flood of alerts.

You'll also note that the description is broken into two lines. This is purely for readability reasons, the lines will be combined in the alert.

I'm not sure why these two rules have different options. I'd like to think that if one of them has the timeframe and ignore options they both should, or neither of them should. I'll have to look into that.

Since ossec-logtest doesn't keep state between the messages fed into it I can't really show a 5720 or 5712 alert using it.

There are a lot more options available in rules. For instance you can use <regex> in a rule. You won't be able to pull information out with parentheses in a regex, that's only available in decoders. Options like <category>, <srcip>, <user>, and <category> can be used to match specific elements. <category>syscheck</category> can be used to modify a syscheck alert. Here's an example:
<rule id="10999" level="15">
  <category>syscheck</category>
  <match>/var/ossec/etc/ossec.conf</match>
  <description>ossec.conf has been modified!</description>
</rule>

This rule would set off an alert of level 15 if syscheck has noticed that /var/ossec/etc/ossec.conf has been modified.

Since we know Bob mis-types his password at least once per day we can do the following to not have alerts fire when he mistypes his password:
<rule id="110000" level="0">
  <if_sid>5716</if_sid>
  <user>bob</user>
  <description>Ignore bob</description>
</rule>

If we want to limit it even further we can limit this to his source IP:
<rule id="110000" level="0">
  <if_sid>5716</if_sid>
  <user>bob</user>
  <srcip>192.168.1.23</srcip>
  <description>Ignore bob</description>
</rule>

There are two more options I want to mention: alert_by_email and no_email_alert. The first always sends an email when that event is triggered, no matter what level is set. This can be useful if you have determined that an event isn't a good candidate for a high level, but you always want to see an email on it. The second means the alert never sends an email. I'm not sure how useful this one is, but I'm guessing someone wanted it.

There's still a lot of information to cover, but it'll have to wait for future blog posts. This one is long enough. If I didn't explain something here well enough please let me know!

OSSEC decoders 101

In a previous post I mentioned that writing rules and decoders for OSSEC can be easy. Now I'm going to attempt to backup that claim bydetailing the process of writing a decoder. A similar post for writing rules will come later. To do this I'll use decoders for OpenSSH that are currently included in OSSEC, and an old log message from a Fedora 11 system.
The log message:
Oct 8 14:15:33 fedora11 sshd[11773]: Failed password for ddp from 172.16.51.1 port 56588 ssh2
To help write the decoders I'll be using the ossec-logtest application. ossec-logtest takes input from stdin and traverses the decoders and rules looking for a match. ossec-logtest should be available on all server and local (not agent) installs.
Having a basic understanding of OSSEC's regular expression (regex) support may help with more complicated decoders. For the log message above we'll be using regex to pull out the username and IP address.
Before I discuss decoders, I should explain how OSSEC parses syslog messages. There are three main parts to OSSEC's log analysis engine: pre-decoding, decoding and signatures.

Phase 1, pre-decoding, extracts known fields like time, the hostname of the system where the message originated, the name of the program that created the message and the log message itself (without some of the metadata).
Here is an example of information gathered during the pre-decoding phase using ossec-logtest:
-----------------------------------------------------------

# /var/ossec/bin/ossec-logtest -D . -c etc/ossec.conf

2010/10/01 08:54:31 ossec-testrule: INFO: Reading local decoder file.

2010/10/01 08:54:31 ossec-testrule: INFO: Started (pid: 22955).

ossec-testrule: Type one log per line.

Oct 8 14:15:33 fedora11 sshd[11773]: Failed password for ddp from 172.16.51.1 port 56588 ssh2

**Phase 1: Completed pre-decoding.

full event: 'Oct 8 14:15:33 fedora11 sshd[11773]: Failed password for ddp from 172.16.51.1 port 56588 ssh2'

hostname: 'fedora11'

program_name: 'sshd'

log: 'Failed password for ddp from 172.16.51.1 port 56588 ssh2'

-----------------------------------------------------------

As you can see the timestamp has been removed. OSSEC uses an internal timestamp of when the message was received instead of the timestamp on the event. After the timestamp is the hostname, 'fedora11' (don't judge, this was an old log message). The program name, sshd, was pulled out of the message and the process ID (11773) was removed and discarded. Finally, the log message without the metadata is displayed.
Phase 2, decoding, comes next. What information goes in? What information comes out? How do I get more information? And how do I write decoders for my applications?
Phase 3 will attempt to match a rule to the log message, and will be detailed in another post.

The decoders I will be using for these examples revolve around OpenSSH. OpenSSH is a complicated program, and has a number of logs. Some are more interesting than others, and we try to create rules for as many as we can. In a number of the logs information like usernames and source IP addresses are available, and this can be useful information. OSSEC can be configured to block IPs attempting to brute force an OpenSSH password, or disable users that are being targeted.
Just a quick note: Some distributions or operating systems have modified the logs in the default OpenSSH source code, so maintaining the sshd decoders has not been the easiest task. It can be a bit disheartening to see the same log information displayed in 3 slightly different and incompatible log messages on different Linux distributions. If anyone knows why package/OS maintainers feel a need to modify log messages please let me know.

Anyways, on to the decoders!
OSSEC decoders are written in XML, and have a very basic format. They can be found in /var/ossec/etc/decoder.xml, and custom decoders can be added to /var/ossec/etc/local_decoder.xml. The local_decoder.xml file will not be overwritten during an upgrade, but the system default decoder.xml will. The easiest decoders are three lines long, and don't include anything more complicated than using the "^" character to indicate that the string that follows is at the very beginning of the section. Many of the fields in decoders can utilize the OS_Match or sregex. 

Here's the first example, the primary sshd decoder, followed by a line-by-line explanation:
<decoder name="sshd">
  <program_name>^sshd</program_name>
</decoder>

• Each decoder starts the same way, with the "decoder," and "name" tags.
• The name must be a unique string, alpha-numeric and should identify the purpose of the decoder. In this case the name of this decoder is just "sshd."
• The next line indicates that this decoder will be applied to any log event produced by the "sshd" application. In this decoder the <program_name> field checks if the program_name begins with the string "sshd." If it does, OSSEC applies this decoder. Another option instead of <program_name> would be to include a <prematch> field, and this option will be detailed later in this post. All decoders must have either a <program_name> or <prematch> field, but <program_name> is often easier.
• The "</decoder>" tag ends this decoder entry.

The following is an example of the output of ossec-logtest without the sshd decoder in place:
-------------------------------------------
Oct 8 14:15:33 fedora11 sshd[11773]: Failed password for ddp from 172.16.51.1 port 56588 ssh2

**Phase 1: Completed pre-decoding.
full event: 'Oct 8 14:15:33 fedora11 sshd[11773]: Failed password for ddp from 172.16.51.1 port 56588 ssh2'
hostname: 'fedora11'
program_name: 'sshd'
log: 'Failed password for ddp from 172.16.51.1 port 56588 ssh2'

**Phase 2: Completed decoding.
No decoder matched.
-------------------------------------------

Notice how no decoder is found in "Phase 2."

Now, for the output of the same log message with the basic sshd decoder in place:
-------------------------------------------
Oct 8 14:15:33 fedora11 sshd[11773]: Failed password for ddp from 172.16.51.1 port 56588 ssh2

**Phase 1: Completed pre-decoding.
full event: 'Oct 8 14:15:33 fedora11 sshd[11773]: Failed password for ddp from 172.16.51.1 port 56588 ssh2'
hostname: 'fedora11'
program_name: 'sshd'
log: 'Failed password for ddp from 172.16.51.1 port 56588 ssh2'

**Phase 2: Completed decoding.
decoder: 'sshd'
--------------------------------------------

Now the decoder is identified as "sshd".

With this information, OSSEC can focus on the rules that apply to the sshd decoder and not waste resources looking at rules that don't.
But this decoder does not give us much information. Many of sshd's logs include useful information like the source IP or username. This information may be useful to OSSEC admins. To get this information, child decoders can be used. Parent decoders can have any number of child decoders, and each child can have only 1 parent. This allows for a wide variety of log messages to be decoded properly without making it horribly difficult to understand and maintain decoders.

This next decoder pulls more information out of the log message (when available), and provides it in various fields that may be used in rules or active responses.

ssh-failed decoder:
<decoder name="ssh-failed">
   <parent>sshd</parent>
   <prematch>^Failed \S+ </prematch>
   <regex offset="after_prematch">^for (\S+) from (\S+) port \d+ \w+$<;/regex>
  <order>user, srcip</order>
</decoder>

• This decoder is a bit more complicated than the "sshd" decoder. It starts the same way as the "sshd" decoder, with the "decoder" and "name" tags.
• The second line (<parent>sshd</parent>) indicates that the "ssh-failed" decoder is a child of the "sshd" decoder. If "sshd" does not match, this decoder will not be checked, saving system resources. A log message that matches the "ssh-failed" decoder will be identified as belonging to the "sshd" decoder to make categorizations and administration easier as you will not need to know the name of the specific child decoder, only the parent.
• The third line (<prematch>^Failed \S+ </prematch>) is used by OSSEC to determine if this child decoder is the appropriate one to apply to this log message. As I said before, each decoder can have any number of children, so there has to be a method to select one for each log message. This line is using a simple regex pattern. This pattern is compared to the log message, if there is a match OSSEC continues with this decoder.

• The regex line is one of the more interesting lines in this decoder. I will break this line into two parts:

1. <regex offset="after_prematch"> - This identifies the line as a regex entry, and indicates that OSSEC should try to match this regular expression to the log message after the prematch. That means, from the log message only the information after 'Failed password ' will be used.
2. ^for (\S+) from (\S+) port \d+ \w+$</regex> - This second part of the regex line is a little more complicated. The beginning of the line should start with the characters 'for'. The "\S+" is a regular expression for "one or more non-whitespace characters." The parenthesis around this regex force the value to be kept in memory for use later. Next is "from (\S+)". Again, OSSEC looks for the string "from " and places the next one or more non-whitespace characters in memory. The last bit, " port \d+ \w+$" instructs OSSEC to look for the string "port", one or more numbers, and a word (a string of: A-Z, a-z, 0-9 characters) immediately followed by the end of the line.

• The <order> line is where the values pulled out of the log message by the regex operation will be categorized. Between the order tags are the values "user" and "srcip" (seperated by a comma). The first value from the regex line will populate the user field, and the second the srcip field.

• In the example log message this lines up with "ddp" as the user, and "172.16.51.1" as the srcip. There are a number of options available in the <order> field, and a list is at the end of this post.

In this example, using the ssh-failed decoder, you can now see the dstuser and srcip have been pulled out of the log message (note that the decoder is still identified as sshd, not as ssh-failed).
------------------------------------------
Oct 8 14:15:33 fedora11 sshd[11773]: Failed password for ddp from 172.16.51.1 port 56588 ssh2

**Phase 1: Completed pre-decoding.
full event: 'Oct 8 14:15:33 fedora11 sshd[11773]: Failed password for ddp from 172.16.51.1 port 56588 ssh2'
hostname: 'fedora11'
program_name: 'sshd'
log: 'Failed password for ddp from 172.16.51.1 port 56588 ssh2'

**Phase 2: Completed decoding.
decoder: 'sshd'
dstuser: 'ddp'
srcip: '172.16.51.1'
---------------------------------------------


In the output from ossec-logtest, the "user" field is displayed as dstuser. I don't know why, but in this case it does happen to be the destination user.

I mentioned using offset="after_prematch" above, but there is another option. You can also use offset="after_parent". Using "after_parent" in the above example wouldn't help with the ssh-failed decoder, since the sshd decoder essentially stops after "sshd[11773]: ". If the parent decoder went further into the log message "after_parent" would be more useful.

So that's how you write a decoder in OSSEC. It can take a few tries to get a decoder right, especially when using regular expressions. The ossec-logtest program is indispensable in these situations. There have been plenty of times where I've had to break a regex line down to the basics, and slowly build it up until it worked the way I wanted.
And, as a final note, the order of decoders in decoder.xml is important. The first decoder OSSEC comes across that matches is applied to the log message, first match wins. I've spent time editing regex lines trying to get a decoder to work only to find out another decoder beat mine to the match.

 
I sometimes have trouble finding these, so here are the various options that can be used inside of <order>:
user
srcuser
dstuser
srcip
dstip
srcport
dstport
port
extra_data
status
protocol
url
id
action