Metricbeat 5.1.2 Windows service times out at startup

asp · March 1, 2017, 2:12pm

Hi,

metricbeat service is not starting in Win2012 R2 terminal server.
When running manually it takes very long until until the first metrics is fetched. There are many errors like this in debug log: error getting process state for pid=20492: getProcCredName failed

2017-03-01T15:04:19+01:00 DBG  Disable stderr logging
2017-03-01T15:04:19+01:00 INFO Home path: [E:\Programme\metricbeat\metricbeat-5.1.2-windows-x86_64] Config path: [E:\Programme\metricbeat\metricbeat-5.1.2-windows-x86_64] Data path: [E:\Programme\metricbeat\metricbeat-5.1.2-windows-x86_64\data] Logs path: [E:\Programme\metricbeat\metricbeat-5.1.2-windows-x86_64/../log]
2017-03-01T15:04:19+01:00 INFO Setup Beat: metricbeat; Version: 5.1.2
2017-03-01T15:04:19+01:00 DBG  Processors: 
2017-03-01T15:04:19+01:00 DBG  Initializing output plugins
2017-03-01T15:04:19+01:00 INFO Dry run mode. All output types except the file based one are disabled.
2017-03-01T15:04:19+01:00 INFO Publisher name: viemanjump1
2017-03-01T15:04:19+01:00 INFO Register [ModuleFactory:[docker, mongodb, mysql, postgresql, system], MetricSetFactory:[apache/status, docker/container, docker/cpu, docker/diskio, docker/info, docker/memory, docker/network, haproxy/info, haproxy/stat, kafka/partition, mongodb/status, mysql/status, nginx/stubstatus, postgresql/activity, postgresql/bgwriter, postgresql/database, redis/info, redis/keyspace, system/core, system/cpu, system/diskio, system/filesystem, system/fsstat, system/memory, system/network, system/process, zookeeper/mntr]]
2017-03-01T15:04:19+01:00 INFO Metricbeat process and system info: {"OSVersion":{"Major":6,"Minor":2,"Build":9200},"Arch":"amd64","NumCPU":5,"User":{"SID":"S-1-5-21-1177238915-261478967-839522115-94099","Account":"aschampe","Domain":"TSIDE","Type":1},"ProcessPrivs":{"SeBackupPrivilege":{"enabled":false},"SeChangeNotifyPrivilege":{"enabled_by_default":true,"enabled":true},"SeCreateGlobalPrivilege":{"enabled_by_default":true,"enabled":true},"SeCreatePagefilePrivilege":{"enabled":false},"SeCreateSymbolicLinkPrivilege":{"enabled":false},"SeDebugPrivilege":{"enabled":false},"SeImpersonatePrivilege":{"enabled_by_default":true,"enabled":true},"SeIncreaseBasePriorityPrivilege":{"enabled":false},"SeIncreaseQuotaPrivilege":{"enabled":false},"SeIncreaseWorkingSetPrivilege":{"enabled":false},"SeLoadDriverPrivilege":{"enabled":false},"SeLockMemoryPrivilege":{"enabled":false},"SeManageVolumePrivilege":{"enabled":false},"SeProfileSingleProcessPrivilege":{"enabled":false},"SeRemoteShutdownPrivilege":{"enabled":false},"SeRestorePrivilege":{"enabled":false},"SeSecurityPrivilege":{"enabled":false},"SeShutdownPrivilege":{"enabled":false},"SeSystemEnvironmentPrivilege":{"enabled":false},"SeSystemProfilePrivilege":{"enabled":false},"SeSystemtimePrivilege":{"enabled":false},"SeTakeOwnershipPrivilege":{"enabled":false},"SeTimeZonePrivilege":{"enabled":false},"SeUndockPrivilege":{"enabled":false}}}
2017-03-01T15:04:19+01:00 INFO SeDebugPrivilege is now enabled. SeDebugPrivilege=(Enabled)
2017-03-01T15:04:19+01:00 DBG  Skip process pid=0: error getting process state for pid=0: getProcName failed: OpenProcess failed for pid=0: The parameter is incorrect.; getProcStatus failed: OpenProcess failed for pid=0: The parameter is incorrect.; getParentPid failed: OpenProcess failed for pid=0: The parameter is incorrect.; getProcCredName failed: OpenProcess failed for pid=0: The parameter is incorrect.
2017-03-01T15:04:19+01:00 DBG  Skip process pid=4: error getting process state for pid=4: getProcName failed: GetProcessImageFileName failed for pid=4: GetProcessImageFileName failed: invalid argument; getProcCredName failed: OpenProcess failed for pid=4: Access is denied.
2017-03-01T15:04:19+01:00 DBG  Skip process pid=240: error getting process state for pid=240: getProcCredName failed: OpenProcess failed for pid=240: Access is denied.
2017-03-01T15:04:19+01:00 DBG  Skip process pid=512: error getting process state for pid=512: ..getProcCredName failed: OpenProcess failed for pid=18632: Access is denied.
2017-03-01T15:05:13+01:00 DBG  mb.NewModules() is returning map[{name:"system", config:{Module:"system", MetricSets:[cpu filesystem memory network process], Enabled:true, Hosts:[0 hosts], Period:"1m0s", Timeout:"1s", Raw:false, Fields:null, FieldsUnderRoot:false, Tags:[]}}:[{name:"cpu", module:"system", hostData:{SanitizedURI:"", Host:""}} {name:"filesystem", module:"system", hostData:{SanitizedURI:"", Host:""}} {name:"memory", module:"system", hostData:{SanitizedURI:"", Host:""}} {name:"network", module:"system", hostData:{SanitizedURI:"", Host:""}} {name:"process", module:"system", hostData:{SanitizedURI:"", Host:""}}]]
2017-03-01T15:05:13+01:00 DBG  Initializing Module type 'system': *system.Module={name:"system", config:{Module:"system", MetricSets:[cpu filesystem memory network process], Enabled:true, Hosts:[0 hosts], Period:"1m0s", Timeout:"1s", Raw:false, Fields:null, FieldsUnderRoot:false, Tags:[]}}
2017-03-01T15:05:13+01:00 DBG  Processors: 
2017-03-01T15:05:13+01:00 DBG  Initializing MetricSet type 'system/cpu' for host '': *cpu.MetricSet={name:"cpu", module:"system", hostData:{SanitizedURI:"", Host:""}}
2017-03-01T15:05:13+01:00 DBG  Initializing MetricSet type 'system/filesystem' for host '': *filesystem.MetricSet={name:"filesystem", module:"system", hostData:{SanitizedURI:"", Host:""}}
2017-03-01T15:05:13+01:00 DBG  Initializing MetricSet type 'system/memory' for host '': *memory.MetricSet={name:"memory", module:"system", hostData:{SanitizedURI:"", Host:""}}
2017-03-01T15:05:13+01:00 DBG  Initializing MetricSet type 'system/network' for host '': *network.MetricSet={name:"network", module:"system", hostData:{SanitizedURI:"", Host:""}}
2017-03-01T15:05:13+01:00 DBG  Initializing MetricSet type 'system/process' for host '': *process.MetricSet={name:"process", module:"system", hostData:{SanitizedURI:"", Host:""}}
2017-03-01T15:05:13+01:00 INFO metricbeat start running.
2017-03-01T15:05:13+01:00 DBG  Starting ModuleWrapper[name=system, len(metricSetWrappers)=5]
2017-03-01T15:05:13+01:00 DBG  Stopped ModuleWrapper[name=system, len(metricSetWrappers)=5]
2017-03-01T15:05:13+01:00 DBG  Starting metricSetWrapper[module=system, name=cpu, host=]
2017-03-01T15:05:13+01:00 DBG  Windows is interactive: true
2017-03-01T15:05:13+01:00 DBG  Starting metricSetWrapper[module=system, name=network, host=]
2017-03-01T15:05:13+01:00 DBG  Starting metricSetWrapper[module=system, name=process, host=]
2017-03-01T15:05:13+01:00 DBG  Starting metricSetWrapper[module=system, name=filesystem, host=]
2017-03-01T15:05:13+01:00 DBG  Starting metricSetWrapper[module=system, name=memory, host=]
2017-03-01T15:05:13+01:00 DBG  Publish: {

What is the issue here?

Thanks, Andreas

asp · March 1, 2017, 2:12pm

there have been many more of the mentioned error, I removed them due to the 7k char limit per post

andrewkroh · March 1, 2017, 3:52pm

Try updating to the latest release. There was fix in 5.2.0 that should help with the timeout problem.

Those a normal log messages caused by certain protected system processes which is why they are not logged at the debug level and not at the ERR or WARN level.

From: OpenProcess function (processthreadsapi.h) - Win32 apps | Microsoft Learn

If the specified process is the System Process (0x00000000), the function fails and the last error code is ERROR_INVALID_PARAMETER. If the specified process is the Idle process or one of the CSRSS processes, this function fails and the last error code is ERROR_ACCESS_DENIED because their access restrictions prevent user-level code from opening them.

system · March 29, 2017, 3:53pm

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.