Re: OPLOCK break notification/response...STATUS_SHARING_VIOLATION

[jr tipton \(MSFT\)]

Does the failure only occur when oplocks are enabled? It doesn't look like
it to me from what I see below. My guess about what is happening is that
the second open would fail even without oplocks because its open is
incompatible with the first open. That is, it might be asking for delete
access on the file while the previous open is not sharing it for delete.
This is perfectly reasonable and the right thing for the server to give
back.

Which redirector/server pair are you using? Are they both running Windows?

JR Tipton
--
This posting is provided "AS IS" with no warranties, and confers no rights.
Please do not respond to this mail alias as it is used for newsgroup
purposes only.

In the middle of this lonely thread I've just added in
microsoft.public.win2000.file_system. So far I've had one helpful
response, which has let us to learn more about OPLOCKs. It looks
like we may want to either tune the OPLOCKs or eliminate them.

Something wrong with the opportunistic locks on the server? What server

OS?

my response to Alexander:

Both our file server (has all our source code), and our
compile build engine PCs (these have the compilers on local drives)
are running Windows 2000 Server. The file server has 4 processors,
the build engines each have 2 CPUs. We have hyperthreading
turned on on the build engines (not sure aout server).

Please take a look at the packet capture test results from last Friday:

Network DOESITMATTER Telecommunications analyst Aabhas XXXXX
and I ran a test (~25 sec network packet capture) to examine a
particular repeatable file contention problem; we run into it during
our nightly software builds. The test ran well; the "makehm"
command failed twice as we had hoped.

background: w/r to our build processes \\c7mkes109\scm is a remote SMB
share. c7mkes109 and c7mkes123 are both multiprocessor compaq servers
running w2k server w/sp3. The file access problem is triggered by the
following Microsoft "makehm" commands from the following makefile -
\\c7mkes109\scm\prep\wscontrols_v5.3toss\wsc_mcommand_ctrl\commandctrl.mak:
<snip>
echo // Commands (ID_* and IDM_*) >>"hlp\$(TargetName).hm"
makehm ID_,HID_,0x10000 IDM_,HIDM_,0x10000 resource.h

"hlp\$(TargetName).hm"

echo // Prompts (IDP_*) >>"hlp\$(TargetName).hm"
makehm IDP_,HIDP_,0x30000 resource.h >>"hlp\$(TargetName).hm"
echo // Resources (IDR_*) >>"hlp\$(TargetName).hm"
makehm IDR_,HIDR_,0x20000 resource.h >>"hlp\$(TargetName).hm"
echo // Dialogs (IDD_*) >>"hlp\$(TargetName).hm"
makehm IDD_,HIDD_,0x20000 resource.h >>"hlp\$(TargetName).hm"
echo // Frame Controls (IDW_*) >>"hlp\$(TargetName).hm"
makehm IDW_,HIDW_,0x50000 resource.h >>"hlp\$(TargetName).hm"
<snip>

The first "makehm" always works. All makehm commands can be made
to work if we "sleep" 20 seconds between makehm invocations.
When makehm fails, it just echoes out it's "usage/help message".

# ====================================================================
# Analysis of 25 sec Packet Capture June 20 Test Data
# (used Ethereal to generate text data I've analyzed)
# ====================================================================

Per Ethereal packet capture report, notice 1196 OPLOCK requests during
the ~25 second capture:

bash-2.05b$ cmd /c cd
C:\TEMP
bash-2.05b$ date
Mon Jun 23 09:35:19 CDT 2003
bash-2.05b$ egrep 'Requesting OPLOCK' c7mke123_pc1.txt|wc -l
1196

Aabhas suggested I look at (among other frames) Frame 20967. I've
dumped out selected portions of the Ethereal packet capture report
for Frames 20908-20909, 20967-20973 - pls see these after my "sig".

Frame 20908:
our "build engine" c7mkes123 requests exclusive Batch Oplock for
file resource.h - the file makehm needs

Frame 20909 (Jun 20, 2003 12:59:19.153999000):
c7mkes109 Oplock level: Batch oplock granted (2); (FID: 0xc0dc)

Frame 20967 (Jun 20, 2003 12:59:19.180999000):
c7mkes123 requests
an exclusive Batch Oplock for file resource.h - the file makehm needs

Frame 20968 (Jun 20, 2003 12:59:19.181999000):
our file server c7mkes109 is apparently notifying our "build engine" c7mkes123
to break it's Oplock on "FID: 0xc0dc"

Frame 20969 (Jun 20, 2003 12:59:19.181999000)
c7mkes123 does a "Oplock Break: This is an oplock break notification/response"
for FID: 0xc0dc

Frame 20971 (Jun 20, 2003 12:59:20.182999000)
c7mkes109 responds:
"Response to: 20967
SMB Command: NT Create AndX (0xa2)
NT Status: STATUS_SHARING_VIOLATION (0xc0000043)"

