How does Windows eventlog monitoring work?

[gospodin.horoshiy]

Hello, please help me with understanding how zabbix process eventlog messages.

Let's say, I have about 40 Windows servers and most of them have at least two eventlogs I would like to track: Application and System. Many of these servers have messages in logs that have been collected for a few years.

Before yesterday I wasn't doing any monitoring of logs at all, but then I turned
item like eventlog[application] ON(ACTIVE) on all servers and here is what happened:

My system has completely queud up: Normaly, my zabbix queue would be 5-20 but now it has raised up to 400! As a result, very few information can come through this jam to the zabbix, even if is not related to logs. I checked, and as far as I can see, zabbix is collecting absolutely all info from these logs, despite its last year date - that's why queue is so enourmous.

Ok, lets say its normal. Zabbix is configured to keep history of logs for 30 days. question is, is zabbix going to download these old messages ONCE AGAIN from hosts after it deletes messages downloaded yesterday in 30 days time?

Hope you got the point... Please help me understand how to manage this log monitoring properly, cheers

[jroberson]

That's a good question that I would like to know more about myself. If I look at my "latest data" and then open the log, the most events that it will allow me to see is the "500 latest values". Does that mean that it only keeps up to 500 entries? I've got an action setup to email me when it sees a "High" severity entry. When I've added a long running server to Zabbix I get lots of emails so it definetly pulls older events when you start monitoring. I have, however, never received a repeated log entry or email. That might suggest You're best bet maybe to clear out the Windows events and then let Zabbix start monitoring them.

[gospodin.horoshiy]

That would work possibly, but I don't really want to do that.

Right now I have setup a little expiriment: I disabled all my eventlog[app] items except one server. At the moment, I can see that it's processing data from eventlog with Local Time of Jul 27 2008 Also I see that it's only adding 2-3 entries per check! That means full log will be in zabbix db not earlier then tomorrow morning I think, no wonder my Zabbix was queued up since I asked to download logs from 40 servers at the same time with rate of 2-3 entries per check

Any thoughts?
Also questions in the first post are still important.
Thanks

[NOB]

ZABBIX Windows Eventlog: how it works / what is missing

Hi

here's how it works:

As soon as you create an agent (active) item with eventlog[xxx] in it,
the ZABBIX-Agent on the system will send ALL events which are in
the current xxx log (where xxx is application, system or security, etc.).

So, IMO the best practice is:

1. Enable those items one after another, otherwise a (slow ?) server will be overwhelmed by the amount of data. Like you have experienced
2. disable the triggers related to eventlog on a server until all events are received, enable them afterwards. Otherwise you'll get a lot of false alarms

So what is missing in ZABBIX ?

1. The event Id. You can specify triggers for the source and the severity, but the event Id is neither send from the agent nor stored in the DB (how, if not send).
2. An option to select: start reading from current last entry or change the default to do that if nothing was read before. Otherwise continue from the last entry read.
3. A selection for time period in the GUI for this type of items. At least in 1.6 this is missing. I did not check the later versions 1.6.1 and 1.6.2. You are right, just the entries in the last hour or last 500 entries are visible in the GUI.
4. Ability to specify Event-Id, Source and Severity in the item, so the agent can do the filtering. Although you have to be careful, again, to avoid storing most of the event log entries multiple times in the DB, because of pattern matches for multiple event log watchers on the same host and eventlog type

I know, that the event id depends on the programmers, require strict management of the numbers inside an application and are therefore unusable most of the time.
But because we have requests for monitoring the event Id and it can't be used in the current ZABBIX implementation (up to 1.6.2) I changed the windows agent.
There is a patch in this forum to add an (optional) filtering on agent-side for the source and the severity. But we need the Id, too.

There are several ways how to approach this change. I am not sure with what I will end up.

For now I have an implementation of the event log where the agent creates an artificially temporary log "line" like
Source: McLogEvent Type: Information Id: 5000 Message: McShield-Service started. Modulversion: 5300.2777 DAT-Version: 5556.0000 ...

