After Windows Vista(WinVista, Win7, Win2008), Zabbix Agent 1.9 (r10124)

I made a patch.
I added the getting event message function using XPath, "zbx_get_eventlog_message_xpath()".
Because the function consume more cpu and slower than the original function "zbx_get_eventlog_message()", the function works only if the original function failed.

Please see picture "02.jpg".
I started and stoped "Windows Media Player Network Sharing Service" again.
"after patched" zabbix succeeded at getting eventlog message.
The Source name is "Microsoft-Windows-WMPNSS-Service".
I'll attach my patch.
The patch requires "wevtapi.lib" to link.

The patch is for trunk r10124.
I'm sorry but I have only Japanese version windows.
So my screen capture is in Japanese.

I think same problem occurs also in 1.4.x and 1.6.x.

[The detail of the speed about original function and my function in my patch]

I measured the original one and my method.
The original method uses legacy eventlog API. My method uses new eventlog API with XPath query.
The original method send about 7000 eventlogs in 5 minutes with low CPU using(under 15% using).
My method send about 7000 eventlogs in 10 minutes with 100% CPU using.
Windows service process consumed many CPU resource. I think the new API is heavy.
So, I uses my method only if original one failed.
It improved the performance.
It's almost same speed and low CPU usage with original method.

Executing new API is heavy, so if zabbix execute a few query and caches multi values, it might be more light weight.
The new eventlog API reference is following.
http://msdn.microsoft.com/en-us/library/aa385785(VS.85).aspx

Or, if there is another way to get "Windows Eventing 6.0" log with legacy API, it is also good.
Though I couldn't find it in google or microsoft web site.

Hi.
Is there any progress?
Or, should I post more information about this problem?
Plz let me know.

Thank you for the patch! We are currently testing it and looking into ways we can integrate it with Zabbix code.

Thank you Saveljevs.
But I have to say I'm sorry.
I just found mistake in my patch.

The patched code always requires "wevtapi.dll" even if it runs under before Windows Vista.
"wevtapi.dll" exists only after Windows Vista.
So, the binary cannot run under before Windows Vista.
We have to load "wevtapi.dll" dynamically as needed using LoadLibrary().
I rewrote eventlog.c to load dll dynamiclly which based on "branches/dev/zbx-2008-windows-eventlog/src/zabbix_agent/eventlog.c" in subversion r13180.
Please see my code.

The "eventlog.c" dosen't require "wevtapi.lib" in linking.

We would like to thank you for the patch, but at the moment we still cannot integrate it into 1.8, because the new API is very slow. In our test environment, the new API generated approximately 35 rows per second, while loading the CPU by 100% - we cannot put an agent on the users' systems that loads the CPU this much. We will continue investigating the possible options, but if you have any further ideas, please let us know.

ZBX-3954 might be related

Also we can use prefetching instead of getting one by one event: http://msdn.microsoft.com/en-us/library/windows/desktop/aa385650(v=vs.85).aspx

Hi.
I recently made more effective patch.
Please see "zabbix-2.0.6-add_eventlog6_key.patch"
Old patch was every time opening and closing the handle of Eventlog and it makes bad performance.
So, in this version, I'm reusing the handle and it becomes much faster, though I cannot have time to test how much faster yet.

It adds new key "eventlog6[]", it supports Eventing 6.0 API and it also can get "application and service log" ZBXNEXT-934.
What you have to set to [] is "full name" of eventlog object in property.

This patch conflicts with current ZBX-5103 fix.
Because, in ZBX-5103, it defining macro "_WIN32_WINT" as Windows 2000 and it affect to macro "WINVER".
This patch is using "WINVER" and I think defining "_WIN32_WINT" as Windows 2000 is not so good.
So, I'm using https://gist.github.com/aliceinwire/4123963 patch for fixing ZBX-5103, which is posted in ZBX-5103.

To be build, it needs to change Makefiles.
My Makefile is like attached one.

Hi,

We have started working on this issue and appreciate your active involvement. Mr. Suzuki, thank you very much for the patch.

I updated the patch.
Fixed the patch about wrong type of lastlogsize.

Takanori, it probably would be good to show also diff between patches (since devs are working already, supposedly on the previous patch) to easily get what exactly you've changed.
It's just my thought

Thank you Oleksiy.
I attached "diff_of_1st_2nd_post.diff" diff between previous and current "zabbix-2.0.6-add_eventlog6_key.patch".