Will someone please analyze Frames 20908-20909, 20967-20973 - perhaps
correcting misunderstandings I may have shown in this e-mail?

Most importantly - could we eliminate these STATUS_SHARING_VIOLATION (0xc0000043)
errors by tuning or eliminating OPLOCKS on our server or build engines?

If anyone wants the original paket capture data, pls e-mail me.

--
regards,
Tom Rodman
pls run for my address:
perl -e 'print unpack("u", "\.\=\$\!T\<F\]D\;6\%N\+F\-O\;0H\`");'

PS
I have several sections of interest below - please take a look.
The first section is the most crucial.
One supplemental section is an "overview of NT Status from SMB commands".

# ====================================================================
# selected frames w/more detail, showing BATCH OPLOCK request and
# sharing violation
# <ethereal used to generate packet report>:
# ====================================================================

Frame 20908
<snip>
Source: c7mkes123.mke.cg.jci.com (10.10.11.236)
Destination: c7mkes109.mke.cg.jci.com (10.10.11.221)
<snip>
Response in: 20909
SMB Command: NT Create AndX (0xa2)
NT Status: STATUS_SUCCESS (0x00000000)
<snip>
.... .... .... .... .... .... .... .1.. = Batch Oplock: Requesting BATCH OPLOCK
.... .... .... .... .... .... .... ..1. = Exclusive Oplock: Requesting OPLOCK
<snip>
File Name: \prep\wscontrols_v5.3toss\wsc_mcommand_ctrl\resource.h

Frame 20909
<snip>
Source: c7mkes109.mke.cg.jci.com (10.10.11.221)
Destination: c7mkes123.mke.cg.jci.com (10.10.11.236)
<snip>
Response to: 20908
SMB Command: NT Create AndX (0xa2)
NT Status: STATUS_SUCCESS (0x00000000)
<snip>
Oplock level: Batch oplock granted (2)
FID: 0xc0dc
Create action: Open (if file exists open it, else fail) (1)
Created: Jun 4, 2003 09:56:18.599958419
Last Access: Jun 20, 2003 13:07:48.633827209
Last Write: May 30, 2003 00:02:52.000000000
<snip>
.... .... .... .... .... .... .... ...1 = Read Only: This file is READ ONLY
<MANY FRAMES SNIPPED>

Frame 20966
<snip>
Source: c7mkes109.mke.cg.jci.com (10.10.11.221)
Destination: c7mkes123.mke.cg.jci.com (10.10.11.236)
<snip>
Source port: nbsession (139)
Destination port: 1107 (1107)
Sequence number: 2084973415
Next sequence number: 2084973495
Acknowledgement number: 437020072
<snip>
Response to: 20965
SMB Command: Transaction2 (0x32)
NT Status: STATUS_SUCCESS (0x00000000)
<snip>
1... .... = Request/Response: Message is a response to the client/redirector
<snip>
Subcommand: QUERY_FS_INFORMATION (0x0003)
<snip>
.... .... .... .... .... .... .... ...1 =
+ Case Sensitive Search: This FS supports CA SE SENSITIVE SEARCHes
.... .... .... .... .... .... .... ..1. =
+ Case Preserving: This FS supports CASE PRE SERVED NAMES
.... .... .... .... .... .... .... .1.. =
+ Persistent ACLs: This FS supports PERSISTE NT ACLs
.... .... .... .... .... .... .... 1... =
+ Compression: This FS supports COMPRESSED F ILES
.... .... .... .... .... .... ...1 .... =
+ Volume Quotas: This FS supports VOLUME QUO TAS
.... .... .... .... .... .... ..1. .... =
+ Mounted: This FS is on a MOUNTED DEVICE
.... .... .... .... 0... .... .... .... =
+ Compressed: This FS is NOT on a compressed volume
Max name length: 255
Label Length: 8
FS Name: NTFS

Frame 20967
<snip>
Source: c7mkes123.mke.cg.jci.com (10.10.11.236)
Destination: c7mkes109.mke.cg.jci.com (10.10.11.221)
<snip>
Source port: 1107 (1107)
Destination port: nbsession (139)
Sequence number: 437020072
Next sequence number: 437020270
Acknowledgement number: 2084973495
<snip>
Response in: 20971
SMB Command: NT Create AndX (0xa2)
NT Status: STATUS_SUCCESS (0x00000000)
<snip>
0... .... = Request/Response: Message is a request to the server
<snip>
.... .... .... .... .... .... .... .1.. = Batch Oplock: Requesting BATCH OPLOCK
.... .... .... .... .... .... .... ..1. = Exclusive Oplock: Requesting OPLOCK
<snip>
File Name: \prep\wscontrols_v5.3toss\wsc_mcommand_ctrl\resource.h

