search

mickem / nscp

NSClient++
http://nsclient.org
GNU General Public License v2.0
239 stars 94 forks source link

Problem with CheckEventLog on Hyper-V Server 2012 R2 #330

Open historicbruno opened 7 years ago

historicbruno commented 7 years ago

I'm using NSClient++ 0.5.0.62 with CheckEventLog and NRPE Server enabled, on a Hyper-V Server 2012 R2 machine. For some reason, CheckEventLog isn't returning successful Windows backup event logs, as it does on our other full Windows servers:

./check_nrpe -H server1 -c CheckEventLog -a file=Microsoft-Windows-Backup "filter=id eq 4"
OK: No entries found|'problem_count'=0;0;0

Compare to a working example on Windows Server 2012 R2:

./check_nrpe -H server2 -c CheckEventLog -a file=Microsoft-Windows-Backup "filter=id eq 4"
Microsoft-Windows-Backup, The backup operation has finished successfully.|'problem_count'=0;0;0

Checking the event logs shows there are in fact successful backups on server1 (with ID 4), which should be returned by the plugin. A different Hyper-V server had a backup complete with errors, and that is returned:

./check_nrpe -H server3 -c CheckEventLog -a file=Microsoft-Windows-Backup
Microsoft-Windows-Backup, The backup operation that started at '?2016?-?09?-?26T23:07:04.183740800Z' has completed with errors. Please review the event details for a solution, and then rerun the backup operation once the issue is resolved.|'problem_count'=1;0;0

I've tried nscp test --debug on the Hyper-V servers, but I don't see any more useful output.

mickem commented 7 years ago

I assume the entries are within the given timeframe? (which I think is defaulted to 24 hours).

Do you have the XML of the eventlog entry?

historicbruno commented 7 years ago

Well, normally our checks include an "AND generated gt -3d" filter or similar, to search more than the past 24 hours. I simplified the test case for ease of debugging :)

Here is XML of the latest entry:

