オンサイトセミナー
豊田孝の「IT談話館」 Windowsメモリダンプ解析を依頼する WinDbgとシステム分析




メモリ解析サービス



豊田孝のクラッシュダンプ解析技術


 Windowsシステムは性能限界に達すると動作を停止し、クラッシュダンプを作成します。本稿では、システムクラッシュ時に作成される「カーネルメモリダンプ」の解析作業工程の一旦を紹介します。

 まずは次のようなカーネルメモリダンプ情報をご覧ください。
*******************************************************************************
*                                                                             *
*                        Bugcheck Analysis                                    *
*                                                                             *
*******************************************************************************

Use !analyze -v to get detailed debugging information.

BugCheck 133, {0, 501, 500, 0}

*** ERROR: Module load completed but symbols could not be loaded for netr28ux.sys
Probably caused by : netr28ux.sys ( netr28ux+8bd3 )

Followup:     MachineOwner
---------

0: kd> vertarget
Windows 8.1 Kernel Version 9600 MP (4 procs) Free x64
Product: WinNt, suite: TerminalServer SingleUserTS
Built by: 9600.17328.amd64fre.winblue_r3.140827-1500
Machine Name:
Kernel base = 0xfffff802`50871000 PsLoadedModuleList = 0xfffff802`50b47370
Debug session time: Fri Nov  7 14:50:46.222 2014 (UTC + 9:00)
System Uptime: 0 days 21:21:18.953
 この情報は次のような障害データを提供しています。  多くの方は「!analyze -v」コマンドを実行していると思いますが、本「IT談話館」」は、解析作業のスケジュール設定や予算見積りをはじめとするビジネス上の観点から、次のような多少多めの情報をまず収集し、クラッシュ発生当時のシステム概要を把握することにしています。
Analyze info
DPC_WATCHDOG_VIOLATION (133)
The DPC watchdog detected a prolonged run time at an IRQL of DISPATCH_LEVEL
or above.
Arguments:
Arg1: 0000000000000000, A single DPC or ISR exceeded its time allotment. The offending
	component can usually be identified with a stack trace.
Arg2: 0000000000000000, The DPC time count (in ticks).
Arg3: 0000000000000000, The DPC time allotment (in ticks).
Arg4: 0000000000000000, cast to nt!DPC_WATCHDOG_GLOBAL_TRIAGE_BLOCK, which contains
	additional information regarding this single DPC timeout
*******************************************************************************
*                                                                             *
*                        Bugcheck Analysis                                    *
*                                                                             *
*******************************************************************************

Use !analyze -v to get detailed debugging information.

BugCheck 133, {0, 501, 500, 0}

Probably caused by : netr28ux.sys ( netr28ux+8bd3 )

Followup:     MachineOwner
---------


Memory
fffff802`50b4e6e0  00000000`00000133
fffff802`50b4e6e8  00000000`00000000
fffff802`50b4e6f0  00000000`00000501
fffff802`50b4e6f8  00000000`00000500
fffff802`50b4e700  00000000`00000000
fffff802`50b4e708  00000000`00000000
fffff802`50b4e710  00000000`00000000
fffff802`50b4e718  00000000`00000000
fffff802`50b4e720  00000000`00000000
fffff802`50b4e728  00000000`00000000
fffff802`50b4e730  ffffe001`91e829f0
fffff802`50b4e738  fffff802`50b27e00 nt!EtwpBugCheckCallback
fffff802`50b4e740  fffff802`50b4e740 nt!KeBugCheckAddPagesCallbackListHead
fffff802`50b4e748  fffff802`50b4e740 nt!KeBugCheckAddPagesCallbackListHead
fffff802`50b4e750  00000000`00000000
fffff802`50b4e758  00000000`00000000

metacommand
Bugcheck code 00000133
Arguments 00000000`00000000 00000000`00000501 00000000`00000500 00000000`00000000

Inter-processor Interrupt
IPI State for Processor 0
    TargetCount          0  PacketBarrier        0  IpiFrozen     0 [Running]


IPI State for Processor 1
    TargetCount          0  PacketBarrier        0  IpiFrozen     2 [Frozen]


IPI State for Processor 2
    TargetCount          0  PacketBarrier        0  IpiFrozen     2 [Frozen]