As you can see, the source, the type (severity) and the Id is included in the text which will be (optionally) filtered by the agent. Then you can specify triggers for the source, the severity and the text (like in the standard agent) and use the Id in the message, too.

Regards

Norbert.

[gospodin.horoshiy]

OK! I have made another test, and it doesn't look good!

I flushed my systemlog completely on 2 different servers
Then I restarted my Zabbig Agent service, so log had ONLY 4 DIFFERENT entries:
1)Send stop
2)service is stopped
3)Send start
4)service is started

(See first screen)


After that, I expect from zabbix to download those 4 entries and then wait for new ones to come.
But it actually downloaded the same message every check!
To be correct, 1st server downloaded only 1st entry
and 2nd server downloaded only 1st and 2nd entry
(just check 2nd screen - so many entries here, but only 4 in windows log in fact)


Versions of zabbix agents: 1st server : 1.6.1
2nd server : 1.6.2 revision 6997
Version of zabbix server: 1.6.2


please help

[gospodin.horoshiy]

Hey Norbert, thanks for your broadened answer! Can you tell something about this:

Zabbix is configured to keep history of logs for 30 days. question is, is zabbix going to download these old messages ONCE AGAIN from hosts after it deletes messages downloaded yesterday in 30 days time?

[jroberson]

I might be able to help with this. I've had eventlogs monitored for quite a while (1 yr+) here and I've never seen a repeated message after 30 days, BUT that is just my experience, and I don't know for certain.

[gospodin.horoshiy]

Maybe you just haven't noticed them, what do you think is this possible?

[bbrendon]

The problem I see when using zabbix for logs is that reading and searching the logs is very difficult. Even alerting from event logs is difficult.

An excellent tool for reading logs is splunk. It would be nice if there was a way for Zabbix to export syslogs and eventlogs to a splunk server so that additional logging agents weren't necessary on windows servers.

Actually, it might be possible by writing a script that accesses mysql directly and pumps the logs into splunk from zabbix db. ...or?

Anyway, just some ideas...

[bbrendon]

Maybe you just haven't noticed them, what do you think is this possible?

Zabbix only downloads new eventlog messages. The first time the agent is configured to collect eventlogs, it can take quite awhile to catch up to real time. After that, only new log entires are downloaded.

[trikke]

Hi,

I had repeated messages before and this was due to the Server not saving/updating the items.lastlogsize row in the Database. I'm on Agent 1.4.5 on Windows, so i don't know for your agent, but just check your db!

Greets
Patrick

[gospodin.horoshiy]

Hi,

I had repeated messages before and this was due to the Server not saving/updating the items.lastlogsize row in the Database. I'm on Agent 1.4.5 on Windows, so i don't know for your agent, but just check your db!

Greets
Patrick

JACKPOT!

I have dublicates (like on screenshot) from agents 1.6.1-1.6.2, but all my old 1.4.6 are working fine!

Gonna investigate a bit, thanks!

UPD: Uf, same problem with 1.4.6 also

[gospodin.horoshiy]

Ok, I think problem with dublicate entries and queuing up was here:

