Snapdrive 6.31R1 takes very long time to enumerate disks

[thierry]

Hello ,

Windows 2008 R2 SP1

DSM 3.5

Snapdrive6.3.1R1

Ontap 8.0.2P3

We have 10 servers installed, dedicated to an exchange 2010 infrastructure.

Each server has 45 Luns.

8 of those servers takes around 15 minutes to enumerates their LUN (when you click on “disks” in the mmc) while 2 of them only takes between 30 to 45 seconds for the same number of LUNs.

Looking at the “snpdrvdbglog files of both a long enumerating server and a fast enumerating server I have noticed the following things.

On the slow server, we issue 4 times the NetShareEnum Call for every volume. Each call takes 10 seconds so 40 seconds per volume, for a total of 14 minutes due to the number of volumes.

On the “quick” servers, for the same process, it doesn’t take any time.

Any idea why we spend each time 10 seconds for this call on some servers and 0s on 2 others ?

See the output below :

Slow enumerating server :

03/28-12:59:07.666                PID:1496  TID:620    System.cpp@649                    CSystem::enumerate_virtual_disks: volume_set.modify(33, 192.91.36.123+192.132.84.101, DRPMSAE207A0011

03/28-12:59:07.666                PID:1496  TID:620    volume_set.cpp@141                             Start volume_t::update_functor::operator()(volume_t* p_volume)

03/28-12:59:07.666                PID:1496  TID:620    volume_set.cpp@14                               Start volume_t::update_cifs_share_name(filer_t& filer)

03/28-12:59:07.666                PID:1496  TID:620    VirtualDiskShare.cpp@2569                   Start get_cifs_share_name(192.132.84.101, DRPMSAE207A0011)

03/28-12:59:07.666                PID:1496  TID:620    VirtualDiskShare.cpp@998                     Start GetShareName(192.132.84.101, DRPMSAE207A0011)

03/28-12:59:07.666                PID:1496  TID:620    VirtualDiskShare.cpp@1006                   GetShareName: calling NetShareEnum

03/28-12:59:17.697                PID:1496  TID:620    VirtualDiskShare.cpp@1058                   GetShareName: did not find share the 1st time, try again...

03/28-12:59:17.697                PID:1496  TID:620    VirtualDiskShare.cpp@1070                   GetShareName: calling NetShareEnum

03/28-12:59:27.712                PID:1496  TID:620    VirtualDiskShare.cpp@1129                   Finish GetShareName: hr = 80070005

03/28-12:59:27.712                PID:1496  TID:620    VirtualDiskShare.cpp@2576                   Finish get_cifs_share_name()

03/28-12:59:27.712                PID:1496  TID:620    volume_set.cpp@27                               Finish volume_t::update_cifs_share_name(filer_t& filer)

03/28-12:59:27.712                PID:1496  TID:620    volume_set.cpp@68                               Start volume_t::update_volume_clone_status(filer_t& filer)

03/28-12:59:27.712                PID:1496  TID:620    volume_set.cpp@100                             Finish volume_t::update_volume_clone_status(filer_t& filer)-volume name:DRPMSAE207A0011, m_is_volume_clone:false

03/28-12:59:27.712                PID:1496  TID:620    volume_set.cpp@33                               Start volume_t::update_snapmirror_status(filer_t& filer)

03/28-12:59:27.712                PID:1496  TID:620    volume_set.cpp@63                               Finish volume_t::update_snapmirror_status(filer_t& filer)

03/28-12:59:27.712                PID:1496  TID:620    volume_set.cpp@106                             Start volume_t::update_snapvault_status(filer_t& filer)

03/28-12:59:27.712                PID:1496  TID:620    volume_set.cpp@136                             Finish volume_t::update_snapvault_status(filer_t& filer)

03/28-12:59:27.712                PID:1496  TID:620    volume_set.cpp@177                             Finish volume_t::update_functor::operator()(volume_t* p_volume)

03/28-12:59:27.712                PID:1496  TID:620    System.cpp@649                    CSystem::enumerate_virtual_disks: volume_set.modify(34, 192.91.36.123+192.132.84.101, DRPMSAE207A0011

03/28-12:59:27.712                PID:1496  TID:620    volume_set.cpp@141                             Start volume_t::update_functor::operator()(volume_t* p_volume)

03/28-12:59:27.712                PID:1496  TID:620    volume_set.cpp@14                               Start volume_t::update_cifs_share_name(filer_t& filer)

03/28-12:59:27.712                PID:1496  TID:620    VirtualDiskShare.cpp@2569                   Start get_cifs_share_name(192.132.84.101, DRPMSAE207A0011)

03/28-12:59:27.712                PID:1496  TID:620    VirtualDiskShare.cpp@998                     Start GetShareName(192.132.84.101, DRPMSAE207A0011)

03/28-12:59:27.712                PID:1496  TID:620    VirtualDiskShare.cpp@1006                   GetShareName: calling NetShareEnum

03/28-12:59:37.727                PID:1496  TID:620    VirtualDiskShare.cpp@1058                   GetShareName: did not find share the 1st time, try again...

03/28-12:59:37.727                PID:1496  TID:620    VirtualDiskShare.cpp@1070                   GetShareName: calling NetShareEnum

03/28-12:59:47.758                PID:1496  TID:620    VirtualDiskShare.cpp@1129                   Finish GetShareName: hr = 80070005

03/28-12:59:47.758                PID:1496  TID:620    VirtualDiskShare.cpp@2576                   Finish get_cifs_share_name()

03/28-12:59:47.758                PID:1496  TID:620    volume_set.cpp@27                               Finish volume_t::update_cifs_share_name(filer_t& filer)

03/28-12:59:47.758                PID:1496  TID:620    volume_set.cpp@68                               Start volume_t::update_volume_clone_status(filer_t& filer)

03/28-12:59:47.758                PID:1496  TID:620    volume_set.cpp@100                             Finish volume_t::update_volume_clone_status(filer_t& filer)-volume name:DRPMSAE207A0011, m_is_volume_clone:false

03/28-12:59:47.758                PID:1496  TID:620    volume_set.cpp@33                               Start volume_t::update_snapmirror_status(filer_t& filer)

03/28-12:59:47.758                PID:1496  TID:620    volume_set.cpp@63                               Finish volume_t::update_snapmirror_status(filer_t& filer)

03/28-12:59:47.758                PID:1496  TID:620    volume_set.cpp@106                             Start volume_t::update_snapvault_status(filer_t& filer)

03/28-12:59:47.758                PID:1496  TID:620    volume_set.cpp@136                             Finish volume_t::update_snapvault_status(filer_t& filer)

03/28-12:59:47.758                PID:1496  TID:620    volume_set.cpp@177                             Finish volume_t::update_functor::operator()(volume_t* p_volume)

Fast Enumerating server

03/28-12:57:27.548                PID:2128  TID:10336                System.cpp@649                    CSystem::enumerate_virtual_disks: volume_set.modify(32, 192.91.36.125+192.132.84.100, DRPMSAE207B0011

03/28-12:57:27.548                PID:2128  TID:10336                volume_set.cpp@141                             Start volume_t::update_functor::operator()(volume_t* p_volume)

03/28-12:57:27.548                PID:2128  TID:10336                volume_set.cpp@14                               Start volume_t::update_cifs_share_name(filer_t& filer)

03/28-12:57:27.548                PID:2128  TID:10336                VirtualDiskShare.cpp@2569                   Start get_cifs_share_name(192.132.84.100, DRPMSAE207B0011)

03/28-12:57:27.548                PID:2128  TID:10336                VirtualDiskShare.cpp@998                     Start GetShareName(192.132.84.100, DRPMSAE207B0011)

03/28-12:57:27.548                PID:2128  TID:10336                VirtualDiskShare.cpp@1006                   GetShareName: calling NetShareEnum

03/28-12:57:27.564                PID:2128  TID:10336                VirtualDiskShare.cpp@1058                   GetShareName: did not find share the 1st time, try again...

03/28-12:57:27.564                PID:2128  TID:10336                VirtualDiskShare.cpp@1070                   GetShareName: calling NetShareEnum

03/28-12:57:27.564                PID:2128  TID:10336                VirtualDiskShare.cpp@1129                   Finish GetShareName: hr = 800706bf

03/28-12:57:27.564                PID:2128  TID:10336                VirtualDiskShare.cpp@2576                   Finish get_cifs_share_name()

03/28-12:57:27.564                PID:2128  TID:10336                volume_set.cpp@27                               Finish volume_t::update_cifs_share_name(filer_t& filer)

03/28-12:57:27.564                PID:2128  TID:10336                volume_set.cpp@68                               Start volume_t::update_volume_clone_status(filer_t& filer)

03/28-12:57:27.564                PID:2128  TID:10336                volume_set.cpp@100                             Finish volume_t::update_volume_clone_status(filer_t& filer)-volume name:DRPMSAE207B0011, m_is_volume_clone:false

03/28-12:57:27.564                PID:2128  TID:10336                volume_set.cpp@33                               Start volume_t::update_snapmirror_status(filer_t& filer)

03/28-12:57:27.564                PID:2128  TID:10336                volume_set.cpp@63                               Finish volume_t::update_snapmirror_status(filer_t& filer)

03/28-12:57:27.564                PID:2128  TID:10336                volume_set.cpp@106                             Start volume_t::update_snapvault_status(filer_t& filer)

03/28-12:57:27.564                PID:2128  TID:10336                volume_set.cpp@136                             Finish volume_t::update_snapvault_status(filer_t& filer)

03/28-12:57:27.564                PID:2128  TID:10336                volume_set.cpp@177                             Finish volume_t::update_functor::operator()(volume_t* p_volume)

03/28-12:57:27.564                PID:2128  TID:10336                System.cpp@649                    CSystem::enumerate_virtual_disks: volume_set.modify(33, 192.91.36.125+192.132.84.100, DRPMSAE207B0011

03/28-12:57:27.564                PID:2128  TID:10336                volume_set.cpp@141                             Start volume_t::update_functor::operator()(volume_t* p_volume)

03/28-12:57:27.564                PID:2128  TID:10336                volume_set.cpp@14                               Start volume_t::update_cifs_share_name(filer_t& filer)

03/28-12:57:27.564                PID:2128  TID:10336                VirtualDiskShare.cpp@2569                   Start get_cifs_share_name(192.132.84.100, DRPMSAE207B0011)

03/28-12:57:27.564                PID:2128  TID:10336                VirtualDiskShare.cpp@998                     Start GetShareName(192.132.84.100, DRPMSAE207B0011)

03/28-12:57:27.564                PID:2128  TID:10336                VirtualDiskShare.cpp@1006                   GetShareName: calling NetShareEnum

03/28-12:57:27.580                PID:2128  TID:10336                VirtualDiskShare.cpp@1058                   GetShareName: did not find share the 1st time, try again...

03/28-12:57:27.580                PID:2128  TID:10336                VirtualDiskShare.cpp@1070                   GetShareName: calling NetShareEnum

03/28-12:57:27.595                PID:2128  TID:10336                VirtualDiskShare.cpp@1129                   Finish GetShareName: hr = 800706bf

03/28-12:57:27.595                PID:2128  TID:10336                VirtualDiskShare.cpp@2576                   Finish get_cifs_share_name()

03/28-12:57:27.595                PID:2128  TID:10336                volume_set.cpp@27                               Finish volume_t::update_cifs_share_name(filer_t& filer)

03/28-12:57:27.595                PID:2128  TID:10336                volume_set.cpp@68                               Start volume_t::update_volume_clone_status(filer_t& filer)

03/28-12:57:27.595                PID:2128  TID:10336                volume_set.cpp@100                             Finish volume_t::update_volume_clone_status(filer_t& filer)-volume name:DRPMSAE207B0011, m_is_volume_clone:false

03/28-12:57:27.595                PID:2128  TID:10336                volume_set.cpp@33                               Start volume_t::update_snapmirror_status(filer_t& filer)

03/28-12:57:27.595                PID:2128  TID:10336                volume_set.cpp@63                               Finish volume_t::update_snapmirror_status(filer_t& filer)

03/28-12:57:27.595                PID:2128  TID:10336                volume_set.cpp@106                             Start volume_t::update_snapvault_status(filer_t& filer)

03/28-12:57:27.595                PID:2128  TID:10336                volume_set.cpp@136                             Finish volume_t::update_snapvault_status(filer_t& filer)

03/28-12:57:27.595                PID:2128  TID:10336                volume_set.cpp@177                             Finish volume_t::update_functor::operator()(volume_t* p_volume)

03/28-12:57:27.595                PID:2128  TID:10336                System.cpp@649                    CSystem::enumerate_virtual_disks: volume_set.modify(34, 192.91.36.125+192.132.84.100, DRPMSAE207B0011

03/28-12:57:27.595                PID:2128  TID:10336                volume_set.cpp@141                             Start volume_t::update_functor::operator()(volume_t* p_volume)

03/28-12:57:27.595                PID:2128  TID:10336                volume_set.cpp@14                               Start volume_t::update_cifs_share_name(filer_t& filer)

03/28-12:57:27.595                PID:2128  TID:10336                VirtualDiskShare.cpp@2569                   Start get_cifs_share_name(192.132.84.100, DRPMSAE207B0011)

03/28-12:57:27.595                PID:2128  TID:10336                VirtualDiskShare.cpp@998                     Start GetShareName(192.132.84.100, DRPMSAE207B0011)

03/28-12:57:27.595                PID:2128  TID:10336                VirtualDiskShare.cpp@1006                   GetShareName: calling NetShareEnum

03/28-12:57:27.595                PID:2128  TID:10336                VirtualDiskShare.cpp@1058                   GetShareName: did not find share the 1st time, try again...

03/28-12:57:27.595                PID:2128  TID:10336                VirtualDiskShare.cpp@1070                   GetShareName: calling NetShareEnum

03/28-12:57:27.611                PID:2128  TID:10336                VirtualDiskShare.cpp@1129                   Finish GetShareName: hr = 800706bf

03/28-12:57:27.611                PID:2128  TID:10336                VirtualDiskShare.cpp@2576                   Finish get_cifs_share_name()

03/28-12:57:27.611                PID:2128  TID:10336                volume_set.cpp@27                               Finish volume_t::update_cifs_share_name(filer_t& filer)

03/28-12:57:27.611                PID:2128  TID:10336                volume_set.cpp@68                               Start volume_t::update_volume_clone_status(filer_t& filer)

03/28-12:57:27.611                PID:2128  TID:10336                volume_set.cpp@100                             Finish volume_t::update_volume_clone_status(filer_t& filer)-volume name:DRPMSAE207B0011, m_is_volume_clone:false

03/28-12:57:27.611                PID:2128  TID:10336                volume_set.cpp@33                               Start volume_t::update_snapmirror_status(filer_t& filer)

03/28-12:57:27.611                PID:2128  TID:10336                volume_set.cpp@63                               Finish volume_t::update_snapmirror_status(filer_t& filer)

03/28-12:57:27.611                PID:2128  TID:10336                volume_set.cpp@106                             Start volume_t::update_snapvault_status(filer_t& filer)

03/28-12:57:27.611                PID:2128  TID:10336                volume_set.cpp@136                             Finish volume_t::update_snapvault_status(filer_t& filer)

03/28-12:57:27.611                PID:2128  TID:10336                volume_set.cpp@177                             Finish volume_t::update_functor::operator()(volume_t* p_volume)

Any help would be very appreciated

[aborzenkov]

Did you configure SnapDrvie to use the same protocol (RPC, HTTP(S)) on all servers?

[thierry]

Yes,

All servers are configured to use HTTPS.

/T

[tyrone_owen_1]

I seem to be having the same problem on multiple Windows 2008 R2 SP1 boxes

I'm alos using Snapdrive6.3.1R1 (RPC) with preferred IPs set

Did you make any progress?

[brauntvr2swiss]

Hi

I would recommend you to plan an update to snapdrive 6.4.. Its much faster, than the previous Version of snapdrive.

We have few Windows 2008 R2  Clusters and since SD 6.4 Lun Enumeration is very fast...

regards,

Thomas

[thierry]

Correct.

Upgrading to the Snapdrive 6.4 release fixed those too long disk enumerating time.

Please consider upgrading your current release.

Regards

[tyrone_owen_1]

Thought I'd quickly post back as I've had a bit of a discovery.

I used SD 6.3.1R1 to mount a snapshot from one of my T2 storage boxes and it was really quick - this is the first time I've carried out this activity. I made an assumption that SD 6.3.1R1 was the issue, but it looks like that isn't the case. When I solve the issue I'll update the post.

Thanks

[ashleycook]

Any issues with DNS?

I've seen enumeration take an excessive amount of time in the past when the host has been unable to resolve the storage system name, even though SnapDrive is attempting to connect to the IP address.

Might be worth entering the addresses in the hosts file to test.

[tyrone_owen_1]

Mr Cook, how are you?

I thought it may have been name resolution when I first started having the issues so tried the local hosts file with no joy.

Two out of six storage controllers are having issues. I've compared VIF configurations which look fine, so I've asked the comms guys to gte involved.

Cheers

[brooksindc]

once the disks finally enumerate.  (right click disk) or go to disk properties in snapdrive.  look for the preferred storage tab and fill in your preferred storage list and IP.

Next time you enumerate....the disk will come up very quickly.