IPI State for Processor 3
    TargetCount          0  PacketBarrier        0  IpiFrozen     2 [Frozen]



eProcesses
Processed 256 entries ffffe00192823be8 ffffe001978e7be8
Processed 512 entries ffffe0019792abe8 ffffe00197929be8
Processed 768 entries ffffe0019274c528 ffffe00197c0c368
Processed 1024 entries ffffe00197fe3368 ffffe00197fa5368
Processed 1280 entries ffffe001978ea368 ffffe00197c11368
Processed 1536 entries ffffe00197e7c368 ffffe00197eca368
Processed 1792 entries ffffe0019879abe8 ffffe00198638be8
Processed 2048 entries ffffe001985bcbe8 ffffe001985ca368
Processed 2304 entries ffffe00198831be8 ffffe0019882abe8
Processed 2560 entries ffffe001988f5368 ffffe00195babbe8
Found list end after 2590 entries

kProcesses
Found list end after 87 entries

Verifier

Verify Flags Level 0x0002092b

  STANDARD FLAGS:
    [X] (0x00000000) Automatic Checks
    [X] (0x00000001) Special pool
    [X] (0x00000002) Force IRQL checking
    [X] (0x00000008) Pool tracking
    [ ] (0x00000010) I/O verification
    [X] (0x00000020) Deadlock detection
    [ ] (0x00000080) DMA checking
    [X] (0x00000100) Security checks
    [X] (0x00000800) Miscellaneous checks
    [X] (0x00020000) DDI compliance checking

  ADDITIONAL FLAGS:
    [ ] (0x00000004) Randomized low resources simulation
    [ ] (0x00000200) Force pending I/O requests
    [ ] (0x00000400) IRP logging
    [ ] (0x00002000) Invariant MDL checking for stack
    [ ] (0x00004000) Invariant MDL checking for driver
    [ ] (0x00008000) Power framework delay fuzzing
    [ ] (0x00010000) Port/miniport interface checking
    [ ] (0x00040000) Systematic low resources simulation
    [ ] (0x00080000) DDI compliance checking (additional)
    [ ] (0x00200000) NDIS/WIFI verification
    [ ] (0x00800000) Kernel synchronization delay fuzzing
    [ ] (0x01000000) VM switch verification
    [ ] (0x02000000) Code integrity checks

    [X] Indicates flag is enabled


Summary of All Verifier Statistics

  RaiseIrqls           0x6308c4
  AcquireSpinLocks     0xeaa213
  Synch Executions     0x0
  Trims                0x565085

  Pool Allocations Attempted             0x97cf64
  Pool Allocations Succeeded             0x97cf64
  Pool Allocations Succeeded SpecialPool 0x97cf64
  Pool Allocations With NO TAG           0x24
  Pool Allocations Failed                0x0

  Current paged pool allocations         0x11a for 0019F2C6 bytes
  Peak paged pool allocations            0x12f for 003A098E bytes
  Current nonpaged pool allocations      0x5d87 for 01DF534B bytes
  Peak nonpaged pool allocations         0x95c3 for 020D6667 bytes


Kernel Logs
(WmiTrace) StrDump Generic
  LoggerContext Array @ 0xFFFFF80250B28720 [64 Elements]
    Logger Id 0x02 @ 0xFFFFE00196C7BC00 Named 'Circular Kernel Context Logger'
    Logger Id 0x03 @ 0xFFFFE001917BF040 Named 'Eventlog-Security'
    Logger Id 0x04 @ 0xFFFFE00191758C00 Named 'AITEventLog'
    Logger Id 0x05 @ 0xFFFFE0019175AC40 Named 'Audio'
    Logger Id 0x06 @ 0xFFFFE0019175DC40 Named 'DiagLog'
    Logger Id 0x07 @ 0xFFFFE0019175D840 Named 'EventLog-Application'
    Logger Id 0x08 @ 0xFFFFE001917BE040 Named 'EventLog-Microsoft-Windows-WorkFolders-WHC'
    Logger Id 0x09 @ 0xFFFFE001917BF440 Named 'EventLog-System'
    Logger Id 0x0a @ 0xFFFFE00191A8C780 Named 'FamilySafetyAOT'
    Logger Id 0x0b @ 0xFFFFE00191A96040 Named 'LwtNetLog'
    Logger Id 0x0c @ 0xFFFFE00191B172C0 Named 'NtfsLog'
    Logger Id 0x0d @ 0xFFFFE0019779AC40 Named 'Steam Event Tracing'
    Logger Id 0x0e @ 0xFFFFE00191B1B040 Named 'SQMLogger'
    Logger Id 0x0f @ 0xFFFFE00191B2D040 Named 'UBPM'
    Logger Id 0x10 @ 0xFFFFE00191B30040 Named 'WdiContextLog'
    Logger Id 0x12 @ 0xFFFFE00195ABD040 Named 'WFP-IPsec Diagnostics'
    Logger Id 0x13 @ 0xFFFFE00195E29680 Named 'MpWppTracing-11062014-002959-00000003-ffffffff'


