IV63704: HEAVY WINDOWS EVENT LOG LOAD CAUSES DELAYS AND THE APPEARANCE OF HANGS

Tivoli Log File Agent, Version 6.3.0 Fix Pack 01 (6.3.0-TIV-ITM_LFA-FP0001)
Tivoli Log File Agent, Version 6.3.0 Interim Fix 04 6.3.0-TIV-ITM_LFA-IF0004
Tivoli Log File Agent, Version 6.3.0 Fix Pack 02 (6.3.0-TIV-ITM_LFA-FP0002)
Tivoli Log File Agent, Version 6.3.0 Interim Fix 05 6.3.0-TIV-ITM_LFA-IF0005

APAR status

• Closed as program error.

Error description

• PROBLEM DESCRIPTION:
  A heavy Windows event log throughput causes delays in the events
  being displayed on the portal.
  For example: when sending 1000 events per second per thread, on
  4 threads, the delay in seeing the events on the portal might be
  as much as 30 minutes. The delay increases as the PollInterval
  increases.
  
  The agent might also appear to hang if too many duplicate
  Windows Event log messages are received.
  
  With a minimum of the following tracing turned on, the agent
  log <hostname>_lo_[instance]_kloagent_<timestamp>-01.log shows
  that the agent is continuing to monitor for incoming events but
  no new events are received.
  
  KBB_RAS1: ERROR (UNIT: WinLogQueryList ALL) (UNIT:kum0nget ALL)
  (UNIT:kumpfdp6 FLOW DETAIL)
  
  ...:winlogquerylist.cpp,1143,"writeEventDataToPipe") Records
  written
  to pipe n writeResult=1
     where n is the number of events written to pipe
  ...
  ...
  And the following sequence repeatedly even though new events are
  being
  sent:
  ...:kumpfdp6.c,162,"WaitUntilNextSampleTime") >>>>>
  WaitForSingleObject returned 258 for WaitFileHandle @78
  ...:kumpfdp6.c,233,"WaitUntilNextSampleTime") Exit: 0x1
  ...:kum0nget.c,122,"KUM0_Fgets") Entry
  ...:kum0nget.c,136,"KUM0_Fgets") read / actual BufferSize =
  64146 / 192438, encoding = ibm-5348_P100-1997, convertToUTF8 = 1
  ...:kum0nget.c,308,"KUM0_Fgets") Using fgets() to get string
  from file
  ...:kum0nget.c,355,"KUM0_Fgets") Pipe read returned no data
  setting EOF
  ...:kum0nget.c,399,"KUM0_Fgets") Exit: 0x0
  
  
  
  The Windows Event log might also contain a message similar to
  the following:
  The EventSystem sub system is suppressing duplicate event log
  entries for a duration of 86400 seconds.  The suppression
  timeout can be controlled by a REG_DWORD value named
  SuppressDuplicateDuration under the following registry key:
  HKLM\Software\Microsoft\EventSystem\EventLog.
  
  
  RECREATE INSTRUCTIONS:
  Create a Windows PowerShell script which generates:
  1000 events per second on 4 threads, all of which match the
  format.
  
  
  With Conf file settings:
  PollInterval=5 (or greater)
  

Local fix

• 1. Lower the PollInterval to one second.
  PollInterval=1
  

Problem summary

• A heavy Windows Event Log throughput causes delays in the events
  being displayed on the portal.  For example:  when sending 1000
  events per second per thread, on 4 threads, the delay in seeing
  the events on the portal might be as much as 30 minutes.  The
  delay increases as the PollInterval increases.
  
  A delay might also occur on LogSources or RegexLogSources
  monitored files on Windows systems, as the Windows change
  notification mechanism was not setup properly.
  
  As a result, the agent was always waiting the full PollInterval
  time before checking for Windows Events or updates to the
  monitored file, rather than receiving the chcange notification.
  The delay would grow as a factor of the PollInterval.
  

Problem conclusion

• 1. Fix Windows FindFirstChangeNotification setup, so notified as
  soon as an event or change occurs.
  
  2. Added an environment variable CDP_MAX_WINLOG_PIPE_BUFFER to
  set in the KLOENV_<instance>, and increased the default size
  to 200,000 bytes.
  This variable should only be set under the direction of support.
  
  3. Increase internal pipe buffer size.
  
  The fix for this APAR is included in the following maintenance
  vehicle:
  
  | interim fix | 6.3.0-TIV-ITM_LFA-IF0004
  
  available at
  http://www.ibm.com/support/docview.wss?uid=swg24039388
  

Temporary fix

Comments

APAR Information

• APAR is sysrouted FROM one or more of the following:

• APAR is sysrouted TO one or more of the following:

Fix information

• Fixed component name

  ITM LOG FILE AG

• Fixed component ID

  5724C04LF

Applicable component levels

• R630 PSY

     UP