none
Cluster service is requesting a bus reset for device \Device\ClusDisk0.

    Question

  • Hello,

    I get quite the same errors and I need your advice on that. 

    It's a 2 node cluster connected to a 3 scsi disk chassis : Quorum, MSDTC and a database.
    It works very well exept that when doing a soft-shutdown it might happen that the failover fails (~1/4 times) : The disk where the database is store is not found. Tipically, we simply need to manually select and "bring on-line" the ressource to finish the fail-over.
    I've tested different ways to trigger a failover : this behaviour is only experienced on soft shutdown.

    evt:1209 src:ClusDisk
    Cluster service is requesting a bus reset for device \Device\ClusDisk0.

    evt:1034 src:ClusSvc
    The disk associated with cluster disk resource 'Disk I:' could not be found. The expected signature of the disk was xxxx If the disk was removed from the server cluster, the resource should be deleted. If the disk was replaced, the resource must be deleted and created again in order to bring the disk online. If the disk has not been removed or replaced, it may be inaccessible at this time because it is reserved by another server cluster node.

    Due to the fact that the cluster is working quite well most of the time, I don't think it is a signature problem. BUT.
    In the cluster.log I found several hints which can let me suspect a problem in that area anyway :

    ERR  Physical Disk <Avid Workgroup Disk>: [DiskArb] Signature of disk has changed or failed to find disk with id, old signature 0x5b3f792 new signature 0x5b3f797, status 0

    ERR  Physical Disk <MSDTC DISK R>: [DiskArb] Signature of disk has changed or failed to find disk with id, old signature 0x5b3f790 new signature 0x5b3f797, status 0

    ERR  Physical Disk <MSDTC DISK R>: [DiskArb] Signature of disk has changed or failed to find disk with id, old signature 0x5b3f790 new signature 0x5b3f790, status 170

     

    Do you know what a "status 0" and a "status 127" means?

     

    I tried several things to make it work correctly, but without any success :

    -Evict each node, one after the other, clean up the config (cluster <nodename> /forcecleanup) and finally ADD the node back to the cluster.

    -Force the disk ressource to match with the correct signature (=> cluster . res "MSDTC DISK R" /priv signature=0x5b3f790)

    But I still experienced that behaviour.

    Do you have any clue on that issue? I don't want to reinstall from scratch; I'm not sure it will solve that problem.

    Friday, September 17, 2010 8:43 AM