0*: Current->0xfffff80250bcaa00	Irql->0x0d	PreIrql->0	Rip->00000000`00000000	nLevel->2	TF->0x0000000000000000
	Process->0xfffff80250bca300	Name->Idle
	State->0x2	WaitReason->25
0: Next->0xffffe001946c3880
	Process->0xffffe0019161f040	Name->System
	State->0x3	WaitReason->32
0: Idle->0xfffff80250bcaa00
	Process->0xfffff80250bca300	Name->Idle
	State->0x2	WaitReason->25

1: Current->0xffffe001973c3080	Irql->0x00
	Process->0xffffe00191ea1080	Name->RustClient.exe
	State->0x2	WaitReason->31
1: Next->***
1: Idle->0xffffd000d41d92c0
	Process->0xfffff80250bca300	Name->Idle
	State->0x2	WaitReason->00

2: Current->0xffffe00193ecf880	Irql->0x00
	Process->0xffffe0019161f040	Name->System
	State->0x2	WaitReason->00
2: Next->***
2: Idle->0xffffd000d43552c0
	Process->0xfffff80250bca300	Name->Idle
	State->0x2	WaitReason->00

3: Current->0xffffe00191e44040	Irql->0x00
	Process->0xffffe0019161f040	Name->System
	State->0x2	WaitReason->00
3: Next->***
3: Idle->0xffffd000d43d32c0
	Process->0xfffff80250bca300	Name->Idle
	State->0x2	WaitReason->00

Cores:4
 この情報は本「IT談話館」」の独自解析コードで収集しています。一見すると収集量過多の印象を受けると思いますが、このレベルの情報は解析作業のスケジュール設定や費用を見積もったり、解析依頼者側の技術レベルを理解する上で重要です。解析作業はあくまでもビジネスであり、作業の依頼者が存在します。

 上記情報内の赤色データはいろいろなヒントを与えてくれます。たとえば、2つの起動プロセス数の数値は「2590」と「87」という具合にExectutiveとKernelでは大きく異なっています。また、解析依頼者側は「Verifier」を有効にし、すでに「netr28ux.sys」デバイスドライバーをかなり調査していることを示唆しています。さらには、割り込み要求レベル(IRQL)は十進数の13ということになっており、常識的には、CPUへの割り込みが発生していることが推測できます。そこで、新しい解析コードを作成し、次のような情報を収集します。
*Core->00 Pcr->0xfffff80250b71000 Prcb->0xfffff80250b71180 CurrentThread->0xfffff80250bcaa00 IntObj->0xfffff80250855800 IntLevel->2 Irql->13
	Trapframe->0xfffff802522b7880 PreviousIrql->02 PreviousRip->ndis!NdisMIndicateReceiveNetBufferLists+0x825 (fffff800`9eabe585)
Core->01	Pcr->0xffffd000d41cd000	Prcb->0xffffd000d41cd180	CurrentThread->0xffffe001973c3080
Core->02	Pcr->0xffffd000d4349000	Prcb->0xffffd000d4349180	CurrentThread->0xffffe00193ecf880
Core->03	Pcr->0xffffd000d43c7000	Prcb->0xffffd000d43c7180	CurrentThread->0xffffe00191e44040
 この情報は、割り込み要求レベル「2」の処理過程で別の割り込み「13」が発生したことを示しています。前者の割り込みは「ndis」から要求されていることも分かります。ここまでの情報を総合すると、次のようなNDISコマンドを実行し、NICの状態を調査する必要がありそうです。