<?xml version="1.0" encoding="utf-8" standalone="yes"?>
<Events>
    <Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'>
        <System>
            <Provider Name='Microsoft-Windows-Backup' Guid='{1DB28F2E-8F80-4027-8C5A-A11F7F10F62D}'/>
            <EventID>4</EventID>
            <Version>3</Version>
            <Level>4</Level>
            <Task>0</Task>
            <Opcode>0</Opcode>
            <Keywords>0x4000000000000000</Keywords>
            <TimeCreated SystemTime='2016-11-13T09:23:21.208126900Z'/>
            <EventRecordID>68</EventRecordID>
            <Correlation/>
            <Execution ProcessID='1892' ThreadID='3520'/>
            <Channel>Microsoft-Windows-Backup</Channel>
            <Computer>server1</Computer>
            <Security UserID='S-1-5-18'/>
        </System>
        <EventData>
            <Data Name='BackupTemplateID'>{C2831599-1831-4B63-9892-274805DE1931}</Data>
            <Data Name='HRESULT'>0x0</Data>
            <Data Name='DetailedHRESULT'>0x0</Data>
            <Data Name='ErrorMessage'>%%0</Data>
            <Data Name='BackupState'>14</Data>
            <Data Name='BackupTime'>2016-11-13T09:00:09.774395900Z</Data>
            <Data Name='BackupTarget'>\\path</Data>
            <Data Name='NumOfVolumes'>1</Data>
            <Data Name='VolumesInfo'>&lt;VolumeInfo&gt;&lt;VolumeInfoItem Name="C:" OriginalAccessPath="C:" State="14" HResult="0" DetailedHResult="0" PreviousState="9" IsCritical="1" IsIncremental="0" BlockLevel="1" HasFiles="0" HasSystemState="1" IsCompacted="0" IsPruned="0" IsRecreateVhd="0" FullBackupReason="10" DataTransferred="7118651392" NumUnreadableBytes="0" TotalSize="7118651392" TotalNoOfFiles="0" Flags="5674" BackupTypeDetermined="1" SSBTotalNoOfFiles="0" SSBTotalSizeOnDisk="0" /&gt;&lt;/VolumeInfo&gt;</Data>
            <Data Name='SourceSnapStartTime'>2016-11-13T09:00:09.680638100Z</Data>
            <Data Name='SourceSnapEndTime'>2016-11-13T09:01:47.156800500Z</Data>
            <Data Name='PrepareBackupStartTime'>&lt;TimesList&gt;&lt;Time Time="2016-11-13T09:02:22.377Z" /&gt;&lt;/TimesList&gt;</Data>
            <Data Name='PrepareBackupEndTime'>&lt;TimesList&gt;&lt;Time Time="2016-11-13T09:02:22.533Z" /&gt;&lt;/TimesList&gt;</Data>
            <Data Name='BackupWriteStartTime'>&lt;TimesList&gt;&lt;Time Time="2016-11-13T09:02:22.549Z" /&gt;&lt;/TimesList&gt;</Data>
            <Data Name='BackupWriteEndTime'>&lt;TimesList&gt;&lt;Time Time="2016-11-13T09:08:37.667Z" /&gt;&lt;/TimesList&gt;</Data>
            <Data Name='TargetSnapStartTime'>1601-01-01T00:00:00.000000000Z</Data>
            <Data Name='TargetSnapEndTime'>1601-01-01T00:00:00.000000000Z</Data>
            <Data Name='DVDFormatStartTime'>&lt;TimesList&gt;&lt;/TimesList&gt;</Data>
            <Data Name='DVDFormatEndTime'>&lt;TimesList&gt;&lt;/TimesList&gt;</Data>
            <Data Name='MediaVerifyStartTime'>&lt;TimesList&gt;&lt;/TimesList&gt;</Data>
            <Data Name='MediaVerifyEndTime'>&lt;TimesList&gt;&lt;/TimesList&gt;</Data>
            <Data Name='BackupPreviousState'>19</Data>
            <Data Name='ComponentStatus'>&lt;ComponentStatus&gt;&lt;/ComponentStatus&gt;</Data>
            <Data Name='ComponentInfo'>&lt;ComponentInfo&gt;&lt;ComponentInfoItem WriterId="{66841cd4-6ded-4f4b-8f17-fd23f8ddc3de}" InstanceId="{44844451-2797-49ed-a2d2-576378bff36c}" Name="A5DC1173-CFD6-4079-8363-9185789EBD40" LogicalPath="" Caption="Offline\H" AppName="HyperV" hResult="0" hDetailedResult="0" IsFullBackup="1" FullBackupReason="0" Size="5638088300" DataTransferred="5638088300" TotalNoOfFiles="12" /&gt;&lt;ComponentInfoItem WriterId="{66841cd4-6ded-4f4b-8f17-fd23f8ddc3de}" InstanceId="{44844451-2797-49ed-a2d2-576378bff36c}" Name="9FDA51A8-B6E6-4DC8-A015-FAAFD48E0E8A" LogicalPath="" Caption="Offline\M" AppName="HyperV" hResult="0" hDetailedResult="0" IsFullBackup="1" FullBackupReason="0" Size="5673280636" DataTransferred="5673280636" TotalNoOfFiles="11" /&gt;&lt;ComponentInfoItem WriterId="{66841cd4-6ded-4f4b-8f17-fd23f8ddc3de}" InstanceId="{44844451-2797-49ed-a2d2-576378bff36c}" Name="A4DA5651-763A-436E-870B-7AFBBD9B0BB5" LogicalPath="" Caption="Offline\W" AppName="HyperV" hResult="0" hDetailedResult="0" IsFullBackup="1" FullBackupReason="0" Size="6350193312" DataTransferred="6350193312" TotalNoOfFiles="12" /&gt;&lt;ComponentInfoItem WriterId="{66841cd4-6ded-4f4b-8f17-fd23f8ddc3de}" InstanceId="{44844451-2797-49ed-a2d2-576378bff36c}" Name="Host Component" LogicalPath="" Caption="Host Component" AppName="HyperV" hResult="0" hDetailedResult="0" IsFullBackup="1" FullBackupReason="0" Size="50335" DataTransferred="0" TotalNoOfFiles="0" /&gt;&lt;/ComponentInfo&gt;</Data>
            <Data Name='SSBEnumerateStartTime'>1601-01-01T00:00:00.000000000Z</Data>
            <Data Name='SSBEnumerateEndTime'>1601-01-01T00:00:00.000000000Z</Data>
            <Data Name='SSBVhdCreationStartTime'>1601-01-01T00:00:00.000000000Z</Data>
            <Data Name='SSBVhdCreationEndTime'>1601-01-01T00:00:00.000000000Z</Data>
            <Data Name='SSBBackupStartTime'>1601-01-01T00:00:00.000000000Z</Data>
            <Data Name='SSBBackupEndTime'>1601-01-01T00:00:00.000000000Z</Data>
            <Data Name='SystemStateBackup'>&lt;SystemState IsPresent="1" HResult="0" DetailedHResult="0" /&gt;</Data>
            <Data Name='BMR'>&lt;BMR IsPresent="1" HResult="0" DetailedHResult="0" /&gt;</Data>
            <Data Name='VssFullBackup'>false</Data>
            <Data Name='UserInputBMR'>true</Data>
            <Data Name='UserInputSSB'>true</Data>
            <Data Name='BackupSuccessLogPath'>C:\Windows\Logs\WindowsServerBackup\Backup-13-11-2016_09-00-09.log</Data>
            <Data Name='BackupFailureLogPath'>C:\Windows\Logs\WindowsServerBackup\Backup_Error-13-11-2016_09-00-09.log</Data>
            <Data Name='EnumerateBackupStartTime'>&lt;TimesList&gt;&lt;Time Time="1601-01-01T00:00:00.000Z" /&gt;&lt;/TimesList&gt;</Data>
            <Data Name='EnumerateBackupEndTime'>&lt;TimesList&gt;&lt;Time Time="1601-01-01T00:00:00.000Z" /&gt;&lt;/TimesList&gt;</Data>
            <Data Name='PruneBackupStartTime'>&lt;TimesList&gt;&lt;Time Time="1601-01-01T00:00:00.000Z" /&gt;&lt;/TimesList&gt;</Data>
            <Data Name='PruneBackupEndTime'>&lt;TimesList&gt;&lt;Time Time="1601-01-01T00:00:00.000Z" /&gt;&lt;/TimesList&gt;</Data>
            <Data Name='BackupFlags'>0x1</Data>
            <Data Name='ComponentInfoSummary'>&lt;ComponentInfoSummary ComponentInfoArrayPresent="1" TotalComponents="4" SucceededComponents="4" /&gt;</Data>
        </EventData>
    </Event>
</Events>
mickem commented 7 years ago

LKooks good, strange..

Please beware there is also a "scan range" which is defaulted to 24hours so youneed to increase that if you want to search further back: scan-range=-72h