All replies

  • I split off your questions to their own topic as "answered" threads tend to get overlooked.

    Event 1209 is expected when your cluster node is forced to take over ownership of the cluster resources. This is not an indication of a problem.

    The 1034 event certainly can be a problem and in your case, it seems that the disk signature might be changing, or the cluster disk driver has the wrong physical disk value for the signature.

    Status 0 means no errors. The status 170 means the device is busy, which means a reservation is seen on the disk. This would be expected during a normal "forced" takeover event and cluster combats this by sending out the bus reset (1209 event).

    We'd need more info to help with this. Post the relevant sections of the cluster.log and we'll take a look.

    FYI, if you want to know what the error codes mean, in most cases, you can find these by doing a 'net helpmsg ###' from a command prompt.


    Visit my blog about multi-site clustering - http://msmvps.com/blogs/jtoner
    Friday, September 17, 2010 4:09 PM
  • Hi John,

    Many thanks for your help so far.

    Here is a copy of part of the cluster.log where those errors can be seen.
    Best regards

    000009d0.00000cd8::2010/09/17-12:01:32.563 ERR  Physical Disk <Avid Workgroup Disk>: [DiskArb] Signature of disk has changed or failed to find disk with id, old signature 0x5b3f792 new signature 0x5b3f797, status 0
    000009d0.00000cd0::2010/09/17-12:01:32.626 WARN [ClNet] Tcpip is not bound to adapter 8133225A-5034-4796-B822-4D63C58F6E39.
    000009d0.00000738::2010/09/17-12:01:32.626 WARN [ClNet] Tcpip is not bound to adapter 8133225A-5034-4796-B822-4D63C58F6E39.
    000009d0.00000cd0::2010/09/17-12:01:32.626 WARN [ClNet] Tcpip is not bound to adapter 66BB9773-7287-4F9E-85D9-D677D716ACD3.
    000009d0.00000738::2010/09/17-12:01:32.626 WARN [ClNet] Tcpip is not bound to adapter 66BB9773-7287-4F9E-85D9-D677D716ACD3.
    0000089c.000006c0::2010/09/17-12:01:32.626 INFO [GUM] GumSendUpdate:  Locker waiting  type 1 context 4098
    0000089c.000006c0::2010/09/17-12:01:32.626 INFO [GUM] Thread 0x6c0 UpdateLock wait on Type 1
    0000089c.000006c0::2010/09/17-12:01:32.626 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.000006c0::2010/09/17-12:01:32.626 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18071 Generation=0
    0000089c.000006c0::2010/09/17-12:01:32.626 INFO [GUM] GumSendUpdate: Locker dispatching seq 18071 type 1 context 4098
    0000089c.000006c0::2010/09/17-12:01:32.626 INFO [DM] DmWriteToQuorumLog Entry Seq#=18071 Type=4098 Size=180
    0000089c.000006c0::2010/09/17-12:01:32.626 INFO [LM] LogCommitSize : Entry RmId=5 Size=180
    0000089c.000006c0::2010/09/17-12:01:32.626 INFO [LM] LogCommitSize : Exit, returning 0x00000000
    0000089c.000006c0::2010/09/17-12:01:32.626 INFO [DM] DmUpdateSetValue
    0000089c.000006c0::2010/09/17-12:01:32.626 INFO [DM] Setting value of InterfaceContext for key Resources\96458aa8-d7e0-4466-9626-e26895d315a8\Parameters\1 to 0x00000005
    0000089c.000006c0::2010/09/17-12:01:32.626 INFO [DM] DmWriteToQuorumLog Entry Seq#=18071 Type=4098 Size=180
    0000089c.000006c0::2010/09/17-12:01:32.626 INFO [LM] LogWrite : Entry TrId=18071 RmId=5 RmType = 4098 Size=180
    0000089c.000006c0::2010/09/17-12:01:32.626 INFO [LM] LogWrite : Exit returning=0x00000a48
    0000089c.000006c0::2010/09/17-12:01:32.626 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.000006c0::2010/09/17-12:01:32.626 INFO [GUM] GumSendUpdate: completed update seq 18071 type 1 context 4098
    0000089c.00000b38::2010/09/17-12:01:32.626 INFO [GUM] GumSendUpdate:  Locker waiting  type 1 context 4098
    0000089c.00000b38::2010/09/17-12:01:32.626 INFO [GUM] Thread 0xb38 UpdateLock wait on Type 1
    0000089c.00000b38::2010/09/17-12:01:32.626 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000b38::2010/09/17-12:01:32.626 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18072 Generation=0
    0000089c.00000b38::2010/09/17-12:01:32.626 INFO [GUM] GumSendUpdate: Locker dispatching seq 18072 type 1 context 4098
    0000089c.00000b38::2010/09/17-12:01:32.626 INFO [DM] DmWriteToQuorumLog Entry Seq#=18072 Type=4098 Size=180
    0000089c.00000b38::2010/09/17-12:01:32.626 INFO [LM] LogCommitSize : Entry RmId=5 Size=180
    0000089c.00000b38::2010/09/17-12:01:32.626 INFO [LM] LogCommitSize : Exit, returning 0x00000000
    0000089c.00000b38::2010/09/17-12:01:32.626 INFO [DM] DmUpdateSetValue
    0000089c.00000b38::2010/09/17-12:01:32.626 INFO [DM] Setting value of InterfaceInstance for key Resources\96458aa8-d7e0-4466-9626-e26895d315a8\Parameters\1 to 0x50488bd2
    0000089c.00000b38::2010/09/17-12:01:32.626 INFO [DM] DmWriteToQuorumLog Entry Seq#=18072 Type=4098 Size=180
    0000089c.00000b38::2010/09/17-12:01:32.626 INFO [LM] LogWrite : Entry TrId=18072 RmId=5 RmType = 4098 Size=180
    0000089c.00000b38::2010/09/17-12:01:32.626 INFO [LM] LogpAppendPage : Writing 1024 bytes to disk at offset 0x00000800
    0000089c.00000b38::2010/09/17-12:01:32.626 INFO [Qfs] WriteFile 78c (....) 1024, status 997 (0=>0)
    0000089c.00000998::2010/09/17-12:01:33.299 INFO [Qfs] GetDiskFreeSpaceEx Q:\MSCS\, status 0
    000009d0.00000228::2010/09/17-12:01:34.378 INFO Network Name <MSDTC NAME>: Registered server name PAM-MSDTC01 on transport \Device\NetBt_If1.
    000009d0.00000cd8::2010/09/17-12:01:34.597 ERR  Physical Disk <Avid Workgroup Disk>: SCSI: Attach, error attaching to signature 5b3f792, error 2.
    000009d0.00000cd8::2010/09/17-12:01:34.597 ERR  Physical Disk <Avid Workgroup Disk>: Online: Unable to attach to signature 5b3f792. Error: 2.
    000009d0.00000cd8::2010/09/17-12:01:34.597 ERR  Physical Disk <Avid Workgroup Disk>: Online, DisksOpenResourceFileHandle failed. Error: 2
    000009d0.00000cd8::2010/09/17-12:01:34.597 INFO Physical Disk <Avid Workgroup Disk>: Online, setting ResourceState 4 .
    000009d0.00000cd8::2010/09/17-12:01:34.597 INFO [RM] RmpSetResourceStatus, Posting state 4 notification for resource <Avid Workgroup Disk>
    000009d0.00000cd8::2010/09/17-12:01:34.597 INFO Physical Disk <Avid Workgroup Disk>: Online, returning final error 2   ResourceState 4  Valid 0
    0000089c.000009e4::2010/09/17-12:01:34.597 INFO [FM] NotifyCallBackRoutine: enqueuing event
    0000089c.000009e4::2010/09/17-12:01:34.597 INFO [FM] Calling RmNotifyChanges in monitor 09d0.
    0000089c.00000990::2010/09/17-12:01:34.597 INFO [CP] CppResourceNotify for resource Avid Workgroup Disk
    0000089c.00000990::2010/09/17-12:01:34.597 INFO [FM] FmpRmDoHandleCriticalResourceStateChange: call InterlockedDecrement on gdwQuoBlockingResources, Resource 5d5a6410-9739-44f5-ae97-7cd9d467fc08
    0000089c.00000994::2010/09/17-12:01:34.597 WARN [FM] FmpHandleResourceTransition: Resource Name = 5d5a6410-9739-44f5-ae97-7cd9d467fc08 [Avid Workgroup Disk] old state=129 new state=4
    0000089c.00000994::2010/09/17-12:01:34.597 WARN [FM] FmpHandleResourceTransition: Resource failed, post a work item
    0000089c.00000b38::2010/09/17-12:01:35.098 INFO [Qfs] QfsFlushBuffers 78c, status 0
    0000089c.00000b38::2010/09/17-12:01:35.098 INFO [LM] LogWrite : Exit returning=0x00000c08
    0000089c.00000b38::2010/09/17-12:01:35.098 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000b38::2010/09/17-12:01:35.098 INFO [GUM] GumSendUpdate: completed update seq 18072 type 1 context 4098
    0000089c.00000c60::2010/09/17-12:01:35.098 INFO [GUM] GumSendUpdate:  Locker waiting  type 1 context 4098
    0000089c.00000c60::2010/09/17-12:01:35.098 INFO [GUM] Thread 0xc60 UpdateLock wait on Type 1
    0000089c.00000c60::2010/09/17-12:01:35.098 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000c60::2010/09/17-12:01:35.098 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18073 Generation=0
    000009d0.00000cd0::2010/09/17-12:01:35.098 INFO IP Address <Cluster IP Address>: Created IP interface 5 (instance 0x50488BD2).
    0000089c.00000c60::2010/09/17-12:01:35.098 INFO [GUM] GumSendUpdate: Locker dispatching seq 18073 type 1 context 4098
    0000089c.00000c60::2010/09/17-12:01:35.098 INFO [DM] DmWriteToQuorumLog Entry Seq#=18073 Type=4098 Size=180
    0000089c.00000c60::2010/09/17-12:01:35.098 INFO [LM] LogCommitSize : Entry RmId=5 Size=180
    0000089c.00000c60::2010/09/17-12:01:35.098 INFO [LM] LogCommitSize : Exit, returning 0x00000000
    0000089c.00000c60::2010/09/17-12:01:35.098 INFO [DM] DmUpdateSetValue
    0000089c.00000c60::2010/09/17-12:01:35.098 INFO [DM] Setting value of InterfaceContext for key Resources\ad1074e2-f308-4b43-b7d7-414e7104a792\Parameters\1 to 0x00000006
    0000089c.00000c60::2010/09/17-12:01:35.098 INFO [DM] DmWriteToQuorumLog Entry Seq#=18073 Type=4098 Size=180
    0000089c.00000c60::2010/09/17-12:01:35.098 INFO [LM] LogWrite : Entry TrId=18073 RmId=5 RmType = 4098 Size=180
    0000089c.00000c60::2010/09/17-12:01:35.098 INFO [LM] LogWrite : Exit returning=0x00000cf0
    0000089c.00000c60::2010/09/17-12:01:35.098 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000c60::2010/09/17-12:01:35.098 INFO [GUM] GumSendUpdate: completed update seq 18073 type 1 context 4098
    0000089c.00000994::2010/09/17-12:01:35.098 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.098 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.098 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.098 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18074 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.098 INFO [GUM] GumSendUpdate: Locker dispatching seq 18074 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.098 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.098 INFO [GUM] GumSendUpdate: completed update seq 18074 type 0 context 8
    0000089c.000006c0::2010/09/17-12:01:35.098 INFO [GUM] GumSendUpdate:  Locker waiting  type 1 context 4098
    0000089c.00000994::2010/09/17-12:01:35.098 INFO [FM] FmpPropagateResourceState: resource 5d5a6410-9739-44f5-ae97-7cd9d467fc08 failed event.
    0000089c.000006c0::2010/09/17-12:01:35.098 INFO [GUM] Thread 0x6c0 UpdateLock wait on Type 1
    0000089c.000006c0::2010/09/17-12:01:35.098 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.000006c0::2010/09/17-12:01:35.098 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18075 Generation=0
    0000089c.000006c0::2010/09/17-12:01:35.098 INFO [GUM] GumSendUpdate: Locker dispatching seq 18075 type 1 context 4098
    0000089c.000006c0::2010/09/17-12:01:35.098 INFO [DM] DmWriteToQuorumLog Entry Seq#=18075 Type=4098 Size=204
    0000089c.000006c0::2010/09/17-12:01:35.098 INFO [LM] LogCommitSize : Entry RmId=5 Size=204
    0000089c.000006c0::2010/09/17-12:01:35.098 INFO [LM] LogCommitSize : Exit, returning 0x00000000
    0000089c.000006c0::2010/09/17-12:01:35.098 INFO [DM] DmUpdateSetValue
    0000089c.000006c0::2010/09/17-12:01:35.098 INFO [DM] Setting value of NbtDeviceName for key Resources\96458aa8-d7e0-4466-9626-e26895d315a8\Parameters\1 to \Device\NetBt_If2
    0000089c.00000994::2010/09/17-12:01:35.098 INFO [FM] FmpHandleResourceFailure: taking resource 5d5a6410-9739-44f5-ae97-7cd9d467fc08 and dependents offline
    0000089c.000006c0::2010/09/17-12:01:35.098 INFO [DM] DmWriteToQuorumLog Entry Seq#=18075 Type=4098 Size=204
    0000089c.00000994::2010/09/17-12:01:35.098 INFO [FM] TerminateResource: 00af16b7-823d-4202-aabf-7c73534fce21 depends on 5d5a6410-9739-44f5-ae97-7cd9d467fc08. Terminating first
    0000089c.00000994::2010/09/17-12:01:35.098 INFO [FM] TerminateResource: 37cc9283-304d-4545-a14b-99f3363233c1 depends on 00af16b7-823d-4202-aabf-7c73534fce21. Terminating first
    0000089c.000006c0::2010/09/17-12:01:35.098 INFO [LM] LogWrite : Entry TrId=18075 RmId=5 RmType = 4098 Size=204
    0000089c.00000994::2010/09/17-12:01:35.098 INFO [FM] TerminateResource: 42c57f85-6025-4b55-9250-155bf80c830f depends on 37cc9283-304d-4545-a14b-99f3363233c1. Terminating first
    0000089c.000006c0::2010/09/17-12:01:35.098 INFO [LM] LogWrite : Exit returning=0x00000dd8
    0000089c.000006c0::2010/09/17-12:01:35.098 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.000006c0::2010/09/17-12:01:35.098 INFO [GUM] GumSendUpdate: completed update seq 18075 type 1 context 4098
    000009d0.000009e0::2010/09/17-12:01:35.098 INFO Generic Service <Avid Workgroup Server Browser>: Terminate request.
    0000089c.00000964::2010/09/17-12:01:35.098 INFO [GUM] GumSendUpdate:  Locker waiting  type 1 context 4098
    0000089c.00000964::2010/09/17-12:01:35.098 INFO [GUM] Thread 0x964 UpdateLock wait on Type 1
    0000089c.00000964::2010/09/17-12:01:35.098 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000964::2010/09/17-12:01:35.098 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18076 Generation=0
    0000089c.00000964::2010/09/17-12:01:35.098 INFO [GUM] GumSendUpdate: Locker dispatching seq 18076 type 1 context 4098
    0000089c.00000964::2010/09/17-12:01:35.098 INFO [DM] DmWriteToQuorumLog Entry Seq#=18076 Type=4098 Size=180
    0000089c.00000964::2010/09/17-12:01:35.098 INFO [LM] LogCommitSize : Entry RmId=5 Size=180
    0000089c.00000964::2010/09/17-12:01:35.098 INFO [LM] LogCommitSize : Exit, returning 0x00000000
    0000089c.00000964::2010/09/17-12:01:35.098 INFO [DM] DmUpdateSetValue
    0000089c.00000964::2010/09/17-12:01:35.098 INFO [DM] Setting value of InterfaceInstance for key Resources\ad1074e2-f308-4b43-b7d7-414e7104a792\Parameters\1 to 0x50488bd2
    0000089c.00000964::2010/09/17-12:01:35.098 INFO [DM] DmWriteToQuorumLog Entry Seq#=18076 Type=4098 Size=180
    0000089c.00000964::2010/09/17-12:01:35.098 INFO [LM] LogWrite : Entry TrId=18076 RmId=5 RmType = 4098 Size=180
    0000089c.00000964::2010/09/17-12:01:35.098 INFO [LM] LogWrite : Exit returning=0x00000ed8
    0000089c.00000964::2010/09/17-12:01:35.098 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000964::2010/09/17-12:01:35.098 INFO [GUM] GumSendUpdate: completed update seq 18076 type 1 context 4098
    0000089c.00000d1c::2010/09/17-12:01:35.098 INFO [GUM] GumSendUpdate:  Locker waiting  type 1 context 4098
    000009d0.00000738::2010/09/17-12:01:35.098 INFO IP Address <Avid Workgroup Address>: Created IP interface 6 (instance 0x50488BD2).
    0000089c.00000d1c::2010/09/17-12:01:35.098 INFO [GUM] Thread 0xd1c UpdateLock wait on Type 1
    0000089c.00000d1c::2010/09/17-12:01:35.098 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000d1c::2010/09/17-12:01:35.098 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18077 Generation=0
    0000089c.00000d1c::2010/09/17-12:01:35.098 INFO [GUM] GumSendUpdate: Locker dispatching seq 18077 type 1 context 4098
    0000089c.00000d1c::2010/09/17-12:01:35.098 INFO [DM] DmWriteToQuorumLog Entry Seq#=18077 Type=4098 Size=180
    0000089c.00000d1c::2010/09/17-12:01:35.098 INFO [LM] LogCommitSize : Entry RmId=5 Size=180
    0000089c.00000d1c::2010/09/17-12:01:35.098 INFO [LM] LogCommitSize : Exit, returning 0x00000000
    0000089c.00000d1c::2010/09/17-12:01:35.098 INFO [DM] DmUpdateSetValue
    0000089c.00000d1c::2010/09/17-12:01:35.098 INFO [DM] Setting value of NbtDeviceInstance for key Resources\96458aa8-d7e0-4466-9626-e26895d315a8\Parameters\1 to 0x5048957a
    0000089c.00000d1c::2010/09/17-12:01:35.098 INFO [DM] DmWriteToQuorumLog Entry Seq#=18077 Type=4098 Size=180
    0000089c.00000d1c::2010/09/17-12:01:35.098 INFO [LM] LogWrite : Entry TrId=18077 RmId=5 RmType = 4098 Size=180
    0000089c.00000d1c::2010/09/17-12:01:35.098 INFO [LM] LogpAppendPage : Writing 1024 bytes to disk at offset 0x00000c00
    0000089c.00000d1c::2010/09/17-12:01:35.098 INFO [Qfs] WriteFile 78c (....) 1024, status 0 (0=>0)
    0000089c.00000d1c::2010/09/17-12:01:35.114 INFO [Qfs] QfsFlushBuffers 78c, status 0
    0000089c.00000d1c::2010/09/17-12:01:35.114 INFO [LM] LogWrite : Exit returning=0x00001008
    0000089c.00000d1c::2010/09/17-12:01:35.114 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000d1c::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate: completed update seq 18077 type 1 context 4098
    0000089c.00000c60::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate:  Locker waiting  type 1 context 4098
    000009d0.00000cd0::2010/09/17-12:01:35.114 INFO IP Address <Cluster IP Address>: Created NBT interface \Device\NetBt_If2 (instance 0x5048957A).
    0000089c.00000c60::2010/09/17-12:01:35.114 INFO [GUM] Thread 0xc60 UpdateLock wait on Type 1
    0000089c.00000c60::2010/09/17-12:01:35.114 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000c60::2010/09/17-12:01:35.114 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18078 Generation=0
    0000089c.00000c60::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate: Locker dispatching seq 18078 type 1 context 4098
    0000089c.00000c60::2010/09/17-12:01:35.114 INFO [DM] DmWriteToQuorumLog Entry Seq#=18078 Type=4098 Size=204
    0000089c.00000c60::2010/09/17-12:01:35.114 INFO [LM] LogCommitSize : Entry RmId=5 Size=204
    0000089c.00000c60::2010/09/17-12:01:35.114 INFO [LM] LogCommitSize : Exit, returning 0x00000000
    0000089c.00000c60::2010/09/17-12:01:35.114 INFO [DM] DmUpdateSetValue
    0000089c.00000c60::2010/09/17-12:01:35.114 INFO [DM] Setting value of NbtDeviceName for key Resources\ad1074e2-f308-4b43-b7d7-414e7104a792\Parameters\1 to \Device\NetBt_If3
    0000089c.00000c60::2010/09/17-12:01:35.114 INFO [DM] DmWriteToQuorumLog Entry Seq#=18078 Type=4098 Size=204
    0000089c.00000c60::2010/09/17-12:01:35.114 INFO [LM] LogWrite : Entry TrId=18078 RmId=5 RmType = 4098 Size=204
    0000089c.00000c60::2010/09/17-12:01:35.114 INFO [LM] LogWrite : Exit returning=0x000010f0
    0000089c.00000c60::2010/09/17-12:01:35.114 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000c60::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate: completed update seq 18078 type 1 context 4098
    0000089c.000006c0::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate:  Locker waiting  type 1 context 4098
    0000089c.000006c0::2010/09/17-12:01:35.114 INFO [GUM] Thread 0x6c0 UpdateLock wait on Type 1
    0000089c.000006c0::2010/09/17-12:01:35.114 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.000006c0::2010/09/17-12:01:35.114 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18079 Generation=0
    0000089c.000006c0::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate: Locker dispatching seq 18079 type 1 context 4098
    0000089c.000006c0::2010/09/17-12:01:35.114 INFO [DM] DmWriteToQuorumLog Entry Seq#=18079 Type=4098 Size=180
    0000089c.000006c0::2010/09/17-12:01:35.114 INFO [LM] LogCommitSize : Entry RmId=5 Size=180
    0000089c.000006c0::2010/09/17-12:01:35.114 INFO [LM] LogCommitSize : Exit, returning 0x00000000
    0000089c.000006c0::2010/09/17-12:01:35.114 INFO [DM] DmUpdateSetValue
    0000089c.000006c0::2010/09/17-12:01:35.114 INFO [DM] Setting value of NbtDeviceInstance for key Resources\ad1074e2-f308-4b43-b7d7-414e7104a792\Parameters\1 to 0x5048957a
    0000089c.000006c0::2010/09/17-12:01:35.114 INFO [DM] DmWriteToQuorumLog Entry Seq#=18079 Type=4098 Size=180
    0000089c.000006c0::2010/09/17-12:01:35.114 INFO [LM] LogWrite : Entry TrId=18079 RmId=5 RmType = 4098 Size=180
    0000089c.000006c0::2010/09/17-12:01:35.114 INFO [LM] LogWrite : Exit returning=0x000011f0
    0000089c.000006c0::2010/09/17-12:01:35.114 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.000006c0::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate: completed update seq 18079 type 1 context 4098
    000009d0.00000738::2010/09/17-12:01:35.114 INFO IP Address <Avid Workgroup Address>: Created NBT interface \Device\NetBt_If3 (instance 0x5048957A).
    000009d0.000009e0::2010/09/17-12:01:35.114 WARN Generic Service <Avid Workgroup Server Browser>: ResUtilRemoveResourceServiceEnvironment: Failed to remove environment value from service Avid Workgroup Server Browser, error = 859088.
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [CP] CppResourceNotify for resource Avid Workgroup Server Browser
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18080 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate: Locker dispatching seq 18080 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate: completed update seq 18080 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [FM] FmpPropagateResourceState: resource 42c57f85-6025-4b55-9250-155bf80c830f offline event.
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [FM] RmTerminateResource: 42c57f85-6025-4b55-9250-155bf80c830f is now offline
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [FM] TerminateResource: 99da4d89-9b80-4812-87ee-51ff1acb346a depends on 37cc9283-304d-4545-a14b-99f3363233c1. Terminating first
    000009d0.000009e8::2010/09/17-12:01:35.114 INFO Generic Service <Avid Workgroup VSS Service>: Terminate request.
    000009d0.000009e8::2010/09/17-12:01:35.114 WARN Generic Service <Avid Workgroup VSS Service>: ResUtilRemoveResourceServiceEnvironment: Failed to remove environment value from service Avid Workgroup VSS Service, error = 861632.
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [CP] CppResourceNotify for resource Avid Workgroup VSS Service
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18081 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate: Locker dispatching seq 18081 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate: completed update seq 18081 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [FM] FmpPropagateResourceState: resource 99da4d89-9b80-4812-87ee-51ff1acb346a offline event.
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [FM] RmTerminateResource: 99da4d89-9b80-4812-87ee-51ff1acb346a is now offline
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [FM] TerminateResource: 0e455252-c22e-462e-9b72-c88b5e8e4644 depends on 37cc9283-304d-4545-a14b-99f3363233c1. Terminating first
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [FM] TerminateResource: c4607cab-9bfd-415f-849b-9a8c549b5101 depends on 0e455252-c22e-462e-9b72-c88b5e8e4644. Terminating first
    000009d0.000009e0::2010/09/17-12:01:35.114 INFO Generic Service <Avid Workgroup Preview Server>: Terminate request.
    000009d0.000009e0::2010/09/17-12:01:35.114 WARN Generic Service <Avid Workgroup Preview Server>: ResUtilRemoveResourceServiceEnvironment: Failed to remove environment value from service Avid_Workgroup_Preview_Server, error = 617528.
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [CP] CppResourceNotify for resource Avid Workgroup Preview Server
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18082 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate: Locker dispatching seq 18082 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate: completed update seq 18082 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [FM] FmpPropagateResourceState: resource c4607cab-9bfd-415f-849b-9a8c549b5101 offline event.
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [FM] RmTerminateResource: c4607cab-9bfd-415f-849b-9a8c549b5101 is now offline
    000009d0.000009e8::2010/09/17-12:01:35.114 INFO Generic Service <Avid Workgroup TCP COM Bridge>: Terminate request.
    000009d0.000009e8::2010/09/17-12:01:35.114 WARN Generic Service <Avid Workgroup TCP COM Bridge>: ResUtilRemoveResourceServiceEnvironment: Failed to remove environment value from service Avid Workgroup TCP COM Bridge, error = 614648.
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [CP] CppResourceNotify for resource Avid Workgroup TCP COM Bridge
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18083 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate: Locker dispatching seq 18083 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate: completed update seq 18083 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [FM] FmpPropagateResourceState: resource 0e455252-c22e-462e-9b72-c88b5e8e4644 offline event.
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [FM] RmTerminateResource: 0e455252-c22e-462e-9b72-c88b5e8e4644 is now offline
    000009d0.000009e0::2010/09/17-12:01:35.114 INFO Avid Workgroup Server <Avid Workgroup Server>: Terminate: Terminate request for resource 'Avid Workgroup Server'.
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [CP] CppResourceNotify for resource Avid Workgroup Server
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18084 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate: Locker dispatching seq 18084 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [GUM] GumSendUpdate: completed update seq 18084 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [FM] FmpPropagateResourceState: resource 37cc9283-304d-4545-a14b-99f3363233c1 offline event.
    0000089c.00000994::2010/09/17-12:01:35.114 INFO [FM] RmTerminateResource: 37cc9283-304d-4545-a14b-99f3363233c1 is now offline
    000009d0.000009e8::2010/09/17-12:01:35.129 INFO File Share <Avid Workgroup Share>: SmbShareDoTerminate: SmbpShareNotifyWorker Terminated... !!!
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [CP] CppResourceNotify for resource Avid Workgroup Share
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18085 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18085 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18085 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] FmpPropagateResourceState: resource 00af16b7-823d-4202-aabf-7c73534fce21 offline event.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] RmTerminateResource: 00af16b7-823d-4202-aabf-7c73534fce21 is now offline
    000009d0.000009e0::2010/09/17-12:01:35.129 INFO Physical Disk <Avid Workgroup Disk>: Terminate, ResourceEntry @ 000B10F0  Valid 0
    000009d0.000009fc::2010/09/17-12:01:35.129 INFO Physical Disk <Avid Workgroup Disk>: [PnP] Stop watching PnP events for disk 5b3f792
    000009d0.000009fc::2010/09/17-12:01:35.129 WARN Physical Disk <Avid Workgroup Disk>: [PnP] RemoveDisk: disk 5b3f792 not found or previously removed
    000009d0.000009fc::2010/09/17-12:01:35.129 INFO Physical Disk <Avid Workgroup Disk>: [PnP] Stop watching disk 5b3f792 - processed
    000009d0.000009e0::2010/09/17-12:01:35.129 INFO Physical Disk <Avid Workgroup Disk>: DiskCleanup started.
    000009d0.000009e0::2010/09/17-12:01:35.129 INFO Physical Disk <Avid Workgroup Disk>: [DiskArb] StopPersistentReservations is called.
    000009d0.000009e0::2010/09/17-12:01:35.129 INFO Physical Disk <Avid Workgroup Disk>: [DiskArb] StopPersistentReservations is complete.
    000009d0.000009e0::2010/09/17-12:01:35.129 INFO Physical Disk <Avid Workgroup Disk>: DiskCleanup returning final error 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [CP] CppResourceNotify for resource Avid Workgroup Disk
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] RmTerminateResource: 5d5a6410-9739-44f5-ae97-7cd9d467fc08 is now offline
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] RestartResourceTree, Restart resource 5d5a6410-9739-44f5-ae97-7cd9d467fc08
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] FmpRmOnlineResource: bringing resource 5d5a6410-9739-44f5-ae97-7cd9d467fc08 (resid 1233496) online.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [CP] CppResourceNotify for resource Avid Workgroup Disk
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] FmpRmOnlineResource: called InterlockedIncrement on gdwQuoBlockingResources for resource 5d5a6410-9739-44f5-ae97-7cd9d467fc08
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18086 Generation=0
    000009d0.00000d58::2010/09/17-12:01:35.129 INFO Physical Disk <Avid Workgroup Disk>: [DiskArb]------- DisksOnline -------.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18086 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18086 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] FmpPropagateResourceState: resource 5d5a6410-9739-44f5-ae97-7cd9d467fc08 pending event.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] FmpRmOnlineResource: Resource 5d5a6410-9739-44f5-ae97-7cd9d467fc08 pending
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] FmpRmOnlineResource: Returning. Resource 5d5a6410-9739-44f5-ae97-7cd9d467fc08, state 129, status 997.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] RestartResourceTree, 00af16b7-823d-4202-aabf-7c73534fce21 depends on 5d5a6410-9739-44f5-ae97-7cd9d467fc08. Restart first
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] RestartResourceTree, Restart resource 00af16b7-823d-4202-aabf-7c73534fce21
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] OnlineResource: 00af16b7-823d-4202-aabf-7c73534fce21 depends on 5d5a6410-9739-44f5-ae97-7cd9d467fc08. Bring online first.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18087 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18087 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18087 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] FmpPropagateResourceState: resource 00af16b7-823d-4202-aabf-7c73534fce21 pending event.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] RestartResourceTree, 37cc9283-304d-4545-a14b-99f3363233c1 depends on 00af16b7-823d-4202-aabf-7c73534fce21. Restart first
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] RestartResourceTree, Restart resource 37cc9283-304d-4545-a14b-99f3363233c1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] OnlineResource: 37cc9283-304d-4545-a14b-99f3363233c1 depends on 1906ae7c-cca0-4acd-99ec-9f010cd4c19d. Bring online first.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18088 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18088 type 0 context 8
    000009d0.00000d58::2010/09/17-12:01:35.129 INFO Physical Disk <Avid Workgroup Disk>: [DiskArb] DisksOpenResourceFileHandle: Attaching to disk with signature 5b3f792
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    000009d0.00000d58::2010/09/17-12:01:35.129 INFO Physical Disk <Avid Workgroup Disk>: [DiskArb] DisksOpenResourceFileHandle: Disk unique id present trying new attach
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18088 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] FmpPropagateResourceState: resource 37cc9283-304d-4545-a14b-99f3363233c1 pending event.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] OnlineResource: 37cc9283-304d-4545-a14b-99f3363233c1 depends on 00af16b7-823d-4202-aabf-7c73534fce21. Bring online first.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] RestartResourceTree, 42c57f85-6025-4b55-9250-155bf80c830f depends on 37cc9283-304d-4545-a14b-99f3363233c1. Restart first
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] RestartResourceTree, Restart resource 42c57f85-6025-4b55-9250-155bf80c830f
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] OnlineResource: 42c57f85-6025-4b55-9250-155bf80c830f depends on 37cc9283-304d-4545-a14b-99f3363233c1. Bring online first.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18089 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18089 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18089 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] FmpPropagateResourceState: resource 42c57f85-6025-4b55-9250-155bf80c830f pending event.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] RestartResourceTree, 99da4d89-9b80-4812-87ee-51ff1acb346a depends on 37cc9283-304d-4545-a14b-99f3363233c1. Restart first
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] RestartResourceTree, Restart resource 99da4d89-9b80-4812-87ee-51ff1acb346a
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] OnlineResource: 99da4d89-9b80-4812-87ee-51ff1acb346a depends on 37cc9283-304d-4545-a14b-99f3363233c1. Bring online first.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18090 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18090 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18090 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] FmpPropagateResourceState: resource 99da4d89-9b80-4812-87ee-51ff1acb346a pending event.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] RestartResourceTree, 0e455252-c22e-462e-9b72-c88b5e8e4644 depends on 37cc9283-304d-4545-a14b-99f3363233c1. Restart first
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] RestartResourceTree, Restart resource 0e455252-c22e-462e-9b72-c88b5e8e4644
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] OnlineResource: 0e455252-c22e-462e-9b72-c88b5e8e4644 depends on 37cc9283-304d-4545-a14b-99f3363233c1. Bring online first.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18091 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18091 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18091 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] FmpPropagateResourceState: resource 0e455252-c22e-462e-9b72-c88b5e8e4644 pending event.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] RestartResourceTree, c4607cab-9bfd-415f-849b-9a8c549b5101 depends on 0e455252-c22e-462e-9b72-c88b5e8e4644. Restart first
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] RestartResourceTree, Restart resource c4607cab-9bfd-415f-849b-9a8c549b5101
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] OnlineResource: c4607cab-9bfd-415f-849b-9a8c549b5101 depends on 0e455252-c22e-462e-9b72-c88b5e8e4644. Bring online first.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18092 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18092 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18092 type 0 context 8
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [FM] FmpPropagateResourceState: resource c4607cab-9bfd-415f-849b-9a8c549b5101 pending event.
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18093 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18093 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18093 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18094 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18094 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18094 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18095 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18095 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18095 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18096 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18096 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18096 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18097 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18097 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18097 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18098 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18098 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18098 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18099 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18099 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18099 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18100 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18100 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18100 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18101 Generation=0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: Locker dispatching seq 18101 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoUnlockingUpdate releasing lock ownership
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate: completed update seq 18101 type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumSendUpdate:  Locker waiting  type 0 context 11
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] Thread 0x994 UpdateLock wait on Type 0
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate: lock was free, granted to 1
    0000089c.00000994::2010/09/17-12:01:35.129 INFO [GUM] GumpDoLockingUpdate successful, Sequence=18102 Generation=0
    000009d0.00000d58::2010/09/17-12:01:35.129 ERR  Physical Disk <Avid Workgroup Disk>: [DiskArb] Signature of disk has changed or failed to find disk with id, old signature 0x5b3f792 new signature 0x5b3f797, status 0

    Monday, September 20, 2010 10:00 AM
  • Hello,

    In a previous thread I found that it could be relevant to test how the node can access the disks when the cluster is not in the way :

    "the next steps would be to disabling cluster service and the cluster disk driver (and reboot) to verify that the host can see/access this disk without cluster in the way."

    I made a first test by desabling the cluster service. The node can see each disk, but cannot access it.
    I don't understand what means/how to disable the cluster disk driver. can you drive me on?

    Best regards

    Emmanuel

    Wednesday, September 22, 2010 8:56 AM
  • To disable the cluster disk driver, you need to go into Device Manager and in the View menu choose Show Hidden Devices. Then, in the right-hand pane, under Non-Plug and Play Drivers, you will find the Cluster Disk driver.

    From your cluster.log, you can see that the cluster isn't finding the signature 0x5b3f792...so it seems that your disk signature is changing.


    Visit my blog about multi-site clustering - http://msmvps.com/blogs/jtoner
    Wednesday, September 22, 2010 6:11 PM
  • Thank you for the info John.

    it's very probably that something is wrong in my cluster knowledge ; I thought that if the signature is missing it was not possible to bring the ressource disk online. In that case case it's always possible to bring the ressource online, even when the failover issue happends. Is there a process in background which allow the Cluster to check if another disk with another signature can be used?

    So, if I understand it means that the signature on the disk itself is changing. That's why, fixing the signature with the command
    cluster . res "ressource" /priv signature=0x5b3f792
    does not work. Because this is the signature the Cluster is expecting.
    In that case what could be the prefered way to solve the issue? Is there a way to fix the signature of the disk itself, to prevent it to change?
    with dumpcfg.exe? It is supposed to be part of the Win2000 RessourceKit. I can't find it in this RK???

    Wednesday, September 22, 2010 7:19 PM
  • Cluster requires that the disk's signature match the signature value stored in the cluster registry.

    In your case, I do not have enough info to diagnose why your signature might be changing. If you did not manually change the signature, I think it would be pretty unlikely that the disks old signature would be so close to the new signature value as this would tend to be more random if the host changed the signature. This leads me to think that maybe the cluster disk driver is looking at the wrong device. Are you doing any sort of cloning with the storage devices?

    I think a good step would be to disable the cluster disk driver and verify the disk signature of all clustered disks on both nodes. If the cluster is using the wrong signature for the disk, you can either corrected it in the cluster hive, or change the signature on the disk to match what cluster is looking for.

    It might be a good idea to open a case with Microsoft PSS or your storage vendor to look at this further as I don't know how much we can actually accomplish diagnosing this further on a forum.


    Visit my blog about multi-site clustering - http://msmvps.com/blogs/jtoner
    Friday, September 24, 2010 4:10 PM
  • I must say that I doubt the signature are changing. Or really temporarly (Storage behaviour?)

    I did some diskpart and some verification of the cluster hive information before, during and after the incident :
    Results are always consistant. Each disks are correctly registered, with the correct signature AND for both nodes.
    When stopping the cluster service and the cluster Disk driver, I can normally work with the cluster disks on both nodes.

    As you say, next step is to work with Microsoft PSS and Storage Vendor. Maybe the storage vendor first.
    If a solution is found, I'll let you know.

    Friday, September 24, 2010 11:00 PM
  • Hi Emmanuel Der ,

    Did you get any solution or workaround for the " disk signature changing" problem? I am experiencing similar problem where disk signature is getting changed during failover and not coming online.

    Thursday, May 03, 2012 6:27 PM
  • If the disk signatures, when examined, are same; then you will have to involve the Storage vendor to see if this is a storage presentation / configuration issue. Check for outdated scsi or hba drivers. More than 1 year old firmware / drivers are normally considered outdated. It looks like may be owing to disk reservation issues. Please involve your storage vendor along-side PSS.

    HTH


    - thestriver



    • Edited by thestriver Friday, May 04, 2012 4:53 AM .
    • Proposed as answer by thestriver Friday, May 11, 2012 1:23 AM
    Friday, May 04, 2012 4:51 AM