0: kd> !ndiskd.minidriver
    ffffe00195f7b740 - tunnel
    ffffe001958df760 - vwifimp
    ffffe00193aa3530 - BthPan
    ffffe00193b9dba0 - netr28ux

0: kd> !ndiskd.minidriver ffffe00193b9dba0


MINIPORT DRIVER

    netr28ux

    Ndis handle        ffffe00193b9dba0
    Driver context     NULL
    DRIVER_OBJECT      ffffe00193b8f080
    Driver image       netr28ux.sys
    Registry path      \REGISTRY\MACHINE\SYSTEM\ControlSet001\Services\netr28ux
    Reference Count    2
    Flags              VERIFYING


MINIPORTS

    Miniport                                                                    
    ffffe00193ba11a0 - ASUS USB-N53 802.11a/b/g/n Network Adapter

    Handlers
    Device objects

0: kd> !ndiskd.netadapter ffffe00193ba11a0


MINIPORT

    ASUS USB-N53 802.11a/b/g/n Network Adapter

    Ndis handle        ffffe00193ba11a0
    Ndis API version   v6.40
    Adapter context    ffffe00194000000
    Driver             ffffe00193b9dba0 - netr28ux  v1.1
    Network interface  ffffcf8099358a20

    Media type         802.3
    Physical medium    Native802.11
    Device instance    USB\VID_0B05&PID_179D\1.0
    Device object      ffffe00193ba1050    More information
    MAC address        60-a4-4c-ec-4c-3d


STATE

    Miniport           Running
    Device PnP         Started             Show state history
    Datapath           DIVERTED_BECAUSE_MINIPORT_RESETTING
    NBL status         NDIS_STATUS_RESET_IN_PROGRESS
    Interface          Up
    Media              Connected
    Power              D0
    References         0n18                Show detail
    User handles       1
    Automatic resets   1
    Resets requested   0
    Pending OID        Unknown value 0xff0c000b
    Flags              NOT_BUS_MASTER, DEFAULT_PORT_ACTIVATED, CALLING_RESET,
                       RESET_IN_PROGRESS, SUPPORTS_MEDIA_SENSE,
                       DOES_NOT_DO_LOOPBACK, MEDIA_CONNECTED
    PnP flags          PM_SUPPORTED, DEVICE_POWER_ENABLED, RECEIVED_START,
                       VERIFYING, HARDWARE_DEVICE, NDIS_WDM_DRIVER
    More flags         PROCESSING_REQUEST, REQUEST_TIMEOUT
    
    .reload ndis.sys....
                     Reload succeeded.



BINDINGS

    Protocol list      Driver              Open               Context           
    [Next link in list is not readable; aborting the list traversal]
    No protocols have an open binding

    Filter list        Driver              Module             Context           
    No filters are attached


MORE INFORMATION

    Driver handlers                        Task offloads
    Power management                       PM protocol offloads
    Pending OIDs                           Timers
    Pending NBLs
    Wake-on-LAN (WoL)                      Packet filter
    Receive queues                         Receive filtering
    RSS                                    NIC switch
    Hardware resources
    NDIS ports                             WMI guids
 ご覧のように、NICはリセット状態に入っています。なぜリセット状態に入ったのか?実務解析作業ではこの疑問への回答を用意する必要がありますが、本稿ではその説明は割愛させていただき、解析コードの開発技術とともに、「オンサイトセミナー」に譲ります。

 WindowsはSaaSとして提供される時代に入り、その内部は頻繁に更新されています。更新内容の多くは、いろいろな事情から、公にされることはほとんどありません。最新のユーザー空間とカーネル空間に関する信頼できる情報を取得するには、インターネットなどでは語られない高度な内部解析技術が必須とされています。時代が求める人材の育成と技術の習得には、「時間と予算の投資」が必要です。


オンサイトセミナー




ビジネスメニュー
Windowsクラッシュダンプ解析サービス 技術資料

Copyright©豊田孝 2004- 2018
本日は2018-10-18です。