In my Zabbix Server log file I had messages of something like that(sorry wasn't able to copy it to before its gone, but there were dozens of them)

Query failed Lock wait timeout exceeded, table history_log is busy, try again later


And agents had log like that one:

7808:20090320:201129 OK
7808:20090320:201129 For key [agent.version] received value [1.4.6]
5576:20090320:201129 In GetCounterName() [index:6]
7808:20090320:201129 XML before sending [<req><host>bWFpbi52aXJ0b24ubG9jYWw=</host><key>YWdlbnQudmVyc2lvbg==</key><data>MS40LjY=</data></req>]
5576:20090320:201129 In GetCounterName() [index:238]
5576:20090320:201129 In GetCounterName() [index:6]
5576:20090320:201129 In GetCounterName() [index:238]
5576:20090320:201129 In GetCounterName() [index:44]
5576:20090320:201129 In GetCounterName() [index:2]
7808:20090320:201129 OK
7808:20090320:201129 In zbx_open_eventlog() [source:application]
7808:20090320:201129 In zbx_open_eventlog() [source:system]
7808:20090320:201129 In zbx_get_eventlog_message() [source:system] [which:3]
7808:20090320:201129 XML before sending [<req><host>bWFpbi52aXJ0b24ubG9jYWw=</host><key>ZXZlbnRsb2dbc3lzdGVtXQ==</key><data>0evz5uHgICJaQUJCSVggQWdlbnQiIO/l8OX46+Ag4iDx7vHy7v/t6OUgItDg4e7y4OXyIi4NCg==</data><lastlogsize>Mw==</lastlogsize><timestamp>MTIzNzU2ODI3OA==</timestamp><source>U2VydmljZSBDb250cm9sIE1hbmFnZXI= </source><severity>MQ==</severity></req>]
7808:20090320:201135 Send value error: [recv] ZBX_TCP_READ() failed [Попытка установить соединение была безуспешной, т.к. от другого компьютера за требуемое время не получен нужный отклик, или было разорвано уже установленное соединение из-за неверного отклика уже подключенного компьютера.

]
7808:20090320:201135 In zbx_open_eventlog() [source:system]
7808:20090320:201135 In zbx_get_eventlog_message() [source:system] [which:3]
7808:20090320:201135 XML before sending [<req><host>bWFpbi52aXJ0b24ubG9jYWw=</host><key>ZXZlbnRsb2dbc3lzdGVtXQ==</key><data>0evz5uHgICJaQUJCSVggQWdlbnQiIO/l8OX46+Ag4iDx7vHy7v/t6OUgItDg4e7y4OXyIi4NCg==</data><lastlogsize>Mw==</lastlogsize><timestamp>MTIzNzU2ODI3OA==</timestamp><source>U2VydmljZSBDb250cm9sIE1hbmFnZXI= </source><severity>MQ==</severity></req>]
7808:20090320:201140 Send value error: [recv] ZBX_TCP_READ() failed [Попытка установить соединение была безуспешной, т.к. от другого компьютера за требуемое время не получен нужный отклик, или было разорвано уже установленное соединение из-за неверного отклика уже подключенного компьютера.

]
7808:20090320:201140 In zbx_open_eventlog() [source:system]
7808:20090320:201140 In zbx_get_eventlog_message() [source:system] [which:3]
7808:20090320:201140 XML before sending [<req><host>bWFpbi52aXJ0b24ubG9jYWw=</host><key>ZXZlbnRsb2dbc3lzdGVtXQ==</key><data>0evz5uHgICJaQUJCSVggQWdlbnQiIO/l8OX46+Ag4iDx7vHy7v/t6OUgItDg4e7y4OXyIi4NCg==</data><lastlogsize>Mw==</lastlogsize><timestamp>MTIzNzU2ODI3OA==</timestamp><source>U2VydmljZSBDb250cm9sIE1hbmFnZXI= </source><severity>MQ==</severity></req>]
7808:20090320:201146 Send value error: [recv] ZBX_TCP_READ() failed [Попытка установить соединение была безуспешной, т.к. от другого компьютера за требуемое время не получен нужный отклик, или было разорвано уже установленное соединение из-за неверного отклика уже подключенного компьютера.

I dunno why message is in Russian, thought that agent should create English logs, but error message means something like "Unable to get response from server in time"




What I did was restarted the Zabbix server and cleaned the majority of logs before monitor them as was adviced. No dublicates, no queues. Phew)


Thank you all


P.S. There is little zabbix[log] actually(not so little : about 70) but if I go to Administration -> Queue - its completely empty. Any thought what does it mean?

[NOB]

Hey Norbert, thanks for your broadened answer! Can you tell something about this:

Zabbix is configured to keep history of logs for 30 days. question is, is zabbix going to download these old messages ONCE AGAIN from hosts after it deletes messages downloaded yesterday in 30 days time?

Hi

I think the answer was already given in this thread:

If the agent can't update the lastlogsize field in the ZABBIX database, it will re-read all
messages between the last time it could update the lastlogsize
and the current value.

Regards

Norbert.

[gospodin.horoshiy]

Norbert, and how agent does decide whether it could update lastlog or not, I didn't get it sorry)