Frame 20968
<snip>
Source: c7mkes109.mke.cg.jci.com (10.10.11.221)
Destination: c7mkes123.mke.cg.jci.com (10.10.11.236)
<snip>
Source port: nbsession (139)
Destination port: 1107 (1107)
Sequence number: 2084973495
Next sequence number: 2084973550
Acknowledgement number: 437020270
<snip>
SMB Command: Locking AndX (0x24)
Error Class: Success (0x00)
Reserved: 00
Error Code: No Error
<snip>
0... .... = Request/Response: Message is a request to the server
<snip>
Locking AndX Request (0x24)
<snip>
.... ..1. = Oplock Break: This is an oplock break notification/response
<snip>
Oplock Level: Level 2 oplock currently held by client (1)
Timeout: Return immediately (0)
<snip>

Frame 20969
<snip>
Source: c7mkes123.mke.cg.jci.com (10.10.11.236)
Destination: c7mkes109.mke.cg.jci.com (10.10.11.221)
<snip>
Source port: 1107 (1107)
Destination port: nbsession (139)
Sequence number: 437020270
Next sequence number: 437020325
Acknowledgement number: 2084973550
<snip>
SMB Command: Locking AndX (0x24)
NT Status: STATUS_SUCCESS (0x00000000)
<snip>
0... .... = Request/Response: Message is a request to the server
<snip>
Locking AndX Request (0x24)
Word Count (WCT): 8
AndXCommand: No further commands (0xff)
Reserved: 00
AndXOffset: 57054
FID: 0xc0dc
Lock Type: 0x12
...1 .... = Large Files: Large file locking format requested
.... 0... = Cancel: Don't cancel outstanding lock request
.... .0.. = Change: Don't change lock type
.... ..1. = Oplock Break: This is an oplock break notification/response
.... ...0 = Shared: This is an exclusive lock
Oplock Level: Level 2 oplock currently held by client (1)
<note: "Wait indefinitely">
Timeout: Wait indefinitely (-1)
Number of Unlocks: 0
Number of Locks: 0
Byte Count (BCC): 0

Frame 20970
<snip>
Source: c7mkes109.mke.cg.jci.com (10.10.11.221)
Destination: c7mkes123.mke.cg.jci.com (10.10.11.236)
<snip>
Source port: nbsession (139)
Destination port: 1107 (1107)
Sequence number: 2084973550
Acknowledgement number: 437020325
Header length: 20 bytes
Flags: 0x0010 (ACK)
<just a TCP ACK, no NETBIOS or SMB stuff,snip>

<notice Frames 20970 and 20971 have same Sequence number and Acknowledgement number>
Frame 20971
<snip>
Source: c7mkes109.mke.cg.jci.com (10.10.11.221)
Destination: c7mkes123.mke.cg.jci.com (10.10.11.236)
<snip>
Source port: nbsession (139)
Destination port: 1107 (1107)
Sequence number: 2084973550
Next sequence number: 2084973589
Acknowledgement number: 437020325
<snip>
Response to: 20967
SMB Command: NT Create AndX (0xa2)
NT Status: STATUS_SHARING_VIOLATION (0xc0000043)
<snip>
1... .... = Request/Response: Message is a response to the client/redirector
<snip>

Frame 20972
<snip>
Source: c7mkes123.mke.cg.jci.com (10.10.11.236)
Destination: c7mkes109.mke.cg.jci.com (10.10.11.221)
<snip>
Source port: 1107 (1107)
Destination port: nbsession (139)
Sequence number: 437020325
Next sequence number: 437020447
Acknowledgement number: 2084973589
<snip>
Response in: 20973
SMB Command: Write AndX (0x2f)
NT Status: STATUS_SUCCESS (0x00000000)
<snip>
0... .... = Request/Response: Message is a request to the server
<snip>
AndXOffset: 57054
FID: 0x0131
Offset: 5410
Reserved: FFFFFFFF
Write Mode: 0x0000
<snip>
Data Length: 54
Data Offset: 64
High Offset: 0
Byte Count (BCC): 55
Padding: EE
File Data: 4D6963726F736F667420285229204865...

Frame 20973
<snip>
Source: c7mkes109.mke.cg.jci.com (10.10.11.221)
Destination: c7mkes123.mke.cg.jci.com (10.10.11.236)
<snip>
Response to: 20972
SMB Command: Write AndX (0x2f)
NT Status: STATUS_SUCCESS (0x00000000)
<snip>
Write AndX Response (0x2f)
Word Count (WCT): 6
AndXCommand: No further commands (0xff)
Reserved: 00
AndXOffset: 47
FID: 0x0131
Count: 54
Remaining: 65535
<snip>

