Types of Resource Entries in the Log File
The MNS resource uses 2 types of entries in the Cluster.log file:
| � | Entries that are related to the actual MNS resource use the
�Majority Node Set Resource Name� string. Note that
the format is not consistent, and because the resource name is typically
Majority Node Set, the entries are long. |
| � | Entries that are related to the pseudo file system use the
[Qfs] identifier. For example:
Note Time stamps have been removed to shorten entries.INFO [Qfs] SharedMem_Create: Created
E:\WINDOWS\Cluster\MajorityNodeSet_SharedMemTransport_ver_1.0 INFO Majority Node SetMajority Node Set: PipeOnline. Path
"\\1b97ebae-f5ac-4\1b97ebae-f5ac-4139-bf2c-b0bda607b814$" Share
"1b97ebae-f5ac-4139-bf2c-b0bda607b814$" |
ForceQuorum
When you are using ForceQuorum, the cluster logs an entry in the
cluster log that indicates what was selected:
INFO Local
Time is 2002/06/08-15:49:47.375
INFO [CS]
Service Starting...
INFO [CS] forcequorum
option chosen: force majority node set for nodes mns1,mns2
Example of Error and Warning entries
The following is an example of an error that was recorded in the
log file. In this case the error was a failure to create a resource. The
resource failed because its name exceeded the MAX_PATH requirement.
INFO [FM] Resmon LRPC EP name is LRPC
INFO Majority Node Set <MNS Quorum 2>: Open share setup
status 234 .
INFO Majority Node Set <MNS
Quorum 2>: Open MNS Quorum 2 status 234.
INFO Majority Node Set <MNS Quorum 2>: Close request.
WARN [RM] RmpInsertResourceList failed,
returned 234
ERR [RM] Failed creating
resource d98b79b2-70e8-4762-a836-215b13ef2965, error 234.
INFO [FM] FmpRmCreateResource: unable to create resource
d98b79b2-70e8-4762-a836-215b13ef2965
Additional Information About MNS Cluster.log Entries
Additional information that you can use to help you decipher MNS
log listings during arbitration.
Normal MNS arbitration in a 3 node
cluster, networks(10.*, 172.*), (10.*) higher priority:
(Clussvc telling RGP that it is trying to arbitrate for the quorum resource, in this case MNS.)
INFO [MM] MmSetQuorumOwner(1,1), old owner 0.
(Resmon thread calling into MNS to start arbitration, the following logs occur because of some pre-MNS arbitration init work.)
INFO Majority Node Set <QON>: Arbitrate request.
INFO
Majority Node Set <QON>: Maximum arbitration time 120000 msec
(2 minutes timeout on arbitration.)
INFO Majority Node Set <QON>: Guid
3a9743cd-7055-450e-8d70-1249c2bfe727
INFO Majority Node Set <QON>:
Local path D:\WINDOWS\cluster\MNS.3a9743cd-7055-450e-8d70-1249c2bfe727$
INFO Majority Node Set <QON>: Netshare
'3a9743cd-7055-450e-8d70-1249c2bfe727$' already exists
INFO Majority Node
Set <QON>: Local node id 1
INFO Majority Node Set <QON>:
FsRegister Tid 1 Share '3a9743cd-7055-450e-8d70-1249c2bfe727$' 3 disks
INFO Majority Node Set <QON>: FsArb: Creating arbitration thread
(Main MNS arbitration thread spawned by the thread earlier, and the thread earlier would wait until arbitration succeeds or fails.)
INFO Majority Node Set <QON>: ArbitrateThread begin
INFO Majority Node Set <QON>: ArbitrateThread current AliveSet=0
(0 is the current bitmask
of shares that are owned by the node. The bitmask is node-ID-based. For example, if it owns shares of nodes 1, 2, and 5, the bitmask is 0x26.
)
(Threads below are spawned to take shares on all the nodes in parallel over all the networks.
In an N node cluster with K networks, N*K number of threads would be spawned. The thread blow is trying to grab Node 3's share over 10.* network)
INFO Majority Node Set <QON>: Probe thread for Replica 3
Addr 10.21.1.161
(The thread below is trying to grab node 1's share over 10.* network)
INFO Majority Node Set <QON>: Probe thread for Replica 1
Addr 10.21.1.179
(CreateTreeConnection is the method to force all SMB traffic for this thread to flow
over 10.* network.)
INFO Majority Node Set <QON>:
CreateTreeConnection(10.21.1.161\3a9743cd-7055-450e-8d70-1249c2bfe727$)
returned 0x0 hdl 0x2f0
INFO Majority Node Set <QON>:
CreateTreeConnection(10.21.1.179\3a9743cd-7055-450e-8d70-1249c2bfe727$)
returned 0x0 hdl 0x10c
(The thread below is trying to take Node 3's share over 172.* network.)
INFO Majority Node Set <QON>: Probe thread for Replica 3
Addr 172.24.21.186
INFO Majority Node Set <QON>:
CreateTreeConnection(172.24.21.186\3a9743cd-7055-450e-8d70-1249c2bfe727$)
returned 0x0 hdl 0x308
(The thread managed to take node 3's share, and the thread is opening and reading the MNS log file.)
INFO Majority Node Set <QON>: Crs3: (Open) Filesz 8192
max_sec 16
INFO Majority Node Set <QON>: Probe thread for Replica 1
Addr 172.24.21.191
INFO Majority Node Set <QON>: Crs3: loaded 8192
bytes, 128 records
INFO Majority Node Set <QON>:
CreateTreeConnection(172.24.21.191\3a9743cd-7055-450e-8d70-1249c2bfe727$)
returned 0x0 hdl 0x2f8
INFO Majority Node Set <QON>: Crs3: 304 Last
record 42 max 128 epoch 376 seq 1
(The thread below is trying to take node 2's share over 10.* network.)
INFO Majority Node Set <QON>: Probe thread for Replica 2
Addr 10.21.1.173
INFO Majority Node Set <QON>:
CreateTreeConnection(10.21.1.173\3a9743cd-7055-450e-8d70-1249c2bfe727$)
returned 0x0 hdl 0x340
INFO Majority Node Set <QON>: Probe thread
for Replica 2 Addr 172.24.21.174
(The thread managed to take node 1's share.)
INFO Majority Node Set
<QON>: Crs1: (Open) Filesz 8192 max_sec 16
INFO Majority Node Set <QON>:
CreateTreeConnection(172.24.21.174\3a9743cd-7055-450e-8d70-1249c2bfe727$)
returned 0x0 hdl 0x30c
(After reading the MNS log file, the thread mounts
(opens) the root share folder.)
INFO Majority Node Set <QON>: Mounted
\Device\LanmanRedirector\10.21.1.161\3a9743cd-7055-450e-8d70-1249c2bfe727$\3a9743cd-7055-450e-8d70-1249c2bfe727$\
INFO Majority Node Set <QON>:
Crs1: loaded 8192 bytes, 128 records
INFO Majority Node Set <QON>: Crs1: 34c Last record 42 max 128 epoch 376
seq 1
(The thread managed to take node 2's share.)
INFO Majority Node Set <QON>:
Crs2: (Open) Filesz 8192 max_sec 16
INFO Majority Node Set <QON>: Mounted
\Device\LanmanRedirector\10.21.1.179\3a9743cd-7055-450e-8d70-1249c2bfe727$\3a9743cd-7055-450e-8d70-1249c2bfe727$\
INFO Majority Node Set <QON>:
Crs2: loaded 8192 bytes, 128 records
INFO Majority Node Set <QON>: Crs2: 300 Last record 42 max 128 epoch 376
seq 1
INFO Majority Node Set
<QON>: Mounted
\Device\LanmanRedirector\10.21.1.173\3a9743cd-7055-450e-8d70-1249c2bfe727$\3a9743cd-7055-450e-8d70-1249c2bfe727$\
INFO Majority Node Set <QON>:
NtNotifyChangeDirectoryFile(\Device\LanmanRedirector\10.21.1.179\3a9743cd-7055-450e-8d70-1249c2bfe727$\)
returns 0x103 FD: 00000370
(Mounting successful, mark the share to be owned,
this is share for node ID 1.)
INFO
Majority Node Set <QON>: Probe Thread probe replica 1 succeeded, ShareSet
2
(Replica 1, Shareset 2 is the bit for node ID 1.)
INFO
Majority Node Set <QON>: FsNotifyCallback: Enqueing Change notification
for Fd:0x370
INFO Majority Node Set
<QON>:
NtNotifyChangeDirectoryFile(\Device\LanmanRedirector\10.21.1.173\3a9743cd-7055-450e-8d70-1249c2bfe727$\)
returns 0x103 FD:
INFO
Majority Node Set <QON>:
NtNotifyChangeDirectoryFile(\Device\LanmanRedirector\10.21.1.161\3a9743cd-7055-450e-8d70-1249c2bfe727$\)
returns 0x103 FD: 000002E8
(Mounting successful, mark the share to be owned,
this is the share for node ID 2.)
INFO
Majority Node Set <QON>: Probe Thread probe replica 2 succeeded, ShareSet
6
(In this example, it took share 1 and 2. Because 2 of the 3 shares (Majority) have been
taken, the resmon arbitration thread returns success. However, the MNS arbitration
thread would wait for all threads to exit, and then synchronize the shares.)
INFO Majority Node Set <QON>:
Arb: status 0.
INFO Majority Node
Set <QON>: Arbitrate request status 0.
(This is the MNS health-monitoring
thread that is started by the resmon arbitration thread after successful
arbitration.)
INFO Majority Node Set
<QON>: MNS FsReserve thread start.
INFO Majority Node Set <QON>:
FsNotifyCallback: Enqueing Change notification for Fd:0x310
(Finally, the share of
node 3 is also mounted.)
INFO
Majority Node Set <QON>: Probe Thread probe replica 3 succeeded, ShareSet
e
(This occurs because of the threads that are spawned to grab shares over 172.* network. Because the threads that are spawned to take shares over 10.* network have already
succeeded, this is getting ERROR_LOCK_VIOLATION. These threads would exit
shortly, notice the 2 second delay in this thread's log.)
INFO Majority Node Set <QON>:
Crs3 Setting EA err=0x0 status=0x21
INFO Majority Node Set <QON>: Replica
'\Device\LanmanRedirector\172.24.21.186\3a9743cd-7055-450e-8d70-1249c2bfe727$\crs.log'
already locked
INFO Majority Node
Set <QON>: FsNotifyCallback: Enqueing Change notification for Fd:0x2e8
INFO Majority Node Set <QON>:
FsNotifyCallback: Enqueing Change notification for Fd:0x2e8
INFO Majority Node Set <QON>:
Crs1 Setting EA err=0x0 status=0x21
INFO Majority Node Set <QON>: Crs2 Setting EA err=0x0 status=0x21
INFO Majority Node Set <QON>:
Replica
'\Device\LanmanRedirector\172.24.21.174\3a9743cd-7055-450e-8d70-1249c2bfe727$\crs.log'
already locked
INFO Majority Node
Set <QON>: Replica
'\Device\LanmanRedirector\172.24.21.191\3a9743cd-7055-450e-8d70-1249c2bfe727$\crs.log'
already locked (FspEvict():
(This evicts failed shares from the alive share set. The meaning of the log below:
Wset - Bitmask of shares that are writable.
Rset
- Bitmask of shares that are readable.
Aset - Bitmask of alive share
set.
EvictMask - Shares in the Aset that have failed.
Because this is a
fresh arbitration, all the bitmasks are 0, and because MNS managed to grab all the
shares, the evictset is also 0.)
INFO Majority Node Set <QON>: FspEvict Entry: WSet 0 Rset 0 ASet 0
EvictMask 0
INFO Majority Node Set
<QON>: FspEvict Exit: vol 3a9743cd-7055-450e-8d70-1249c2bfe727$ WSet 0
RSet 0 ASet 0 (FspJoin():
(This synchronizes and joins the new shares:
JoinMask -Bitmask for newly available shares)
INFO Majority Node Set <QON>: FspJoin Entry: WSet 0 Rset 0 ASet 0
JoinMask e
INFO Majority Node Set
<QON>: Crs1 last record 42 epoch 376 seq 1 state 5
INFO Majority Node Set <QON>:
Crs2 last record 42 epoch 376 seq 1 state 5
INFO Majority Node Set <QON>:
Crs3 last record 42 epoch 376 seq 1 state 5
INFO Majority Node Set <QON>:
Vol 3a9743cd-7055-450e-8d70-1249c2bfe727$ done recovery nid 1 mid 1
INFO Majority Node Set <QON>:
Vol 3a9743cd-7055-450e-8d70-1249c2bfe727$ done recovery nid 2 mid 1
INFO Majority Node Set <QON>:
Vol 3a9743cd-7055-450e-8d70-1249c2bfe727$ done recovery nid 3 mid 1
INFO Majority Node Set <QON>:
Crs1: append record 43 epoch 377 seq 0 state b
INFO Majority Node Set <QON>:
Crs1: flush 512 bytes record 43 -> 5,2560
INFO Majority Node Set <QON>:
Crs2: append record 43 epoch 377 seq 0 state b
INFO Majority Node Set <QON>:
Crs2: flush 512 bytes record 43 -> 5,2560
INFO Majority Node Set <QON>:
Crs3: append record 43 epoch 377 seq 0 state b
INFO Majority Node Set <QON>:
Crs3: flush 512 bytes record 43 -> 5,2560
INFO Majority Node Set <QON>:
FsNotifyCallback: Enqueing Change notification for Fd:0x370
INFO Majority Node Set <QON>:
FsNotifyCallback: Enqueing Change notification for Fd:0x310
INFO Majority Node Set <QON>:
FspJoin Exit: vol 3a9743cd-7055-450e-8d70-1249c2bfe727$ WSet e Rset e ASet e
(Exit of FspJoin():
(Note The new Wset, Rset, and Aset are same as the joinmask, and MNS
was able to synchronize all the shares it took during arbitration. The Main
arbitration thread exits.)
INFO Majority Node Set <QON>: Arbitrate request status 0.