Takanori, in your patch you mentioned that "EvtGetLogInfo()" doesn't work properly with "EvtLogOldestRecordNumber"? Could you explain what it the problem? I works fine on my PC.

Hi Igors.
Actually, in some situation it works properly, but it doesn't in other situation.
For example, if I didn't delete any eventlog, it worked.
But if I once deleted some eventlog and generated other new eventlog, it started to return wrong number.
At least, I got wrong number in this situation.

And I found following info and actually I got wrong number, so I decided to use other way.
Also here is the way how to reproduce.
http://stackoverflow.com/questions/2958610/event-log-oldest-record-number
> When Vista came out I reported this, clearly unusual and unexpected behavior, to Microsoft. They confirmed it to be a problem,
> but stated that they would not change it, since code may already depend on the (incorrect) behavior. It is frustrating to see
> that this has still not changed in Windows 7. – Lucky Luke
I reproduced it also in Windows 2012.
So, I also think horrible MS will never change the unexpected behavior.

In that page, "Mitch" suggests to use legacy API, it means "GetOldestEventLogRecord()", but it cannot work with eventlog in "application and service log".
So, the code I posted seems only the way to get oldest eventlog.

Takanori, thanks a lot for the information.

BTW, my patch includes following not good thing.

• Windows Eventing 6.0 severity levels is mapped to less severity levels in Zabbix

From Windows Eventing 6.0, it adds new levels "critical", "log always" and "verbose".
But Zabbix doesn't have so much severity levels.
Only "info", "warning", "error", "audit success" and "audit failure".
I thought about adding new severity levels, but it makes more change in Zabbix server side code.

So, I mapped "error" and "critical" to "error".
I also mapped "info", "log always" and "verbose" to "info".
You can find the code in my patch, like following.

+		switch(VAR_LEVEL(renderedContent))
+		{
+		case WINEVENT_LEVEL_LOG_ALWAYS:
+		case WINEVENT_LEVEL_INFO:
+		case WINEVENT_LEVEL_VERBOSE:
+			*out_severity = EVENTLOG_INFORMATION_TYPE;
+			break;
+		case WINEVENT_LEVEL_CRITICAL:
+		case WINEVENT_LEVEL_ERROR:
+			*out_severity = EVENTLOG_ERROR_TYPE;
+			break;
+		case WINEVENT_LEVEL_WARNING:
+			*out_severity = EVENTLOG_WARNING_TYPE;
+			break;
+		default:
+			*out_severity = EVENTLOG_INFORMATION_TYPE;
+			break;
+		}

But if Zabbix can add more secerity, it's better.
Especially, mapping "critical" to "error" is annoying to users.
The problem is, if Zabbix add new severity levels, it becomes incompatibility with existing zabbix server version.
I think it can be added in only new major release.

Takanori, I have already taken care of the severity levels. They were made in a accordance to Windows Eventing.

I see, it's nice
Can I see the current code at anywhere?

I'm doing some minor modification now. You will see it in a day or two

Thanks Igors.
BTW, I read ZBX-5103 comment by wiper.
I suggest to add "#define HAVE_WINEVT_H 1" to build/win32/include/config.h instead of using WINVER.
WINVER is originally come from asaveljevs's test patch for ZBX-2008.

Fixed in development branch svn://svn.zabbix.com/branches/dev/ZBX-2008

(1) [F] CRITICAL and VERBOSE severity levels have to be added in PHP.

iivs Severities added in frontend.
RESOLVED in svn://svn.zabbix.com/branches/dev/ZBX-2008 r38725
Eduards Suggest to group new status in get_item_logtype_style()
iivs RESOLVED in r39056
Eduards CLOSED

Takanori, thanks for the comment. Please have a look at the code. Your comments are highly welcomed.

(2) [S] Successfully tested, please review my changes in r38692

igorsh I accept your changes.

CLOSED

(3) [A] Some additional modifications were done. Please review my changes in r38696

wiper reviewed, tested and CLOSED

(4) docs :
whatsnew
windows eventlog key docs, including "<this> supported since 2.2.0"

igorsh Updated whatsnew:
https://www.zabbix.com/documentation/2.2/manual/introduction/whatsnew220

and
https://www.zabbix.com/documentation/2.2/manual/config/items/itemtypes/zabbix_agent/win_keys

RESOLVED

Frontend tested!

Fixed in version 2.1.7(trunk) r39160