# ====================================================================
# Overview of SMB commands that ran during entire capture:
# ====================================================================

11:23:53 Mon Jun 23 0j tty0 /drv/c/TEMP
ws011206 adm_tsr > egrep 'SMB Command:|Subcommand:' c7mke123_pc1.txt

|sort|uniq -c
346 SMB Command: Close (0x04)
94 SMB Command: Delete (0x06)
58 SMB Command: Locking AndX (0x24)
2476 SMB Command: NT Create AndX (0xa2)
58 SMB Command: NT Transact (0xa0)
416 SMB Command: Read AndX (0x2e)
2 SMB Command: Session Setup AndX (0x73)
15517 SMB Command: Transaction2 (0x32)
4 SMB Command: Tree Connect AndX (0x75)
1459 SMB Command: Write AndX (0x2f)
10 Subcommand: <UNKNOWN> since request packet wasn't seen
2159 Subcommand: FIND_FIRST2 (0x0001)
2 Subcommand: GET_DFS_REFERRAL (0x0010)
630 Subcommand: QUERY_FILE_INFORMATION (0x0007)
1088 Subcommand: QUERY_FS_INFORMATION (0x0003)
11562 Subcommand: QUERY_PATH_INFORMATION (0x0005)
66 Subcommand: SET_FILE_INFORMATION (0x0008)

# ====================================================================
# overview of NT Status from SMB commands
# ====================================================================

08:41:53 Mon Jun 23 1j tty0 /drv/c/TEMP
ws011206 adm_tsr > egrep 'NT Status: ' c7mke123_pc1.txt |sort |uniq -c

1 NT Status: STATUS_ACCESS_DENIED (0xc0000022)
1 NT Status: STATUS_DFS_UNAVAILABLE (0xc000026d)
142 NT Status: STATUS_NO_SUCH_FILE (0xc000000f)
2129 NT Status: STATUS_OBJECT_NAME_NOT_FOUND (0xc0000034)
700 NT Status: STATUS_OBJECT_PATH_NOT_FOUND (0xc000003a)
2 NT Status: STATUS_SHARING_VIOLATION (0xc0000043)
17421 NT Status: STATUS_SUCCESS (0x00000000)

# ====================================================================
# misc
# ====================================================================

Notice there are two STATUS_SHARING_VIOLATION (0xc0000043)
errors:

bash-2.05b$ date
Mon Jun 23 10:10:08 CDT 2003
bash-2.05b$ egrep -i -2 violation c7mke123_pc1.txt
Response to: 20967
SMB Command: NT Create AndX (0xa2)
NT Status: STATUS_SHARING_VIOLATION (0xc0000043)
Flags: 0x98
1... .... = Request/Response: Message is a response to the client/redirector
--
Response to: 21093
SMB Command: NT Create AndX (0xa2)
NT Status: STATUS_SHARING_VIOLATION (0xc0000043)
Flags: 0x98
1... .... = Request/Response: Message is a response to the client/redirector

FYI: the following frames contain the string "resource.h":

15528 (Subcommand: QUERY_PATH_INFORMATION)
15530 (Subcommand: QUERY_PATH_INFORMATION)
15552 (Subcommand: QUERY_PATH_INFORMATION)
15554 (Subcommand: QUERY_PATH_INFORMATION)
20908 (SMB Command: NT Create AndX )
20967 (SMB Command: NT Create AndX)
21034 (SMB Command: NT Create AndX)
21093 (SMB Command: NT Create AndX)
21164 (SMB Command: NT Create AndX)
22092 (SMB Command: NT Create AndX)
23922 (SMB Command: NT Create AndX)

# ====================================================================
# proof that makehm error *did* occur during test
# ====================================================================

13:30:34 Mon Jun 23 0j tty0 //c7mkes109/scm/prep/wscontrols_v5.3toss/wsc_mcommand_ctrl
ws011206 adm_tsr > egrep -2 'makehm.*:' pcr_make.out

Microsoft (R) Help Maintainence Utility Version 6.00
Copyright (c) Microsoft Corp. 1992-1998. All rights reserved.
makehm: error: unable to open file "resource.h".
makehm usage:
makehm <from>,<to>,<add>... <resource.h> [output.hm]
<from>,<to>,<add> fields must appear as one argument and
--
Microsoft (R) Help Maintainence Utility Version 6.00
Copyright (c) Microsoft Corp. 1992-1998. All rights reserved.
makehm: error: unable to open file "resource.h".
makehm usage:

13:30:47 Mon Jun 23 0j tty0 //c7mkes109/scm/prep/wscontrols_v5.3toss/wsc_mcommand_ctrl
ws011206 adm_tsr > ls -l pcr_make.out

-r-xr-xr-x+ 1 Administ SCM_ES_S 8786 Jun 20 13:08 pcr_make.out*