A lot of misc adjustments, pretty broken now.
[captive.git] / src / TraceFS / checktrace.pl
1 #! /usr/bin/perl
2
3 # $Id$
4 # Checks assumptions on Cc* (Cache Manager) behaviour by reading TraceFS log
5 # Copyright (C) 2003 Jan Kratochvil <project-captive@jankratochvil.net>
6
7 # This program is free software; you can redistribute it and/or modify
8 # it under the terms of the GNU General Public License as published by
9 # the Free Software Foundation; exactly version 2 of June 1991 is required
10
11 # This program is distributed in the hope that it will be useful,
12 # but WITHOUT ANY WARRANTY; without even the implied warranty of
13 # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
14 # GNU General Public License for more details.
15
16 # You should have received a copy of the GNU General Public License
17 # along with this program; if not, write to the Free Software
18 # Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
19
20
21 use strict;
22 use warnings;
23 use Data::Dumper;
24 use Carp qw(cluck confess);
25
26
27 my $filter=0;
28 $Data::Dumper::Sortkeys=1;
29 my $ntfs_blocksize=0x200;
30
31 # $Object->{"by"}="CcSomeFunction";
32 # $Object->{"line_enter"}=123;
33 # $Object->{"line_leave"}=124;
34 # $Object->{"ProcessThread"}="0x12345678/0x12345678";
35 # $Object->{"data"}[dataline]{"FileObject"}="0x12345678";
36 # $Object->{"data"}[dataline]{"FileName"}="\filename" or undef() if NULL;
37 # $Object->{"data"}[dataline]{"Flags"}="0x40100";
38 # $Object->{"data"}[dataline]{"SectionObjectPointer"}="0x12345678";
39 # $Object->{"data"}[dataline]{"SharedCacheMap"}="0x12345678";
40 # $FileObject{$FileObject}{"FileObject"}="0x12345678";
41 # $FileObject{$FileObject}{"SectionObjectPointer"}="0x12345678";
42 # $SectionObjectPointer{$SectionObjectPointer}{"SectionObjectPointer"}="0x12345678";
43 # $SectionObjectPointer{$SectionObjectPointer}{"SharedCacheMap"}="0x12345678";
44 # $SharedCacheMap{$SharedCacheMap}{"SharedCacheMap"}="0x12345678";
45 # $SharedCacheMap{$SharedCacheMap}{"SectionObjectPointer"}="0x12345678";
46 # $SharedCacheMap{$SharedCacheMap}{"AllocationSize"}="0x12345";
47 # $SharedCacheMap{$SharedCacheMap}{"FileSize"}="0x12345";
48 # $SharedCacheMap{$SharedCacheMap}{"ref_count"}=1;
49 # $SharedCacheMap{$SharedCacheMap}{"map"}="0x12345678" (Bcb);
50 # $SharedCacheMap{$SharedCacheMap}{"pin"}{"0x1000"}="0x12345678" (Bcb) if !Bcb->{"OwnerPointer"};
51 # $SharedCacheMap{$SharedCacheMap}{"PinAccess"}=0 or 1;
52 # $SharedCacheMap{$SharedCacheMap}{"LogHandle"}="0x12345678" optional;
53 # $SharedCacheMap{$SharedCacheMap}{"AcquireForLazyWrite"}=0;    # count
54 # $SharedCacheMap{$SharedCacheMap}{"in_memory"}{"0x4000"}=1;    # mapped page?
55 # $SharedCacheMap{$SharedCacheMap}{"Buffer"}="0x12345678";
56 # $LogHandle{$LogHandle}{"LogHandle"}="0x12345678";
57 # $Bcb{$Bcb}{"Bcb"}="0x12345678";
58 # $Bcb{$Bcb}{"SharedCacheMap"}="0x12345678";
59 # $Bcb{$Bcb}{"type"}="pin" or "map";
60 # $Bcb{$Bcb}{"ref_count"}=1;
61 # $Bcb{$Bcb}{"FileOffset"}="0x1000" if {"type"} eq "pin";
62 # $Bcb{$Bcb}{"Buffer"}="0x12345678";    # PAGE_SIZE-aligned for "pin", FileOffset_0-aligned for "map"
63 # $Bcb{$Bcb}{"OwnerPointer"}="0x12345678" optional;
64 # $Bcb{$Bcb}{"Lsn"}="0x12345678" optional;
65 # $Bcb{$Bcb}{"dirty"}=1 optional;
66 # $MdlChain{$MdlChain}{"MdlChain"}="0x12345678";
67 # $MdlChain{$MdlChain}{"FileObject"}="0x12345678";
68 # $MdlChain{$MdlChain}{"FileOffset"}="0x5000";
69 # $MdlChain{$MdlChain}{"Length"}="0x9000";
70
71 my %FileObject;
72 my %LogHandle;
73 my %SectionObjectPointer;
74 my %SharedCacheMap;
75 my %Bcb;
76 my %MdlChain;
77 my %LastLeave;  # $ProcessThread=>[$Object,$Object,...]
78 my $LastLeave;  # ref copy of the last item for the current $ProcessThread
79 my $ProcessThread;
80 my %EnterLeave;
81 my $EnterLeave; # ref copy of the list for the current $ProcessThread
82
83 END {
84         print Data::Dumper->Dump([\%FileObject,\%SectionObjectPointer,\%SharedCacheMap,\%Bcb],
85                                [qw(%FileObject  %SectionObjectPointer  %SharedCacheMap  %Bcb)]) if !$filter;
86         }
87
88 my $Object;
89
90 sub tohex($)
91 {
92 my($num)=@_;
93
94         return sprintf("0x%X",$num);
95 }
96
97 sub FObject($)
98 {
99 my($FileObject)=@_;
100
101         my $FObject=$FileObject{$FileObject};
102         if (!$FObject) {
103                 my($package,$filename,$line,$subroutine)=caller 0;
104                 warn "Non-existent FileObject $FileObject by line $line";
105                 }
106         return $FObject;
107 }
108
109 sub delete_FObject($)
110 {
111 my($FObject)=@_;
112
113         my $FileObject=$FObject->{"FileObject"};
114         delete $FileObject{$FileObject};
115 }
116
117 sub SObject($)
118 {
119 my($SectionObjectPointer)=@_;
120
121         my $SObject=$SectionObjectPointer{$SectionObjectPointer};
122         if (!$SObject) {
123                 my($package,$filename,$line,$subroutine)=caller 0;
124                 warn "Non-existent SectionObjectPointer $SectionObjectPointer by line $line"
125                 }
126         return $SObject;
127 }
128
129 sub SObject_from_FileObject($)
130 {
131 my($FileObject)=@_;
132
133         return if !(my $FObject=FObject $FileObject);
134         my $SObject=SObject $FObject->{"SectionObjectPointer"};
135         if (!$SObject) {
136                 my($package,$filename,$line,$subroutine)=caller 0;
137                 warn "by line $line";
138                 }
139         return $SObject;
140 }
141
142 sub delete_CObject($)
143 {
144 my($CObject)=@_;
145
146         my $SharedCacheMap=$CObject->{"SharedCacheMap"};
147         do { warn "Trailing map $_ of SharedCacheMap $SharedCacheMap during its deletion" if $_; } for ($CObject->{"map"});
148         do { warn "Trailing pin $_ of SharedCacheMap $SharedCacheMap during its deletion" if $_; } for (values(%{$CObject->{"pin"}}));
149         if (my $LogHandle=$CObject->{"LogHandle"}) {
150                 do { warn "INTERNAL: Missing LogHandle $LogHandle for SharedCacheMap $SharedCacheMap"; return; }
151                         if !(my $LObject=$LogHandle{$LogHandle});
152                 # Do not delete $LogHandle as it may be used by many SharedCacheMap-s
153                 }
154         warn "ref_count=".$CObject->{"ref_count"}." of SharedCacheMap $SharedCacheMap during its deletion"
155                         if $CObject->{"ref_count"};
156         delete $SharedCacheMap{$SharedCacheMap};
157 }
158
159 sub CObject($)
160 {
161 my($SharedCacheMap)=@_;
162
163         my $CObject=$SharedCacheMap{$SharedCacheMap};
164         if (!$CObject) {
165                 my($package,$filename,$line,$subroutine)=caller 0;
166                 warn "Non-existent SharedCacheMap $SharedCacheMap by line $line";
167                 }
168         return $CObject;
169 }
170
171 sub CObject_from_FileObject($)
172 {
173 my($FileObject)=@_;
174
175         return if !(my $SObject=SObject_from_FileObject $FileObject);
176         return if !(my $CObject=CObject $SObject->{"SharedCacheMap"});
177         return $CObject;
178 }
179
180 sub SharedCacheMap_valid($)
181 {
182 my($SharedCacheMap)=@_;
183
184         cluck if !defined $SharedCacheMap;
185         return 0 if "0x".("F"x8) eq $SharedCacheMap;
186         return 0 if !eval $SharedCacheMap;
187         return 1;
188 }
189
190 sub check_data($)
191 {
192 my($data)=@_;
193
194         if (!eval $data->{"SectionObjectPointer"}) {
195                 return if $Object->{"by"} eq "IRP_MJ_CREATE";   # SectionObjectPointer is not yet initialized
196                 warn "Existing FileObject ".$data->{"FileObject"}." but no SectionObjectPointer found"
197                                 if $FileObject{$data->{"FileObject"}} && eval($FileObject{$data->{"FileObject"}}{"SectionObjectPointer"});
198                 return;
199                 }
200         my $SectionObjectPointer=$data->{"SectionObjectPointer"};
201         if (!SharedCacheMap_valid $data->{"SharedCacheMap"} && $SectionObjectPointer{$SectionObjectPointer}) {
202                 return if !(my $SObject=SObject $SectionObjectPointer);
203                 my $SharedCacheMap=$SObject->{"SharedCacheMap"};
204                 return if !eval $SharedCacheMap;
205                 my $CObject=CObject $SharedCacheMap;
206                 warn "Existing SectionObjectPointer ".$data->{"SectionObjectPointer"}." but no SharedCacheMap found,"
207                                                 ." ref_count of SharedCacheMap is ".$CObject->{"ref_count"}
208                                 if $CObject->{"ref_count"};
209 #                               if $SectionObjectPointer{$data->{"SectionObjectPointer"}};
210                 # SharedCacheMap was droppped by async task as it had ref_count==0.
211                 delete_CObject $CObject;
212                 $SObject->{"SharedCacheMap"}=tohex(0);
213                 # FileObject is still valid!
214                 return;
215                 }
216         return if !$FileObject{$data->{"FileObject"}};
217         return if !(my $FObject=FObject $data->{"FileObject"});
218         $SectionObjectPointer=$FObject->{"SectionObjectPointer"};
219         return if !(my $SObject=SObject $SectionObjectPointer);
220         warn "FileObject ".$FObject->{"FileObject"}
221                                         ." expected SectionObjectPointer $SectionObjectPointer"
222                                         ." but found SectionObjectPointer ".$data->{"SectionObjectPointer"}
223                         if $SectionObjectPointer ne $data->{"SectionObjectPointer"};
224         my $SharedCacheMap=$SObject->{"SharedCacheMap"};
225         warn "FileObject ".$FObject->{"FileObject"}." SectionObjectPointer ".$SObject->{"SectionObjectPointer"}
226                                         ." expected SharedCacheMap $SharedCacheMap"
227                                         ." but found SharedCacheMap ".$data->{"SharedCacheMap"}
228                         if $SharedCacheMap ne $data->{"SharedCacheMap"};
229         warn "INTERNAL: SharedCacheMap $SharedCacheMap of FileObject ".$FObject->{"FileObject"}." got destroyed"
230                         if !$SharedCacheMap{$SharedCacheMap};
231 }
232
233 sub CcInitializeCacheMap($$$$$)
234 {
235 my($FileObject,$AllocationSize,$FileSize,$ValidDataLength,$PinAccess)=@_;
236
237         $ValidDataLength=$FileSize if $ValidDataLength==eval("0x".("F"x8));
238         $Object->{"ref_count"}=1;
239         $Object->{"AllocationSize"}=tohex($AllocationSize);
240         $Object->{"FileSize"}=tohex($FileSize);
241         $Object->{"ValidDataLength"}=tohex($ValidDataLength);
242         $Object->{"map"}=undef();
243         $Object->{"pin"}={};
244         $Object->{"PinAccess"}=$PinAccess;
245         $Object->{"FileObject"}=$FileObject;
246 }
247
248 sub CcInitializeCacheMap_leave()
249 {
250         my $SharedCacheMap=$Object->{"data"}[1]{"SharedCacheMap"};
251         $Object->{"SharedCacheMap"}=$SharedCacheMap;
252         my $old=$SharedCacheMap{$SharedCacheMap};
253         if (!SharedCacheMap_valid $Object->{"data"}[0]{"SharedCacheMap"} && $old) {
254                 # SharedCacheMap got deleted in the meantime
255                 delete_CObject CObject $SharedCacheMap;
256                 # Either it got deleted of some foreign SectionObjectPointer
257                 # or of the current one:
258                 if (my $SObject=$SectionObjectPointer{$Object->{"data"}[0]{"SectionObjectPointer"}}) {
259                         $SObject->{"SharedCacheMap"}=tohex(0);
260                         }
261                 $old=undef();
262                 }
263         if (!$old != !SharedCacheMap_valid $Object->{"data"}[0]{"SharedCacheMap"}) {
264                 warn "Expecting old SharedCacheMap validity ".(!!$old)
265                                 ." but found old SharedCacheMap ".$Object->{"data"}[0]{"SharedCacheMap"};
266                 }
267         warn "New SharedCacheMap ".$Object->{"data"}[1]{"SharedCacheMap"}." is not valid"
268                         if !SharedCacheMap_valid $Object->{"data"}[1]{"SharedCacheMap"};
269         if (SharedCacheMap_valid $Object->{"data"}[0]{"SharedCacheMap"}) {
270                 warn "Existing SharedCacheMap changed"
271                                                 ." from ".$Object->{"data"}[0]{"SharedCacheMap"}." to ".$Object->{"data"}[1]{"SharedCacheMap"}
272                                 if $Object->{"data"}[0]{"SharedCacheMap"} ne $Object->{"data"}[1]{"SharedCacheMap"};
273                 }
274         if ($old) {
275                 for my $field (qw(AllocationSize FileSize PinAccess)) {
276                         warn "SharedCacheMap $SharedCacheMap old instance $field ".$old->{$field}
277                                                         ." != new instance $field ".$Object->{$field}
278                                         if $old->{$field} ne $Object->{$field};
279                         }
280                 do { warn "Existing map Bcb $_ during CcInitializeCacheMap()" if $_; } for ($old->{"map"});
281                 do { warn "Existing pin Bcb $_ during CcInitializeCacheMap()" if $_; } for (values(%{$old->{"pin"}}));
282                 $Object->{"ref_count"}+=$old->{"ref_count"};
283                 }
284         $SharedCacheMap{$SharedCacheMap}=$Object;
285
286         warn "Changed SectionObjectPointer inside CcInitializeCacheMap()"
287                                         ." from ".$Object->{"data"}[0]{"SectionObjectPointer"}." to ".$Object->{"data"}[1]{"SectionObjectPointer"}
288                         if $Object->{"data"}[0]{"SectionObjectPointer"} ne $Object->{"data"}[1]{"SectionObjectPointer"};
289         my $SectionObjectPointer=$Object->{"data"}[1]{"SectionObjectPointer"};
290
291         my $FileObject=$Object->{"FileObject"};
292         if (my $FObject=$FileObject{$FileObject}) {
293                 if (my $SObject=$SectionObjectPointer{$FObject->{"SectionObjectPointer"}}) {
294                         warn "Changed SectionObjectPointer of FileObject $FileObject"
295                                                         ." from ".$FObject->{"SectionObjectPointer"}." to ".$SectionObjectPointer
296                                         if $FObject->{"SectionObjectPointer"} ne $SectionObjectPointer;
297                         }
298                 # Otherwise SectionObjectPointer could be deleted and rebuilt async in the meantime.
299                 }
300         $FileObject{$FileObject}={
301                         "FileObject"=>$FileObject,
302                         "SectionObjectPointer"=>$SectionObjectPointer,
303                         };
304
305         if (my $SObject=$SectionObjectPointer{$SectionObjectPointer}) {
306                 warn "Changed SharedCacheMap of SectionObjectPointer $SectionObjectPointer"
307                                                 ." from ".$SObject->{"SharedCacheMap"}." to ".$SharedCacheMap
308                                 if $SObject->{"SharedCacheMap"} ne $SharedCacheMap && eval($SObject->{"SharedCacheMap"});
309                 }
310         $SectionObjectPointer{$SectionObjectPointer}={
311                         "SectionObjectPointer"=>$SectionObjectPointer,
312                         "SharedCacheMap"=>$SharedCacheMap,
313                         };
314
315         CcSetFileSizes($FileObject,map({ eval($Object->{$_}); } qw(AllocationSize FileSize ValidDataLength)));
316         delete $Object->{$_} for (qw(FileObject ValidDataLength));
317 }
318
319 sub CcUninitializeCacheMap($$)
320 {
321 my($FileObject,$TruncateSize)=@_;
322
323         $Object->{"FileObject"}=$FileObject;
324 }
325
326 sub CcUninitializeCacheMap_leave($)
327 {
328 my($r)=@_;
329
330         my $FileObject=$Object->{"FileObject"};
331         # 'r' means function success.
332         # r=0 either if no CcInitializeCacheMap() was called at all
333         # or if Cc was unable to detach SharedCacheMap and it remains valid
334         # (FIXME: Do we SharedCacheMap->ref_count-- on in such case?).
335         my $SectionObjectPointer=$FileObject{$FileObject}->{"SectionObjectPointer"} if $FileObject{$FileObject};
336         my $SharedCacheMap=$SectionObjectPointer{$SectionObjectPointer}->{"SharedCacheMap"}
337                         if $SectionObjectPointer && $SectionObjectPointer{$SectionObjectPointer};
338         warn "Unexpected 'r' result $r for CcUninitializeCacheMap of FileObject $FileObject"
339                         if !(eval($SharedCacheMap) && !SharedCacheMap_valid($Object->{"data"}[1]{"SharedCacheMap"})) != !$r;
340         if (!eval $SharedCacheMap) {
341                 for my $SharedCacheMap ($Object->{"data"}[0]{"SharedCacheMap"},$Object->{"data"}[1]{"SharedCacheMap"}) {
342                         warn "Not expecting valid SharedCacheMap $SharedCacheMap"
343                                         if SharedCacheMap_valid $SharedCacheMap;
344                         }
345                 return;
346                 }
347         for my $SharedCacheMap ($Object->{"data"}[0]{"SharedCacheMap"}) {
348                 warn "Expecting valid SharedCacheMap $SharedCacheMap"
349                                 if !SharedCacheMap_valid $SharedCacheMap;
350                 }
351         return if !(my $FObject=FObject $FileObject);
352         return if !(my $SObject=SObject $FObject->{"SectionObjectPointer"});
353         return if !(my $CObject=CObject $SObject->{"SharedCacheMap"});
354         if (--$CObject->{"ref_count"}) {
355                 for my $SharedCacheMap ($Object->{"data"}[1]{"SharedCacheMap"}) {
356                         warn "Expecting still valid SharedCacheMap $SharedCacheMap after CcUninitializeCacheMap()"
357                                                         ." with ref_count=".$CObject->{"ref_count"}
358                                         if !SharedCacheMap_valid $SharedCacheMap;
359                         }
360                 return;
361                 }
362         if (!SharedCacheMap_valid $Object->{"data"}[1]{"SharedCacheMap"}) {
363                 delete_CObject $CObject;
364                 $SObject->{"SharedCacheMap"}=tohex(0);
365                 # FileObject is still valid!
366                 }
367         else {
368                 # FIXME: Do we SharedCacheMap->ref_count-- on in such case?
369                 }
370 }
371
372 sub CcSetFileSizes($$$$)
373 {
374 my($FileObject,$AllocationSize,$FileSize,$ValidDataLength)=@_;
375
376         return if !(my $CObject=CObject_from_FileObject $FileObject);
377         my $SharedCacheMap=$CObject->{"SharedCacheMap"};
378         if ($AllocationSize!=eval($CObject->{"AllocationSize"})) {
379                 do { warn "Existing map $_ of FileObject $FileObject SharedCacheMap $SharedCacheMap during CcSetAllocationSizes(),"
380                                                 ." AllocationSize=".$CObject->{"AllocationSize"} if $_; }
381                                 for ($CObject->{"map"});
382                 do { warn "Existing pin $_ of FileObject $FileObject SharedCacheMap $SharedCacheMap during CcSetAllocationSizes(),"
383                                                 ." AllocationSize=".$CObject->{"AllocationSize"} if $_; }
384                                 for (values(%{$CObject->{"pin"}}));
385                 # Do not: delete $CObject->{"in_memory"};
386                 # as its keep is required by W32. Squeeze it instead:
387                 $CObject->{"in_memory"}={ map({
388                                 (eval($_)<$AllocationSize ? ($_=>1) : ());
389                                 } keys(%{$CObject->{"in_memory"}})) };
390                 }
391         # $ValidDataLength can be > $CObject->{"FileSize"};
392         warn "ValidDataLength ".tohex($ValidDataLength)." > FileSize ".tohex($FileSize)
393                         if $ValidDataLength>$FileSize;
394         warn "0 != AllocationSize ".tohex($AllocationSize)." % ntfs_blocksize ".tohex($ntfs_blocksize)
395                         if 0!=($AllocationSize%$ntfs_blocksize);
396         # $AllocationSize can be higher
397         warn "FileSize ".tohex($FileSize)." > AllocationSize ".tohex($AllocationSize)
398                         if $FileSize>$AllocationSize;
399         $CObject->{"FileSize"}=tohex($FileSize);
400         $CObject->{"AllocationSize"}=tohex($AllocationSize);
401         delete $CObject->{"Buffer"} if !eval $AllocationSize;
402 }
403
404 sub IRP_MJ_CREATE_leave()
405 {
406         do { warn "Non-NULL SectionObjectPointer $_ not expected" if eval($_); } for ($Object->{"data"}[0]{"SectionObjectPointer"});
407         my $FileObject=$Object->{"data"}[0]{"FileObject"};
408         warn "Existing FileObject $FileObject not expected" if $FileObject{$FileObject};
409         my $SectionObjectPointer=$Object->{"data"}[1]{"SectionObjectPointer"};
410         # We want to track even FileObject without SectionObjectPointer yet.
411 #       if ($SectionObjectPointer && $SectionObjectPointer{$SectionObjectPointer})
412         {
413                 $FileObject{$FileObject}={
414                                 "FileObject"=>$FileObject,
415                                 "SectionObjectPointer"=>$SectionObjectPointer,
416                                 };
417                 }
418         if (eval $SectionObjectPointer) {
419                 my $SharedCacheMap=$Object->{"data"}[1]{"SharedCacheMap"};
420                 if (my $SObject=$SectionObjectPointer{$SectionObjectPointer}) {
421                         warn "Changed SharedCacheMap from stored ".$SObject->{"SharedCacheMap"}." to ".$SharedCacheMap
422                                         if $SObject->{"SharedCacheMap"} ne $SharedCacheMap && $Object->{"by"} ne "IRP_MJ_CREATE";
423                         }
424                 $SectionObjectPointer{$SectionObjectPointer}={
425                                 "SectionObjectPointer"=>$SectionObjectPointer,
426                                 "SharedCacheMap"=>$SharedCacheMap,
427                                 };
428                 }
429 }
430
431 sub BObject($)
432 {
433 my($Bcb)=@_;
434
435         cluck if !defined $Bcb;
436         my $BObject=$Bcb{$Bcb};
437         if (!$BObject) {
438                 my($package,$filename,$line,$subroutine)=caller 0;
439                 warn "Non-existent Bcb $Bcb by line $line"
440                 }
441         return $BObject;
442 }
443
444 sub delete_BObject($)
445 {
446 my($BObject)=@_;
447
448         my $Bcb=$BObject->{"Bcb"};
449 #       warn "XXX delete_BObject 0x811799B8 line $. BObject=".Dumper $BObject if $Bcb eq "0x811799B8";
450         warn "Deleting ref_count=".$BObject->{"ref_count"}." Bcb $Bcb" if $BObject->{"ref_count"};
451         # Do not: warn "Deleting dirty Bcb $Bcb" if $BObject->{"dirty"};
452         # as it is valid to allow sanity check below.
453         warn "Deleting dirty Bcb $Bcb" if $BObject->{"dirty"} && $BObject->{"ref_count"};
454         return if !(my $CObject=CObject $BObject->{"SharedCacheMap"});
455         if ($BObject->{"type"} eq "map") {
456                 for my $pin (values(%{$CObject->{"pin"}})) {
457                         next if !defined $pin;
458                         warn "unpin map but CcPinMappedData pin $pin still exists"
459                                         if $Bcb{$pin}->{"by"} eq "CcPinMappedData";
460                         }
461                 }
462         else {
463                 warn "unpin of pin Bcb $Bcb of SharedCacheMap ".$CObject->{"SharedCacheMap"}
464                                                 ." although FileOffset ".$BObject->{"FileOffset"}." not in_memory"
465                                 if !($CObject->{"in_memory"}{$BObject->{"FileOffset"}});
466                 # Do not: delete $CObject->{"in_memory"}{$BObject->{"FileOffset"}};
467                 # as Cache Manager is not forced to drop it.
468 #               warn "UNMARK: SharedCacheMap ".$CObject->{"SharedCacheMap"}." FileOffset ".$BObject->{"FileOffset"};
469                 }
470         for my $ref ($BObject->{"type"} eq "map" ? \$CObject->{"map"} : \$CObject->{"pin"}{$BObject->{"FileOffset"}}) {
471                 warn "Final unpin but ".$BObject->{"type"}." Bcb $Bcb not registered"
472                                                 ." in SharedCacheMap ".$CObject->{"SharedCacheMap"}." ref ".($$ref || "<undef>")
473                                 if !defined($BObject->{"OwnerPointer"}) && !($$ref && $$ref eq $Bcb)
474                                                 && !($BObject->{"ref_count"}==0 && $BObject->{"dirty"});
475                 if ($$ref && $$ref eq $Bcb) {
476                         $$ref=undef();
477                         # Do not: delete $CObject->{"pin"}{$BObject->{"FileOffset"}} if $BObject->{"type"} eq "pin";
478                         # as it would destroy $$ref slot in &Bcb_checkref '($$ref && $Bcb ne $$ref)' codepath.
479                         }
480                 }
481         delete $Bcb{$Bcb};
482 #       warn "XXX delete_BObject 0x811799B8 line $. CObject=".Dumper $CObject if $Bcb eq "0x811799B8";
483         CObject_Buffer_check($CObject);
484 }
485
486 sub MObject($)
487 {
488 my($MdlChain)=@_;
489
490         cluck if !defined $MdlChain;
491         my $MObject=$MdlChain{$MdlChain};
492         warn "Non-existent MdlChain $MdlChain" if !$MObject;
493         return $MObject;
494 }
495
496 sub CObject_Buffer_check($)
497 {
498 my($CObject)=@_;
499
500         my $any;
501         for my $BObject ($CObject->{"map"},values(%{$CObject->{"pin"}})) {
502                 # There may exist OwnerPointer-ed or dirty&unreffed standalone Bcbs bound to this SharedCacheMap
503                 # but these are not important for Buffer reset.
504                 next if !$BObject;
505                 $any=1;
506                 last;
507                 }
508         if (!$any) {
509                 delete $CObject->{"Buffer"};
510                 }
511 }
512
513 sub Bcb_conflict($;@)
514 {
515 my($CObject,@Bcb_list)=@_;
516
517         my $arg=0;
518         my %check=(
519                 "map"=>$CObject->{"map"},
520                 map(("arg".($arg++)=>$_),@Bcb_list),
521                 %{$CObject->{"pin"}},
522                 );
523         my %reversed;
524         my $BufferBase; # relativized to FileOffset 0
525         my $BufferBase_val;
526         if ($CObject->{"Buffer"}) {
527                 $BufferBase=eval $CObject->{"Buffer"};
528                 $BufferBase_val="SharedCacheMap Buffer";
529                 }
530         while (my($key,$val)=each(%check)) {
531                 next if !defined $val;
532                 warn "Conflicting Bcb $val of keys $key and ".$reversed{$val}." of SharedCacheMap ".$CObject->{"SharedCacheMap"}
533                                 if $reversed{$val};
534                 # Buffer base should match even between 'map's and 'pin's
535                 # as the data are always mapped only once.
536                 my $BObject=$Bcb{$val};
537                 warn "Non-existent key=$key Bcb $val"
538 #                                               ." XXX line $. CObject=".Dumper $CObject
539                                 if !$BObject;
540                 if ($BObject) {
541                         my $Buffer=eval $BObject->{"Buffer"};
542                         $Buffer-=eval($BObject->{"FileOffset"}) if exists $BObject->{"FileOffset"};
543                         warn "INTERNAL: Non page aligned Buffer ".tohex($Buffer)." of Bcb $val"
544                                         if $Buffer & 0xFFF;
545                         warn "Non-matching Bcb ".$BObject->{"type"}." $val Buffer base ".tohex($Buffer)
546                                                         ." with".($BufferBase_val=~/^SharedCacheMap / ? "" : " Bcb ".$Bcb{$BufferBase_val}->{"type"})
547                                                         ." $BufferBase_val BufferBase ".tohex($BufferBase)."; SharedCacheMap=".$CObject->{"SharedCacheMap"}
548 #                                                       ." XXX line $. ".Dumper($CObject,\%Bcb)
549                                         if defined($BufferBase) && $Buffer!=$BufferBase;
550                         $BufferBase=$Buffer;
551                         $BufferBase_val=$val;
552                         }
553                 $reversed{$val}=$key;
554                 }
555 }
556
557 # New $BObject will always be forced as the last stored reference.
558 sub Bcb_checkref($$)
559 {
560 my($BObject,$ref)=@_;
561
562         return if !(my $CObject=CObject $BObject->{"SharedCacheMap"});
563         my $type=$BObject->{"type"};
564         my $Bcb=$BObject->{"Bcb"};
565         if ($$ref && $Bcb ne $$ref) {
566                 my $BObject2=$Bcb{$$ref};
567                 warn "new $type Bcb $Bcb != old ".$BObject2->{"type"}." Bcb $$ref";
568                 delete_BObject $BObject2;
569                 }
570         if ($Bcb{$Bcb}) {
571                 my $BObject2=$Bcb{$Bcb};
572                 warn "new $type $Bcb type ".$BObject->{"type"}." != old type $type $Bcb type ".$BObject2->{"type"}
573                                 if $BObject->{"type"} ne $BObject2->{"type"};
574                 warn "new $type $Bcb Buffer ".($BObject->{"Buffer"} || "<undef>")
575                                                 ." != old $type $Bcb Buffer ".($BObject2->{"Buffer"} || "<undef>")
576 #                                               ." XXX line $. ".Dumper($BObject,$BObject2)
577                                 if $BObject->{"Buffer"} ne $BObject2->{"Buffer"};
578                 }
579         if ($Bcb{$Bcb}) {
580                 warn "Equal Bcb?" if $Bcb{$Bcb} eq $BObject;
581                 $Bcb{$Bcb}->{"ref_count"}+=$BObject->{"ref_count"};
582                 $BObject=$Bcb{$Bcb};
583                 }
584         $Bcb{$Bcb}=$BObject;    # &Bcb_conflict needs this reference
585         Bcb_conflict $CObject,($$ref && $$ref eq $Bcb ? () : ($Bcb));
586         $$ref=$Bcb;
587 }
588
589 sub map_new($;$$)
590 {
591 my($SharedCacheMap,$FileOffset,$Length)=@_;
592
593         return if !(my $CObject=CObject $SharedCacheMap);
594         if (defined($FileOffset) && defined($Length)) {
595                 warn "Mapping data (end ".tohex($FileOffset+$Length).") out of FileSize ".$CObject->{"FileSize"}
596                                 if $FileOffset+$Length>eval($CObject->{"FileSize"});
597                 }
598         $Object->{"SharedCacheMap"}=$CObject->{"SharedCacheMap"};
599         if (defined $FileOffset) {
600                 $Object->{"FileOffset"}=tohex($FileOffset);
601                 }
602         $Object->{"type"}="map";
603         $Object->{"ref_count"}=1;
604 }
605
606 sub map_new_from_FileObject($;$$)
607 {
608 my($FileObject,$FileOffset,$Length)=@_;
609
610         return if !(my $CObject=CObject_from_FileObject $FileObject);
611         map_new $CObject->{"SharedCacheMap"},$FileOffset,$Length;
612 }
613
614 sub map_new_leave($;$)
615 {
616 my($Bcb,$Buffer)=@_;
617
618         $Object->{"Bcb"}=$Bcb;
619         return if !(my $CObject=CObject $Object->{"SharedCacheMap"});
620
621         if (defined $Buffer) {
622                 $Object->{"Buffer"}=tohex(eval($Buffer)-(eval($Object->{"FileOffset"}) || 0));
623                 }
624         delete $Object->{"FileOffset"};
625         $CObject->{"Buffer"}=$Object->{"Buffer"} if !$CObject->{"Buffer"};
626         warn "Unknown Buffer during map_new_leave" if !$Object->{"Buffer"};
627
628         my $ref=\$CObject->{"map"};
629         # There may exist some pin bcbs even if we are creating the new map bcb.
630         Bcb_checkref $Object,$ref;
631 }
632
633 sub CcMapData($$$)
634 {
635 my($FileObject,$FileOffset,$Length)=@_;
636
637         map_new_from_FileObject $FileObject,$FileOffset,$Length;
638 }
639
640 sub CcMapData_leave($$)
641 {
642 my($Bcb,$Buffer)=@_;
643
644         map_new_leave $Bcb,$Buffer;
645 }
646
647 sub pin_new($$$)
648 {
649 my($FileObject,$FileOffset,$Length)=@_;
650
651         return if !(my $CObject=CObject_from_FileObject $FileObject);
652         warn "Pinning of non-PinAccess FileObject $FileObject" if !$CObject->{"PinAccess"};
653         warn "Mapping data (end ".tohex($FileOffset+$Length).") out of FileSize ".$CObject->{"FileSize"}
654                         if $FileOffset+$Length>eval($CObject->{"FileSize"});
655         warn "Pinning Length ".tohex($Length)." > 0x1000" if $Length>0x1000;
656         warn "Pinning across file page (start=".tohex($FileOffset).",end-1=".tohex($FileOffset+$Length-1).")"
657                         if ($FileOffset&~0xFFF)!=(($FileOffset+$Length-1)&~0xFFF);
658         $Object->{"SharedCacheMap"}=$CObject->{"SharedCacheMap"};
659         $Object->{"FileOffset"}=tohex($FileOffset);
660         $Object->{"type"}="pin";
661         $Object->{"ref_count"}=1;
662 }
663
664 sub pin_new_leave($$)
665 {
666 my($Bcb,$Buffer)=@_;
667
668         $Object->{"Bcb"}=$Bcb;
669         return if !(my $CObject=CObject $Object->{"SharedCacheMap"});
670         $Object->{"Buffer"}=tohex(eval($Buffer)-(eval($Object->{"FileOffset"})&0xFFF));
671         my $shift=eval($Object->{"FileOffset"})&0xFFF;
672         $Object->{"FileOffset"}=tohex(eval($Object->{"FileOffset"})-$shift);
673         $Object->{"Buffer"}=tohex(eval($Buffer)-$shift);
674
675         my $Buffer_base=tohex(eval($Object->{"Buffer"})-eval($Object->{"FileOffset"}));
676         $CObject->{"Buffer"}=$Buffer_base if !$CObject->{"Buffer"};
677
678         warn "pin_new_leave() while FileOffset ".$Object->{"FileOffset"}." not in_memory"
679                                         ." of SharedCacheMap ".$CObject->{"SharedCacheMap"}
680                         if !$CObject->{"in_memory"}{$Object->{"FileOffset"}};
681
682         my $ref=\$CObject->{"pin"}{$Object->{"FileOffset"}};
683         # There may not exist map bcb even if we are creating the new pin bcb.
684         Bcb_checkref $Object,$ref;
685 #       warn "XXX pin_new_leave line $. BObject=".Dumper $Object if $Bcb eq "0x811799B8";
686 }
687
688 sub CcPinRead($$$)
689 {
690 my($FileObject,$FileOffset,$Length)=@_;
691
692         pin_new $FileObject,$FileOffset,$Length;
693 }
694
695 sub CcPinRead_leave($$)
696 {
697 my($Bcb,$Buffer)=@_;
698
699         pin_new_leave $Bcb,$Buffer;
700 }
701
702 sub CcPreparePinWrite($$$)
703 {
704 my($FileObject,$FileOffset,$Length)=@_;
705
706         return if !(my $CObject=CObject_from_FileObject $FileObject);
707         # Full pages do not need to be read:
708         if (!($FileOffset&0xFFF)) {
709                 $CObject->{"in_memory"}{tohex $FileOffset}=1;
710                 }
711
712         pin_new $FileObject,$FileOffset,$Length;
713 }
714
715 sub CcPreparePinWrite_leave($$)
716 {
717 my($Bcb,$Buffer)=@_;
718
719         pin_new_leave $Bcb,$Buffer;
720         my $BObject=BObject $Bcb;
721         $BObject->{"dirty"}=1;
722 }
723
724 sub CcPinMappedData($$$)
725 {
726 my($FileObject,$FileOffset,$Length)=@_;
727
728         pin_new $FileObject,$FileOffset,$Length;
729 }
730
731 sub CcPinMappedData_leave($)
732 {
733 my($Bcb)=@_;
734
735         return if !(my $CObject=CObject $Object->{"SharedCacheMap"});
736         # Do not: do { warn "CcPinMappedData() with Bcb $Bcb on non-CcMapData()ed SharedCacheMap ".$CObject->{"SharedCacheMap"}; return; }
737         #             if !$CObject->{"map"};
738         # as the only requirement of CcPinMappedData() is to have all the pages already 'in_memory'.
739         my $Buffer=$CObject->{"Buffer"};
740         warn "SharedCacheMap ".$CObject->{"SharedCacheMap"}." Buffer not known during CcPinMappedData()"
741                         if !$Buffer;
742         $Buffer=tohex(eval($Buffer)+eval($Object->{"FileOffset"})) if $Buffer;
743
744 #       my $Bcb2=$CObject->{"pin"}{tohex(eval($Object->{"FileOffset"})&~0xFFF)};
745 #       my $BObject2=BObject $Bcb2 if $Bcb2;
746
747         pin_new_leave $Bcb,$Buffer;
748 }
749
750 sub CcSetDirtyPinnedData($$)
751 {
752 my($Bcb,$Lsn)=@_;
753
754         return if !(my $BObject=BObject $Bcb);
755         # Do not: warn "Lsn already set for Bcb $Bcb as ".$BObject->{"Lsn"}." while current Lsn=$Lsn" if $BObject->{"Lsn"};
756         # as it is permitted.
757         warn "Lsn goes backward for Bcb $Bcb old Lsn ".$BObject->{"Lsn"}." to a new Lsn=$Lsn"
758                         if $BObject->{"Lsn"} && eval($BObject->{"Lsn"})>eval($Lsn);
759         $BObject->{"Lsn"}=$Lsn if $Lsn ne "0x".("F"x8);
760         $BObject->{"dirty"}=1;
761         return if !(my $CObject=CObject $BObject->{"SharedCacheMap"});
762 }
763
764 sub FlushToLsnRoutine($$)
765 {
766 my($LogHandle,$Lsn)=@_;
767
768         $Object->{"LogHandle"}=$LogHandle;
769         $Object->{"Lsn"}=$Lsn;
770 }
771
772 my $LogHandle_static;
773 sub CcSetLogHandleForFile($$$)
774 {
775 my($FileObject,$LogHandle,$FlushToLsnRoutine)=@_;
776
777         return if !(my $CObject=CObject_from_FileObject $FileObject);
778         warn "LogHandle ".$CObject->{"LogHandle"}." already exists for SharedCacheMap ".$CObject->{"SharedCacheMap"}
779                         if $CObject->{"LogHandle"};
780         return if !eval $LogHandle;     # $LogHandle may be "0x0"
781         # ntfs.sys uses single LogHandle for its whole session:
782         warn "Non-unique LogHandle $LogHandle while last LogHandle was $LogHandle_static"
783                         if $LogHandle_static && $LogHandle ne $LogHandle_static;
784         $CObject->{"LogHandle"}=$LogHandle;
785         if (!$LogHandle{$LogHandle}) {
786                 $LogHandle{$LogHandle}={
787                                 "LogHandle"=>$LogHandle,
788                                 };
789                 }
790 }
791
792 sub IRP_MJ_WRITE_leave_page($$)
793 {
794 my($ByteOffset,$Lsn_check)=@_;
795
796         my $SharedCacheMap=$Object->{"data"}[0]{"SharedCacheMap"};
797         return if !(my $CObject=CObject $SharedCacheMap);
798         my $FlushToLsnRoutine=$LastLeave if $LastLeave->{"by"} eq "FlushToLsnRoutine";
799         # Do not: my $Bcb=$CObject->{"pin"}{$ByteOffset};
800         # as Bcbs with $BObject->{"OwnerPointer"} are no longer stored in $CObject->{"pin"}.
801         my @Bcbs;
802         for my $Bcb (keys(%Bcb)) {
803                 my $BObject=BObject $Bcb;
804                 if (1
805                                 && $BObject->{"type"} eq "pin"
806                                 && $BObject->{"SharedCacheMap"} eq $SharedCacheMap
807                                 && $BObject->{"FileOffset"} eq $ByteOffset) {
808                         push @Bcbs,$Bcb;
809                         }
810                 }
811         if (!@Bcbs) {
812                 do {
813                                 warn "Non-Bcb IRP_MJ_WRITE ByteOffset=$ByteOffset as non-toplevel function"
814                                                 ." (".join(",",map({ $_->{"line_enter"}.":".$_->{"by"}; } @$EnterLeave)).")";
815 #                               warn Dumper $CObject;
816                                 # Direct IRP_MJ_WRITE can be from callbacked 'FlushToLsnRoutine'.
817                                 # It can occur even from other callbacks ('DirtyPageRoutine' etc.)
818                                 # but it was not needed here yet.
819                                 } if @$EnterLeave && !(${$EnterLeave}[$#$EnterLeave]->{"by"}=~/^(?:FlushToLsnRoutine\b|IRP_MJ_)/);
820                 warn "Non-Bcb IRP_MJ_WRITE ByteOffset=$ByteOffset but FlushToLsnRoutine was preceding"
821                                 if $FlushToLsnRoutine;
822                 return;
823                 }
824         $CObject->{"in_memory"}{$ByteOffset}=1;
825         warn "Ambiguous matching Bcbs ".join(",",@Bcbs)
826                                         ." to SharedCacheMap $SharedCacheMap WRITE ByteOffset $ByteOffset"
827                         if @Bcbs>=2;
828         my $Bcb=$Bcbs[0];
829         return if !(my $BObject=BObject $Bcb);
830         warn "IRP_MJ_WRITE on non-dirty Bcb $Bcb" if !$BObject->{"dirty"};
831         if ($FlushToLsnRoutine) {
832                 push @$Lsn_check,{
833                                 "Bcb"=>$Bcb,
834                                 "Bcb_Lsn",$BObject->{"Lsn"},
835                                 } if $Lsn_check;
836                 }
837         else {
838                 warn "Missing preceding FlushToLsnRoutine during IRP_MJ_WRITE of Bcb $Bcb with Lsn ".$BObject->{"Lsn"}
839                                 if $BObject->{"Lsn"};
840                 }
841         warn "IRP_MJ_WRITE with FlushToLsnRoutine although not in AcquireForLazyWrite or CcFlushCache"
842                         if $FlushToLsnRoutine && !((1==@$EnterLeave && ${$EnterLeave}[0]->{"by"} eq "CcFlushCache")
843                                                 || (2==@$EnterLeave && ${$EnterLeave}[0]->{"by"}=~/^IRP_MJ_/
844                                                                     && ${$EnterLeave}[1]->{"by"} eq "CcFlushCache"))
845                                               && !($CObject->{"AcquireForLazyWrite"}>=1);
846         warn "IRP_MJ_WRITE not the toplevel function"
847                                                 ." (".join(",",map({ $_->{"line_enter"}.":".$_->{"by"}; } @$EnterLeave)).")"
848                         if !(0==@$EnterLeave
849                          || (1==@$EnterLeave && ${$EnterLeave}[0]->{"by"} eq "CcFlushCache")
850                          || (2==@$EnterLeave && ${$EnterLeave}[0]->{"by"}=~/^IRP_MJ_/
851                                              && ${$EnterLeave}[1]->{"by"} eq "CcFlushCache"));
852         my $CcFlushCache=${$EnterLeave}[$#$EnterLeave];
853         if ($CcFlushCache && $CcFlushCache->{"by"} eq "CcFlushCache") {
854                 $CcFlushCache->{"CcFlushCached"}++;
855                 if ($CcFlushCache->{"FileOffset"} ne "0x".("F"x8) || $CcFlushCache->{"Length"} ne "0x0") {
856                         warn "IRP_MJ_WRITE outside of range of active CcFlushCache()"
857                                         if eval($ByteOffset)< eval($CcFlushCache->{"FileOffset"})
858                                         || eval($ByteOffset)>=eval($CcFlushCache->{"FileOffset"})+eval($CcFlushCache->{"Length"});
859                         }
860                 }
861         # Keep $BObject->{"dirty"} there for &delete_BObject sanity checks.
862         delete_BObject $BObject if $BObject->{"dirty"} && !$BObject->{"ref_count"};
863 }
864
865 sub IRP_MJ_WRITE_leave()
866 {
867         return if !(my $CObject=CObject $Object->{"data"}[0]{"SharedCacheMap"});
868         # toplevel IRP_MJ_WRITE has no requirements
869         return if 0==@$EnterLeave
870                         # We do not need any outer function, just 'AcquireForLazyWrite' is enough
871                         # for flushing Cache Manager buffers by some its LazyWriter task.
872                         && !$CObject->{"AcquireForLazyWrite"};
873         do { warn "Length $_ not divisible by 0x1000" if eval($_)%0x1000; } for ($Object->{"WRITE"}{"Length"});
874         my @Lsn_check;
875         for my $reloffs (0..(eval($Object->{"WRITE"}{"Length"})/0x1000)-1) {
876                 IRP_MJ_WRITE_leave_page tohex(eval($Object->{"WRITE"}{"ByteOffset"})+0x1000*$reloffs),\@Lsn_check;
877                 }
878
879         if ($LastLeave->{"by"} eq "FlushToLsnRoutine" && (my $FlushToLsnRoutine=$LastLeave)) {
880                 my $Lsn_max;
881                 for (@Lsn_check) {
882                         my $Lsn=eval $_->{"Bcb_Lsn"};
883                         $Lsn_max=$Lsn if !defined($Lsn_max) || $Lsn_max<$Lsn;
884                         }
885                 warn "FlushToLsnRoutine of line_enter ".$FlushToLsnRoutine->{"line_enter"}
886                                                 ." got Lsn ".$FlushToLsnRoutine->{"Lsn"}." although Bcbs have "
887                                                 .join(",",map({ "(".$_->{"Bcb"}.":".$_->{"Bcb_Lsn"}.")"; } @Lsn_check))
888                                 if tohex($Lsn_max) ne $FlushToLsnRoutine->{"Lsn"};
889                 }
890 }
891
892 sub IRP_MJ_READ_leave()
893 {
894         # toplevel IRP_MJ_READ has no requirements
895         return if 0==@$EnterLeave;
896         my @stack=map({ $_->{"by"}=~/^IRP_MJ_/ ? () : $_ } @$EnterLeave);
897         my $opObject=$stack[0] if 1==@stack;
898         warn "IRP_MJ_READ not the expected function stack"
899                                                 ." (".join(",",map({ $_->{"line_enter"}.":".$_->{"by"}; } @$EnterLeave)).")"
900                         if !($opObject->{"by"} eq "CcMapData"
901                           || $opObject->{"by"} eq "CcCopyRead"
902                           || $opObject->{"by"} eq "CcMdlRead"
903                           || $opObject->{"by"} eq "CcPinRead");
904         if ($opObject->{"by"} eq "CcMdlRead") {
905                 do { warn "Length $_ not divisible by 0x1000" if eval($_)%0x1000; } for ($Object->{"READ"}{"Length"});
906                 }
907         else {
908                 do { warn "Length $_ not 0x1000" if eval($_)!=0x1000; } for ($Object->{"READ"}{"Length"});
909                 }
910         my $SharedCacheMap=$Object->{"data"}[0]{"SharedCacheMap"};
911         return if !(my $CObject=CObject $SharedCacheMap);
912         for my $reloffs (0..eval($Object->{"READ"}{"Length"})/0x1000-1) {
913                 my $ByteOffset=tohex(eval($Object->{"READ"}{"ByteOffset"})+$reloffs*0x1000);
914                 # Do not: warn "Reading ByteOffset $ByteOffset into SharedCacheMap $SharedCacheMap twice"
915                 #             if $CObject->{"in_memory"}{$ByteOffset};
916                 # as it may be still cached there as Cache Manager is not forced to drop it.
917                 $CObject->{"in_memory"}{$ByteOffset}=1;
918 #               warn "MARK: SharedCacheMap ".$CObject->{"SharedCacheMap"}." FileOffset $ByteOffset";
919                 }
920 }
921
922 sub CcPurgeCacheSection($$$$$)
923 {
924 my($SectionObjectPointer,$SharedCacheMap,$FileOffset,$Length,$UninitializeCacheMaps)=@_;
925
926         return if !(my $CObject=CObject $SharedCacheMap);
927         warn "Unexpected UninitializeCacheMaps $UninitializeCacheMaps" if $UninitializeCacheMaps ne "0";
928         my $all=($FileOffset eq "0x".("F"x8) && !eval $Length);
929         warn "Not yet implemented ranged CcPurgeCacheSection()" if !$all;
930         do { warn "Existing map Bcb $_ during CcPurgeCacheSection()" if $_; } for ($CObject->{"map"});
931         do { warn "Existing pin Bcb $_ during CcPurgeCacheSection()" if $_; } for (values(%{$CObject->{"pin"}}));
932         # Primary goal of this function:
933         delete $CObject->{"in_memory"};
934         # Really needed:
935         delete $CObject->{"Buffer"};
936 }
937
938 sub CcFlushCache($$$$)
939 {
940 my($SectionObjectPointer,$SharedCacheMap,$FileOffset,$Length)=@_;
941
942         $Object->{"CcFlushCached"}=0;
943         $Object->{"FileOffset"}=$FileOffset;
944         $Object->{"Length"}=$Length;
945 }
946
947 sub CcFlushCache_leave($$)
948 {
949 my($Status,$Information)=@_;
950
951         warn "CcFlushCache() not the toplevel function"
952                                                 ." (".join(",",map({ $_->{"line_enter"}.":".$_->{"by"}; } @$EnterLeave)).")"
953                         if !(0==@$EnterLeave
954                          || (1==@$EnterLeave && ${$EnterLeave}[0]->{"by"}=~/^IRP_MJ_/));
955         if ($Status ne "0x".("F"x8) || $Information ne "0x".("F"x8)) {
956                 warn "Unexpected Status $Status" if eval $Status;
957                 warn "Unexpected Information $Information while CcFlushCached=".$Object->{"CcFlushCached"}
958                                 if eval($Information)!=eval($Object->{"CcFlushCached"})*0x1000;
959                 }
960 }
961
962 sub CcPrepareMdlWrite($$$)
963 {
964 my($FileObject,$FileOffset,$Length)=@_;
965
966         $Object->{"FileObject"}=$FileObject;
967         warn "FileOffset $FileOffset not divisible by 0x1000" if eval($FileOffset)%0x1000;
968         $Object->{"FileOffset"}=$FileOffset;
969         warn "Length $Length not divisible by 0x1000" if eval($Length)%0x1000;
970         $Object->{"Length"}=$Length;
971 }
972
973 sub CcPrepareMdlWrite_leave($$$)
974 {
975 my($MdlChain,$Status,$Information)=@_;
976
977         do { warn "Unexpected Status $Status"; return; } if eval $Status;
978         warn "Unexpected Information $Information" if $Information ne $Object->{"Length"};
979         warn "MdlChain $MdlChain already exists" if $MdlChain{$MdlChain};
980         $MdlChain{$MdlChain}=$Object;
981 }
982
983 sub CcMdlWriteComplete($$$)
984 {
985 my($FileObject,$FileOffset,$MdlChain)=@_;
986
987         return if !(my $MObject=MObject $MdlChain);
988         warn "CcMdlWriteComplete() parameter FileObject $FileObject"
989                                         ." not matching MdlChain $MdlChain FileObject ".$MObject->{"FileObject"}
990                         if $FileObject ne $MObject->{"FileObject"};
991         warn "CcMdlWriteComplete() parameter FileOffset $FileOffset"
992                                         ." not matching MdlChain $MdlChain FileOffset ".$MObject->{"FileOffset"}
993                         if $FileOffset ne $MObject->{"FileOffset"};
994         # Propose MdlChain to a simulated Bcb.
995         # We must split it by pages as pin can be just 0x1000 sized.
996         return if !(my $CObject=CObject_from_FileObject $MObject->{"FileObject"});
997         for my $reloffs (0..eval($MObject->{"Length"})/0x1000-1) {
998                 my $BObject={ %$MObject };
999                 $BObject->{"Bcb"}="MdlChain $MdlChain reloffs $reloffs";
1000                 $BObject->{"FileOffset"}=tohex(eval($MObject->{"FileOffset"})+$reloffs*0x1000);
1001                 $BObject->{"SharedCacheMap"}=$CObject->{"SharedCacheMap"};
1002                 $BObject->{"type"}="pin";
1003                 $BObject->{"ref_count"}=0;
1004                 $BObject->{"dirty"}=1;
1005                 warn "Bcb ".$BObject->{"Bcb"}." already exists" if $Bcb{$BObject->{"Bcb"}};
1006                 $Bcb{$BObject->{"Bcb"}}=$BObject;
1007                 }
1008         delete $MdlChain{$MdlChain};
1009 }
1010
1011 sub CcMdlWriteAbort($$)
1012 {
1013 my($FileObject,$MdlChain)=@_;
1014
1015         warn "CcMdlWriteAbort() not handled";
1016 }
1017
1018 sub AcquireForLazyWrite_leave($)
1019 {
1020 my($r)=@_;
1021
1022         warn "Unexpected 'r' $r" if $r ne "1";
1023         warn "AcquireForLazyWrite() not the toplevel function" if @$EnterLeave;
1024         return if !(my $CObject=CObject $Object->{"data"}[0]{"SharedCacheMap"});
1025         $CObject->{"AcquireForLazyWrite"}++;
1026 }
1027
1028 sub ReleaseFromLazyWrite_leave()
1029 {
1030         warn "ReleaseFromLazyWrite() not the toplevel function" if @$EnterLeave;
1031         return if !(my $CObject=CObject $Object->{"data"}[0]{"SharedCacheMap"});
1032         warn "Invalid 'AcquireForLazyWrite' value ".$CObject->{"AcquireForLazyWrite"}
1033                         if !($CObject->{"AcquireForLazyWrite"}>=1);
1034         $CObject->{"AcquireForLazyWrite"}--;
1035 }
1036
1037 sub CcRemapBcb($)
1038 {
1039 my($Bcb)=@_;
1040
1041         return if !(my $BObject=BObject $Bcb);
1042         map_new $BObject->{"SharedCacheMap"};
1043         $Object->{"Buffer"}=tohex(eval($BObject->{"Buffer"})-eval($BObject->{"FileOffset"} || 0));
1044 }
1045
1046 sub CcRemapBcb_leave($)
1047 {
1048 my($r)=@_;
1049
1050         map_new_leave $r;
1051 }
1052
1053 sub unpin($)
1054 {
1055 my($Bcb)=@_;
1056
1057         return if !(my $BObject=BObject $Bcb);
1058         return if --$BObject->{"ref_count"};
1059         if ($BObject->{"dirty"}) {
1060                 # last unpin of unreferenced dirty Bcb will no longer allow reincarnation
1061                 # of the same Bcb to the pin map of its SharedCacheMap.
1062                 return if !(my $CObject=CObject $BObject->{"SharedCacheMap"});
1063                 warn "unpin() of pin Bcb $Bcb but it is already not registered in SharedCacheMap ".$BObject->{"SharedCacheMap"}." pin map"
1064                                 if (!$CObject->{"pin"}{$BObject->{"FileOffset"}} || $CObject->{"pin"}{$BObject->{"FileOffset"}} ne $Bcb)
1065                                                 && !$BObject->{"OwnerPointer"};
1066                 delete $CObject->{"pin"}{$BObject->{"FileOffset"}}
1067                                 if $CObject->{"pin"}{$BObject->{"FileOffset"}} && ($CObject->{"pin"}{$BObject->{"FileOffset"}} eq $Bcb);
1068                 CObject_Buffer_check $CObject;
1069                 return;
1070                 }
1071         delete_BObject $BObject;
1072 }
1073
1074 sub CcUnpinData($)
1075 {
1076 my($Bcb)=@_;
1077
1078         unpin $Bcb;
1079 }
1080
1081 sub CcUnpinDataForThread($)
1082 {
1083 my($Bcb)=@_;
1084
1085         unpin $Bcb;
1086 }
1087
1088 sub CcSetBcbOwnerPointer($$)
1089 {
1090 my($Bcb,$OwnerPointer)=@_;
1091
1092         return if !(my $BObject=BObject $Bcb);
1093         warn "CcSetBcbOwnerPointer() on map Bcb $Bcb" if $BObject->{"type"} ne "pin";
1094         return if !(my $CObject=CObject $BObject->{"SharedCacheMap"});
1095         warn "Double CcSetBcbOwnerPointer() on Bcb $Bcb" if defined $BObject->{"OwnerPointer"};
1096         my $val=$CObject->{"pin"}{$BObject->{"FileOffset"}};
1097         warn "CcSetBcbOwnerPointer() on unregistered pin Bcb $Bcb" if !$val || $val ne $Bcb;
1098         delete $CObject->{"pin"}{$BObject->{"FileOffset"}} if $val && $val eq $Bcb;
1099         $BObject->{"OwnerPointer"}=$OwnerPointer;
1100         CObject_Buffer_check $CObject;
1101 }
1102
1103 sub IRP_MJ_CLOSE_leave()
1104 {
1105         my $FileObject=$Object->{"data"}[0]{"FileObject"};
1106 #       # IRP_MJ_CLOSE of FileObject w/o CcInitializeCacheMap()?
1107 #       return if !$FileObject{$FileObject};
1108         return if !(my $FObject=FObject $FileObject);
1109         if (eval(my $SectionObjectPointer=$FObject->{"SectionObjectPointer"})) {
1110                 return if !(my $SObject=SObject $SectionObjectPointer);
1111                 my $SharedCacheMap=$SObject->{"SharedCacheMap"};
1112                 if (eval $SharedCacheMap) {
1113                         return if !(my $CObject=CObject $SObject->{"SharedCacheMap"});
1114                         # SharedCacheMap may still exist for FCB although this FileObject gets destroyed now.
1115 #                       warn "SectionObjectPointer $SectionObjectPointer still exists during IRP_MJ_CLOSE"
1116 #                                                       ." while SharedCacheMap ".$CObject->{"SharedCacheMap"}." ref_count ".$CObject->{"ref_count"}
1117 #                                       if $SectionObjectPointer && $CObject->{"ref_count"};
1118                         }
1119                 }
1120         delete_FObject $FObject;
1121 }
1122
1123
1124 local $_;
1125 my $hex='0x[\dA-F]+';
1126 my %last_irp_mj;
1127 while (<>) {
1128         chomp;
1129         s/\r$//;
1130         # We may get some foreign garbage without '\n' before our debug data line:
1131         # Do not use '\bTraceFS' as there really can be precediny _any_ data.
1132         s#^.*?TraceFS[(]($hex/$hex)[)]: ## or do { print "$_\n" if $filter; next; };
1133         $ProcessThread=$1;
1134
1135         $Object=undef();
1136         if (/^enter: (\w+)/) {
1137                 $Object={};
1138                 $Object->{"by"}=$1;
1139                 $Object->{"line_enter"}=$.;
1140                 $Object->{"ProcessThread"}=$ProcessThread;
1141                 push @{$EnterLeave{$ProcessThread}},$Object;
1142                 }
1143         elsif (/^leave: (\w+)/) {
1144                 warn "Empty pop stack during 'leave' of $1" if !($Object=pop @{$EnterLeave{$ProcessThread}});
1145                 warn "Non-matching popped 'by' ".$Object->{"by"}." ne current 'leave' $1"
1146                                 if $Object->{"by"} ne $1;
1147                 $Object->{"line_leave"}=$.;
1148                 push @{$LastLeave{$ProcessThread}},$Object;
1149                 }
1150         elsif (my($FileObject,$FileName,$Flags,$SectionObjectPointer,$SharedCacheMap)=
1151                         /^FileObject=($hex): FileName=(?:NULL|'(.*)'),Flags=($hex),SectionObjectPointer=($hex),->SharedCacheMap=($hex)/) {
1152                 my $aref=$EnterLeave{$ProcessThread};
1153                 warn "Empty stack during 'data' line" if !($Object=${$aref}[$#$aref]);
1154                 my $data={
1155                                 "FileObject"=>$FileObject,
1156                                 "FileName"=>$FileName,
1157                                 "Flags"=>$Flags,
1158                                 "SectionObjectPointer"=>$SectionObjectPointer,
1159                                 "SharedCacheMap"=>$SharedCacheMap,
1160                                 "line"=>$.,
1161                                 };
1162                 push @{$Object->{"data"}},$data;
1163                 my $isinit={ map(($_=>1),qw(
1164                                 CcInitializeCacheMap
1165                                 CcUninitializeCacheMap
1166                                 IRP_MJ_CREATE
1167                                 )) }->{$Object->{"by"}};
1168                 check_data $data
1169                                 if 1==@{$Object->{"data"}} || !$isinit;
1170                 if ($isinit) {
1171                         # Prevent 'SharedCacheMap' 0->N change by CcInitializeCacheMap() called inside.
1172                         for my $ref (@$aref[0..$#$aref-1]) {
1173                                 $ref->{"data"}[0]->{"SharedCacheMap"}=$SharedCacheMap;
1174                                 }
1175                         }
1176                 if (2<=@{$Object->{"data"}}) {
1177                         my $data_prev=$Object->{"data"}[$#{$Object->{"data"}}-1];
1178                         for my $field (qw(FileObject FileName Flags),($isinit ? () : qw(SharedCacheMap))) {
1179                                 next if !defined(my $prev=$data_prev->{$field});
1180                                 next if !defined(my $now=$data->{$field});
1181                                 my $by=$Object->{"by"};
1182                                 if ($field eq "Flags") {
1183                                         next if $by eq "IRP_MJ_CREATE" && $field eq "Flags";
1184                                         my $FO_CLEANUP_COMPLETE=0x4000;
1185                                         $now=tohex(eval($now)&~$FO_CLEANUP_COMPLETE) if $by eq "IRP_MJ_CLEANUP";
1186                                         my $FO_FILE_FAST_IO_READ=0x80000;
1187                                         $prev=tohex(eval($prev)&~$FO_FILE_FAST_IO_READ) if $by eq "IRP_MJ_CLEANUP";
1188                                         $now=tohex(eval($now)&~$FO_FILE_FAST_IO_READ) if $by eq "IRP_MJ_READ" && !(eval($prev)&$FO_FILE_FAST_IO_READ);
1189                                         my $FO_FILE_MODIFIED=0x1000;
1190                                         $now=tohex(eval($now)&~$FO_FILE_MODIFIED) if $by eq "IRP_MJ_WRITE" && !(eval($prev)&$FO_FILE_MODIFIED);
1191                                         my $FO_FILE_SIZE_CHANGED=0x2000;
1192                                         $prev=tohex(eval($prev)&~$FO_FILE_MODIFIED)
1193                                                         if $by eq "IRP_MJ_SET_INFORMATION" && !(eval($now)&$FO_FILE_MODIFIED);
1194                                         $prev=tohex(eval($prev)&~$FO_FILE_SIZE_CHANGED)
1195                                                         if $by eq "IRP_MJ_SET_INFORMATION" && !(eval($now)&$FO_FILE_SIZE_CHANGED);
1196                                         }
1197                                 next if $by eq "IRP_MJ_CLOSE" && $field eq "FileName";
1198                                 $prev=~s#\\$## if $by eq "IRP_MJ_CREATE";
1199                                 $prev="\\" if $by eq "IRP_MJ_CREATE" && $prev eq "";
1200                                 $prev=~s#:.*## if $by eq "IRP_MJ_CREATE" && $prev ne $now;
1201                                 next if $field eq "SharedCacheMap" && !SharedCacheMap_valid $prev && !SharedCacheMap_valid $now;
1202                                 do { warn "Changed data field $field, prev=".$data_prev->{$field}.", now=".$data->{$field}." by $by";
1203 #                                               print STDERR Dumper $data_prev,$data;
1204                                                 } if $prev ne $now;
1205                                 }
1206                         }
1207                 next;
1208                 }
1209         elsif (my($op,$ByteOffset,$Length)=
1210                         /^(READ|WRITE): ByteOffset=($hex),Length=($hex)/) {
1211                 my $aref=$EnterLeave{$ProcessThread};
1212                 warn "Empty stack during 'data' line" if !($Object=${$aref}[$#$aref]);
1213                 $Object->{$op}={
1214                         "ByteOffset"=>$ByteOffset,
1215                         "Length"=>$Length,
1216                         };
1217                 next;
1218                 }
1219
1220         $LastLeave=${$LastLeave{$ProcessThread}}[$#{$LastLeave{$ProcessThread}}-1];
1221         $EnterLeave=$EnterLeave{$ProcessThread};
1222
1223         if (my($r)=
1224                         /^leave: IRP_MJ_\w+: r=($hex)/) {
1225                 # Failed requests should make no consequences.
1226                 next if eval($r);
1227                 }
1228
1229         if (my($FileObject,$AllocationSize,$FileSize,$ValidDataLength,$PinAccess)=
1230                         /^enter: CcInitializeCacheMap: FileObject=($hex),FileSizes,->AllocationSize=($hex),->FileSize=($hex),->ValidDataLength=($hex),PinAccess=([01]),/) {
1231                 CcInitializeCacheMap $FileObject,eval($AllocationSize),eval($FileSize),eval($ValidDataLength),eval($PinAccess);
1232                 next;
1233                 }
1234         if (/^leave: CcInitializeCacheMap\b/) {
1235                 CcInitializeCacheMap_leave;
1236                 next;
1237                 }
1238
1239         if (my($FileObject,$TruncateSize)=
1240                         /^enter: CcUninitializeCacheMap: FileObject=($hex),TruncateSize=($hex),/) {
1241                 CcUninitializeCacheMap $FileObject,eval($TruncateSize);
1242                 next;
1243                 }
1244         if (my($r)=
1245                         /^leave: CcUninitializeCacheMap: r=([01])/) {
1246                 CcUninitializeCacheMap_leave $r;
1247                 next;
1248                 }
1249
1250         if (my($FileObject,$AllocationSize,$FileSize,$ValidDataLength)=
1251                         /^enter: CcSetFileSizes: FileObject=($hex),FileSizes,->AllocationSize=($hex),->FileSize=($hex),->ValidDataLength=($hex)/) {
1252                 CcSetFileSizes $FileObject,eval($AllocationSize),eval($FileSize),eval($ValidDataLength);
1253                 next;
1254                 }
1255
1256         if (/^leave: IRP_MJ_CREATE\b/) {
1257                 IRP_MJ_CREATE_leave;
1258                 next;
1259                 }
1260
1261         if (/^leave: IRP_MJ_CLOSE\b/) {
1262                 IRP_MJ_CLOSE_leave;
1263                 next;
1264                 }
1265
1266         if (my($FileObject,$FileOffset,$Length)=
1267                         /^enter: CcMapData: FileObject=($hex),FileOffset=($hex),Length=($hex),Flags=0x1/) {
1268                 CcMapData $FileObject,eval($FileOffset),eval($Length);
1269                 next;
1270                 }
1271         if (my($Bcb,$Buffer)=
1272                         /^leave: CcMapData: r=1,Bcb=($hex),Buffer=($hex)/) {
1273                 CcMapData_leave $Bcb,$Buffer;
1274                 next;
1275                 }
1276
1277         if (my($FileObject,$FileOffset,$Length)=
1278                         /^enter: CcPinRead: FileObject=($hex),FileOffset=($hex),Length=($hex),Flags=0x1/) {
1279                 CcPinRead $FileObject,eval($FileOffset),eval($Length);
1280                 next;
1281                 }
1282         if (my($Bcb,$Buffer)=
1283                         /^leave: CcPinRead: r=1,Bcb=($hex),Buffer=($hex)/) {
1284                 CcPinRead_leave $Bcb,$Buffer;
1285                 next;
1286                 }
1287
1288         if (my($FileObject,$FileOffset,$Length)=
1289                         /^enter: CcPreparePinWrite: FileObject=($hex),FileOffset=($hex),Length=($hex),Zero=([01]),Flags=0x1/) {
1290                 CcPreparePinWrite $FileObject,eval($FileOffset),eval($Length);
1291                 next;
1292                 }
1293         if (my($Bcb,$Buffer)=
1294                         /^leave: CcPreparePinWrite: r=1,Bcb=($hex),Buffer=($hex)/) {
1295                 CcPreparePinWrite_leave $Bcb,$Buffer;
1296                 next;
1297                 }
1298
1299         if (my($FileObject,$FileOffset,$Length)=
1300                         /^enter: CcPinMappedData: FileObject=($hex),FileOffset=($hex),Length=($hex),Flags=0x1/) {
1301                 CcPinMappedData $FileObject,eval($FileOffset),eval($Length);
1302                 next;
1303                 }
1304         if (my($Bcb)=
1305                         /^leave: CcPinMappedData: r=1,Bcb=($hex)/) {
1306                 CcPinMappedData_leave $Bcb;
1307                 next;
1308                 }
1309
1310         if (my($BcbVoid,$Lsn)=
1311                         /^enter: CcSetDirtyPinnedData: BcbVoid=($hex),Lsn=($hex)/) {
1312                 CcSetDirtyPinnedData $BcbVoid,$Lsn;
1313                 next;
1314                 }
1315
1316         if (my($LogHandle,$Lsn)=
1317                         /^enter: FlushToLsnRoutine: LogHandle=($hex),Lsn=($hex)/) {
1318                 FlushToLsnRoutine $LogHandle,$Lsn;
1319                 next;
1320                 }
1321
1322         if (/^leave: IRP_MJ_READ\b/) {
1323                 IRP_MJ_READ_leave;
1324                 next;
1325                 }
1326
1327         if (my($SectionObjectPointer,$SharedCacheMap,$FileOffset,$Length,$UninitializeCacheMaps)=
1328                 /^enter: CcPurgeCacheSection: SectionObjectPointer=($hex),->SharedCacheMap=($hex),FileOffset=($hex),Length=($hex),UninitializeCacheMaps=([01])/) {
1329                 CcPurgeCacheSection $SectionObjectPointer,$SharedCacheMap,$FileOffset,$Length,$UninitializeCacheMaps;
1330                 next;
1331                 }
1332
1333         if (/^leave: IRP_MJ_WRITE\b/) {
1334                 IRP_MJ_WRITE_leave;
1335                 next;
1336                 }
1337
1338         if (my($SectionObjectPointer,$SharedCacheMap,$FileOffset,$Length)=
1339                         /^enter: CcFlushCache: SectionObjectPointer=($hex),->SharedCacheMap=($hex),FileOffset=($hex),Length=($hex)/) {
1340                 CcFlushCache $SectionObjectPointer,$SharedCacheMap,$FileOffset,$Length;
1341                 next;
1342                 }
1343
1344         if (my($Status,$Information)=
1345                         /^leave: CcFlushCache: IoStatus->Status=($hex),IoStatus->Information=($hex)/) {
1346                 CcFlushCache_leave $Status,$Information;
1347                 next;
1348                 }
1349
1350         if (my($r)=
1351                         /^leave: AcquireForLazyWrite: r=([01])/) {
1352                 AcquireForLazyWrite_leave $r;
1353                 }
1354
1355         if (/^leave: ReleaseFromLazyWrite\b/) {
1356                 ReleaseFromLazyWrite_leave;
1357                 }
1358
1359         if (my($FileObject,$LogHandle,$FlushToLsnRoutine)=
1360                         /^enter: CcSetLogHandleForFile: FileObject=($hex),LogHandle=($hex),FlushToLsnRoutine=($hex)/) {
1361                 CcSetLogHandleForFile $FileObject,$LogHandle,$FlushToLsnRoutine;
1362                 next;
1363                 }
1364
1365         if (my($FileObject,$FileOffset,$Length)=
1366                         /^enter: CcPrepareMdlWrite: FileObject=($hex),FileOffset=($hex),Length=($hex)/) {
1367                 CcPrepareMdlWrite $FileObject,$FileOffset,$Length;
1368                 next;
1369                 }
1370         if (my($MdlChain,$Status,$Information)=
1371                         /^leave: CcPrepareMdlWrite: MdlChain=($hex),IoStatus->Status=($hex),IoStatus->Information=($hex)/) {
1372                 CcPrepareMdlWrite_leave $MdlChain,$Status,$Information;
1373                 next;
1374                 }
1375
1376         if (my($FileObject,$FileOffset,$MdlChain)=
1377                         /^enter: CcMdlWriteComplete: FileObject=($hex),FileOffset=($hex),MdlChain=($hex)/) {
1378                 CcMdlWriteComplete $FileObject,$FileOffset,$MdlChain;
1379                 next;
1380                 }
1381
1382         if (my($FileObject,$MdlChain)=
1383                         /^enter: CcMdlWriteAbort: FileObject=($hex),MdlChain=($hex)/) {
1384                 CcMdlWriteAbort $FileObject,$MdlChain;
1385                 next;
1386                 }
1387
1388         if (my($Bcb)=
1389                         /^enter: CcRemapBcb: Bcb=($hex)/) {
1390                 CcRemapBcb $Bcb;
1391                 next;
1392                 }
1393         if (my($r)=
1394                         /^leave: CcRemapBcb: r=($hex)/) {
1395                 CcRemapBcb_leave $r;
1396                 next;
1397                 }
1398
1399         if (my($Bcb)=
1400                         /^enter: CcUnpinData: Bcb=($hex)/) {
1401                 CcUnpinData $Bcb;
1402                 next;
1403                 }
1404         if (my($Bcb)=
1405                         /^enter: CcUnpinDataForThread: Bcb=($hex)/) {
1406                 CcUnpinDataForThread $Bcb;
1407                 next;
1408                 }
1409
1410         if (my($Bcb,$OwnerPointer)=
1411                         /^enter: CcSetBcbOwnerPointer: Bcb=($hex),OwnerPointer=($hex)/) {
1412                 CcSetBcbOwnerPointer $Bcb,$OwnerPointer;
1413                 next;
1414                 }
1415
1416         print "$_\n" if $filter;
1417         }
1418 for my $FileObject (keys(%FileObject)) {
1419         warn "EXIT: still CcInitializeCacheMap FileObject $FileObject";
1420         next if !(my $FObject=FObject $FileObject);
1421         }