(5) [G] The new code is incorrectly formatted.

igorsh RESOLVED in r39171 and r39216

Hi Igors.
Sorry about my late reply.
I read your code.
I found following three point.

• You can add "/DELAYLOAD:wevtapi.dll" to "LFLAGS" in Makefile instead of following many functions definition.

  +static EVT_HANDLE      (WINAPI *EvtQueryFunc)(EVT_HANDLE, LPCWSTR, LPCWSTR, DWORD) = NULL;
  +static EVT_HANDLE      (WINAPI *EvtCreateRenderContextFunc)(DWORD, LPCWSTR*, DWORD) = NULL;
  +static BOOL            (WINAPI *EvtNextFunc)(EVT_HANDLE, DWORD, PEVT_HANDLE, DWORD, DWORD, PDWORD) = NULL;
  +static BOOL            (WINAPI *EvtRenderFunc)(EVT_HANDLE, EVT_HANDLE, DWORD, DWORD, PVOID, PDWORD, PDWORD) = NULL;
  +static EVT_HANDLE      (WINAPI *EvtOpenPublisherMetadataFunc)(EVT_HANDLE, LPCWSTR, LPCWSTR, LCID, DWORD) = NULL;
  +static BOOL            (WINAPI *EvtFormatMessageFunc)(EVT_HANDLE, EVT_HANDLE, DWORD, DWORD, PEVT_VARIANT, DWORD,
  +                                       DWORD, LPWSTR, PDWORD) = NULL;
  +static BOOL            (WINAPI *EvtGetLogInfoFunc)(EVT_HANDLE, EVT_LOG_PROPERTY_ID, DWORD, PEVT_VARIANT,
  +                                       PDWORD) = NULL;
  +static EVT_HANDLE      (WINAPI *EvtOpenLogFunc)(EVT_HANDLE, LPCWSTR, DWORD) = NULL;
  +static BOOL            (WINAPI *EvtCloseFunc)(EVT_HANDLE) = NULL;
  

  If you use "/DELAYLOAD", it automatically load dll and the functions definitions only when the functions are actually called.
  It makes code more clearly.
  Please read following document.
  http://msdn.microsoft.com/en-us/library/yx9zd12s(v=vs.90).aspx

• In Windows using eventlog 6.0 api, user never can know audit success or fail by severity.
  ITEM_LOGTYPE_SUCCESS_AUDIT and ITEM_LOGTYPE_FAILURE_AUDIT don't exist any more in eventlog 6.0 api.
  But in Windows 8 event viewer, it show the audit status similar as previous Windows.
  The status can be get from "/Event/System/Keywords".
  So, it might be better to map the status to Zabbix severity.
  Because if it doesn't show the status, old Windows show the status, but new Windows show the severity always as "info".
  I think it's bit annoying for users.

• It looks getting eventlog handle every time.
  It might not become problem, but getting eventlog handle every time is, I think, essentially same way which I posted before.
  And the last patch I posted has performance problem.
  Is there any reason to avoid reusing eventlog handle?

Hi Takanori,

Thank you for your comments. I'm looking into your suggestions now and will get back to you as soon as possible.

Takanori,

In my previous performance tests the performance overhead of getting eventlog handle each time was not significant.
Was it different in your case?

Igors,

In my case, if I didn't reuse the handle, it makes CPU exhausted and becomes slow like following.
Monitoring interval was 30.

• The original method send about 7000 eventlogs in 5 minutes with low CPU using(under 15% using). It means 23 req/sec.
• My method, it didn't reuse the handle, send about 7000 eventlogs in 10 minutes with 100% CPU using. It means 11 req/sec.
  I think 23 req/sec was the bottle neck of zabbix server side.
  Becaue my test environment is on VM and it's terribly slow.

And asaveljevs, he was working for this issue at first, also said "In our test environment, the new API generated approximately 35 rows per second, while loading the CPU by 100%"

In this time, I tested with second patch, which reusing the handle.
It can send data with less CPU usage.
This handle reusing binary is using CPU around 10% or bit over.
I made also handle non-reusing binary and its CPU usage is often 100%. Average is around 80%.
The sending speed is almost same, both 16 req/sec, I think it's because of my poor zabbix server which cannot treat so much data.

And more eventlog makes Eventing 6.0 API slower.
I tested this on a Windows with 20000 eventlog.

(6) [IG] Implement automatic loading of wevtapi.dll and its functions' definitions using "/DELAYLOAD"

igorsh RESOLVED in r39556

wiper CLOSED

(7) (G) Audit Success/Failure severity is not displayed in Security log

igorsh RESOLVED in r39585

wiper CLOSED

(8) [G] Add reuse of handle to improve performance

igorsh RESOLVED in r40000

wiper CLOSED

Igors,

I did performance test again in better environment.
Following is the result.
Non-reusing handle agent is slow and using much CPU power.
Reusing handle agent is faster and using less CPU power.

[non-reusing handle]
CPU usage:
  average:97.17%
  please also see "graph_reusing_handle.png"
Read Eventlog performance:
  system: 22281row, 2190sec, 10row/sec
  application: 4302row, 194sec, 22row/sec
  security: 35269row, 3632sec, 9row/sec

[reusing handle]
CPU usage:
  average:9.18%
  please also see "graph_reusing_handle.png"
Read Eventlog performance:
  system: 22272row, 241sec, 92row/sec
  application: 4302row, 42sec, 102row/sec
  security: 35267row, 380sec, 92row/sec

Please mind this result is using my patch which is different from yours.
But I think basically same thing also happens with your code.

Takanori,

Thank you sharing your performance results.

(9) [G] Please review coding style fixes in r40060, r40081

igorsh i reviewed your changes. Thank you. RESOLVED
wiper CLOSED

(10) [G] possible crash when failing to format event message

In eventlog.c:669-678

		if (EvtVarTypeNull != VAR_EVENT_TYPE(renderedContent))
		{
			char	*data;

			data = zbx_unicode_to_utf8(VAR_EVENT_DATA(renderedContent));
			*out_message = zbx_strdcatf(*out_message, "The following information was included"
					" with the event: %s", data);

			zbx_free(data);
		}

Where VAR_EVENT_DATA(p) is defined as (p[7].StringArr[0])

This code is based on assumption that renderedContent[7] always is string array, but in my tests it was string, leading to random crashes. We must either add explicit checks for rederedContent[7] type or drop this code part (I'm not sure how useful this additional data might be).

igorsh RESOLVED in r40108

wiper CLOSED

(11) [G] Logging message format and serverity must be reviewed.

Some of the logging messages does not follow Zabbix style, for example

		zabbix_log(LOG_LEVEL_WARNING, "In Eventlog '%s': Expected EventRecordID(" ZBX_FS_UI64 ")"
				" is not equal to the real EventRecordID(" ZBX_FS_UI64 ")."
				" Overwriting expected EventRecordID by the real EventRecordID",
				tmp_str, *which, VAR_RECORD_NUMBER(renderedContent));

Also the severity of log messages should be lowered to DEBUG if the function still can return success.

igorsh RESOLVED in r40110-r40111

wiper CLOSED

Successfully tested

Available in pre-2.2.1 r40193 and pre-2.3.0 (trunk) r40194.

could this have resulted in ZBX-7515 ?

wiper Yes. Currently my only guess is that delayed loading of wevtapi.dll did not work on x64 system.

ZBX-7515 is because forgetting to add " /DELAYLOAD:wevtapi.dll" to build/win32/project/Makefile_agent_x64
Attached patch is for r41495.

Should I post this to ZBX-7515 issue?
If so, please let me know.
Thank you.

Takanori, thank you for your patch. This issue will be resolved shortly.

Hello, I have upgraded my host to 2.2.2 and upgraded the agent I am trying to monitor to 2.2.1 and I am still getting a not supported in my agent logs:

13192:20140218:115240.786 cannot open eventlog 'Microsoft-Windows-TaskScheduler/Optional':[0x00003A9F] The specified channel could not be found. Check channel configuration.
13192:20140218:115240.789 cannot open eventlog 'Microsoft-Windows-TaskScheduler/Optional'
13192:20140218:115240.791 active check "eventlog["Microsoft-Windows-TaskScheduler/Optional"]" is not supported

Can you please tell me if you can successfully monitor this and also what is the appropriate convention for monitoring the Applications and services logs?

Robert,

Are you sure you want to monitor Microsoft-Windows-TaskScheduler/Optional, but not Microsoft-Windows-TaskScheduler/Operational?

If so, please confirm that this log is present in C:\Windows\System32\winevt\Logs

Please ignore my above comment, it works flawlessly!! Thank you Igors and the rest of the dev team that fixed this!!!!

-Robert