Cannot synchronize after Blackout Virtual SAN Free

Software-based VM-centric and flash-friendly VM storage + free version

Moderators: anton (staff), art (staff), Max (staff), Anatoly (staff)

Post Reply
sebsom
Posts: 2
Joined: Sat May 25, 2024 7:35 pm

Sat May 25, 2024 7:57 pm

Hi there,
I've searched a lot but cannot find a solution for my Problem.

After a blackout I cannot synchonize my nodes. When I use the script syncHaDevice I get the error

Code: Select all

 .\SyncHaDevice.ps1
Synchronize device HAImage1
Failed to perform synchronization (1) from
-
control 0x0000023797FF6400 -Synchronize: -SynchronizationType:"1"
-
200 Failed: can't find available or valid partner for synchronization..
It would be nice if anybody has an idea how to get it back online!

Log:

Code: Select all

5/25 20:13:09.345165 1530 Srv: StarWind Virtual SAN v8.0.0 (Build 15159, [SwSAN], Win64)
5/25 20:13:09.345226 1530 Srv: Built Jun  2 2023 14:29:14
5/25 20:13:09.345250 1530 Srv: PID 6200
5/25 20:13:09.345452 1530 Srv: Windows Server 2022 Standard Edition (v10.0 Build 20348)
5/25 20:13:09.345503 1530 Srv: Processor packages/cores/logical: 1/8/16
5/25 20:13:09.440094 1530 Srv: Config file: 'StarWind.cfg'
5/25 20:13:09.479704 1530 General: DllMain: NetDirect providers are not found.
5/25 20:13:09.479785 1530 Srv: *** iScsiServer::iScsiServer: iSER_DM is not loaded.
5/25 20:13:09.487762 1530 conf: 'LogLevel' = '1'
5/25 20:13:09.487785 1530 conf: 'LogMask' = '0xbfffffffffffffff'
5/25 20:13:09.487800 1530 conf: 'LogRotateSize' = '100'
5/25 20:13:09.487818 1530 conf: 'LogRotateKeepLastFiles' = '20'
5/25 20:13:09.487836 1530 conf: 'UpdatePeriod' = '7'
5/25 20:13:09.487850 1530 conf: 'UpdateHost' = 'www.starwindsoftware.com'
5/25 20:13:09.487867 1530 conf: 'UpdatePage' = '/updatetracker/index.php'
5/25 20:13:09.487884 1530 conf: 'UpdatePort' = '80'
5/25 20:13:09.487908 1530 conf: 'UpdateCopyId' = '90D938A6-9D7B-466F-8E02-F772B72B2986'
5/25 20:13:09.487923 1530 conf: 'UpdateLastRequest' = '20240520'
5/25 20:13:09.487936 1530 conf: 'WUSCEnabled' = 'yes'
5/25 20:13:09.487950 1530 conf: 'SrvRestoreStartType' = '3'
5/25 20:13:09.487965 1530 conf: 'SrvWasDisabled' = 'yes'
5/25 20:13:09.487978 1530 conf: 'VaaiExCopyEnabled' = 'yes'
5/25 20:13:09.487992 1530 conf: 'VaaiCawEnabled' = 'yes'
5/25 20:13:09.488006 1530 conf: 'VaaiWriteSameEnabled' = 'yes'
5/25 20:13:09.488016 1530 conf: 'OdxEnabled' = 'no'
5/25 20:13:09.488030 1530 conf: 'OdxOptimalRodSizeMB' = '64'
5/25 20:13:09.488041 1530 conf: 'OdxMaximumRodSizeMB' = '256'
5/25 20:13:09.488053 1530 conf: 'OdxRodTokenDefaultTimeoutSec' = '10'
5/25 20:13:09.488066 1530 conf: 'OdxRodTokenMaximumTimeoutSec' = '30'
5/25 20:13:09.488079 1530 conf: 'Port' = '3260'
5/25 20:13:09.488092 1530 conf: 'Interface' = '0.0.0.0'
5/25 20:13:09.488105 1530 conf: 'BCastEnable' = 'yes'
5/25 20:13:09.488118 1530 conf: 'BCastInterface' = '0.0.0.0'
5/25 20:13:09.488128 1530 conf: 'BCastPort' = '3261'
5/25 20:13:09.488139 1530 conf: 'Login' = 'root'
5/25 20:13:09.488150 1530 conf: 'Password' = '##evVRsIJtRmAEEd2sCslZDg=='
5/25 20:13:09.488163 1530 conf: 'MinBufferSize' = '65536'
5/25 20:13:09.488176 1530 conf: 'AlignmentMask' = '0x0000'
5/25 20:13:09.488186 1530 conf: 'MaxPendingRequests' = '256'
5/25 20:13:09.488197 1530 conf: 'iScsiPingPeriod' = '0'
5/25 20:13:09.488211 1530 conf: 'iScsiDiscoveryListInterfaces' = '0'
5/25 20:13:09.488221 1530 conf: 'ServerIoWorkersCount' = '0'
5/25 20:13:09.488232 1530 conf: 'ServerIoWorkersConcurency' = '0'
5/25 20:13:09.488245 1530 conf: 'iSerListen' = ''
5/25 20:13:09.488258 1530 conf: 'LocalizationDir' = 'Localizations'
5/25 20:13:09.488271 1530 conf: 'DefaultStoragePoolPath' = 'My Computer\D'
5/25 20:13:09.488282 1530 conf: 'ClusterName' = ''
5/25 20:13:09.488292 1530 conf: 'ClusterGUID' = ''
5/25 20:13:09.488303 1530 conf: 'ClusterSettingsVersion' = '0'
5/25 20:13:09.488314 1530 conf: 'ClusterNodes' = ''
5/25 20:13:09.488326 1530 conf: 'ClusterSync' = ''
5/25 20:13:09.488337 1530 conf: 'ClusterHeartbeat' = ''
5/25 20:13:09.488350 1530 conf: 'DataBaseRoot' = '.\NotifyDB'
5/25 20:13:09.488362 1530 conf: 'DBRotationDays' = '5'
5/25 20:13:09.488373 1530 conf: 'DBFileSizeDays' = '1'
5/25 20:13:09.488384 1530 conf: 'PerformanceMonitorEnabled' = 'yes'
5/25 20:13:09.488397 1530 conf: 'PerformanceRoot' = '.\PerformanceDB'
5/25 20:13:09.488410 1530 conf: 'FSMThresholdPercent' = '30'
5/25 20:13:09.488420 1530 conf: 'FSMCheckPeriodSeconds' = '30'
5/25 20:13:09.488432 1530 conf: 'FSMEnabled' = 'yes'
5/25 20:13:09.488468 1530 conf: read command: addimagedir -path:"*" -flags:"cdmfv" -alias:"My Computer" -extensions:"*" 
5/25 20:13:09.488505 1530 conf: read command: addimagedir -path:"*" -flags:"cdmfv" -alias:"Image Files" -extensions:"img,dat" 
5/25 20:13:09.488530 1530 conf: read command: addimagedir -path:"*" -flags:"cmdfv" -alias:"VTLs" -extensions:"swdsk" 
5/25 20:13:09.488599 1530 conf: read command: addimagedir -path:"*" -flags:"cmdfv" -alias:"VTapes" -extensions:"VTape" 
5/25 20:13:09.488629 1530 conf: read command: addimagedir -path:"*" -flags:"cdmfv" -alias:"Event Logs" -extensions:"txt,log" 
5/25 20:13:09.488660 1530 conf: read command: addimagedir -path:"*" -flags:"cdmfv" -alias:"Headers" -extensions:"swdsk" 
5/25 20:13:09.488702 1530 conf: read command: reaction -maskSeverity:"14" -maskCode:"-1" -type:"eventlog" 
5/25 20:13:09.488759 1530 conf: read command: addplugin -module:"RamDisk.dll" -symlink:"RamDrive" -type:"RAM disk" 
5/25 20:13:09.488855 1530 conf: read command: addplugin -module:"ImageFile.dll" -symlink:"ImageFile" -type:"Image file" -imagedir:"*|cmdfv|My Computer|img,swdsk" -volumes:"no" -QueueFlags:"0" -QueueWorkersCount:"0" -QueueWorkersActive:"0" -CacheFlags:"0" -L2CacheFlags:"0" -ReqExecTimeLogWarningLimitInSec:"3" 
5/25 20:13:09.488907 1530 conf: read command: addplugin -module:"VirtualDvd.dll" -symlink:"VirtualDvd" -type:"Virtual DVD" -imagedir:"*|mv|My Computer|mds,iso" 
5/25 20:13:09.488946 1530 conf: read command: addplugin -module:"DiskBridge.dll" -symlink:"DiskBridge" -type:"DiskBridge" 
5/25 20:13:09.489093 1530 conf: read command: addplugin -module:"HAImage.dll" -symlink:"HAImage" -type:"HA Image" -imagedir:"*|cmdfv|My Computer|img,swdsk,swcbt" -imagedir:"*|cdmfv|Headers|swdsk" -imagedir:"Device Headers|cdmfv|DefaultHeaderPath|swdsk" -transport:"auto" -rpl_threshold:"4" -node_shutdown_type:"close_clients_conn" -MaxSyncQueueSize:"16" -StorPerfDegTimeLimitMs:"7000" -StorPerfDegDetectPeriodMin:"3" -ReqExecTimeWarningLimitInSec:"10" -iScsiGenCmdSendCmdTimeoutInSec:"10" -iScsiPingCmdSendCmdTimeoutInSec:"5" -iScsiPingCmdSendCmdPeriodInSec:"1" -iScsiConnectRetryPeriodInSec:"5" -iScsiDisconnectRetryPeriodInSec:"1" -UnderlyingStorageTimeoutInSec:"60" 
5/25 20:13:09.489212 1530 conf: read command: addplugin -module:"VTL.dll" -symlink:"VTL" -type:"VTL" -LogLevel:"1" -replicator:"119" -closedatafiles:"yes" -linuxpath:"/opt/StarWind/StarWindVSA" -imagedir:"*|cmdfv|My Computer|swdsk" -imagedir:"*|cmdfv|VTapes|VTape" -imagedir:"VTL\|cmdfv|Patterns|VTLP" 
5/25 20:13:09.489299 1530 conf: read command: addplugin -module:"SysMan.dll" -symlink:"SysMan" -type:"System Manager" -deduplicationmanager:"no" -deploymenttasks:"no" -LogLevel:"1" 
5/25 20:13:09.489373 1530 conf: read command: addplugin -module:"NVMfTarget.dll" -symlink:"NVMfTarget" -type:"NVMf Target" -imagedir:"*|cmdfv|My Computer|img,conf" -volumes:"no" 
5/25 20:13:09.489415 1530 conf: read command: add "imagefile1" -file:"My computer\D\starwind\quorum-image-n2.swdsk" 
5/25 20:13:09.489443 1530 conf: read command: add "HAImage1" -OwnTargetName:"iqn.2008-08.com.starwindsoftware:hv02-quorum-target-n2" -file:"My computer\D\starwind\quorum-image-n2_HA.swdsk" -serialId:"06E18C60C0F811B3" -asyncmode:"yes" -readonly:"no" -highavailability:"yes" -buffering:"no" -header:"65536" -reservation:"no" -CacheMode:"wb" -CacheSizeMB:"128" -Storage:"imagefile1" 
5/25 20:13:09.489475 1530 conf: read command: add "imagefile2" -file:"My computer\D\starwind\storage-image-n2.swdsk" 
5/25 20:13:09.489505 1530 conf: read command: add "HAImage2" -OwnTargetName:"iqn.2008-08.com.starwindsoftware:hv02-storage-target-n2" -file:"My computer\D\starwind\storage-image-n2_HA.swdsk" -serialId:"3CE74B0D41DF5092" -asyncmode:"yes" -readonly:"no" -highavailability:"yes" -buffering:"no" -header:"65536" -reservation:"no" -CacheMode:"wb" -CacheSizeMB:"128" -Storage:"imagefile2" 
5/25 20:13:09.489545 1530 conf: read command: addtarget "iqn.2008-08.com.starwindsoftware:hv02-quorum-target-n2" -alias:"quorum-target-n2" -devices:"HAImage1" 
5/25 20:13:09.489572 1530 conf: read command: addtarget "iqn.2008-08.com.starwindsoftware:hv02-storage-target-n2" -alias:"storage-target-n2" -devices:"HAImage2" 
5/25 20:13:09.489617 1530 conf: 'DefaultAccessPolicy' = 'allow'
5/25 20:13:09.489636 1530 conf: Variable 'LogLevel' is set to '1'.
5/25 20:13:09.489642 1530 conf: Variable 'LogMask' is set to '0xbfffffffffffffff'.
5/25 20:13:09.489675 1530 conf: Variable 'LogRotateSize' is set to '100'.
Delete log file 'logs\starwind-20230823-135339.log'.
5/25 20:13:09.490538 1530 conf: Variable 'LogRotateKeepLastFiles' is set to '20'.
5/25 20:13:09.490552 1530 conf: Variable 'UpdatePeriod' is set to '7'.
5/25 20:13:09.490557 1530 conf: Variable 'UpdateHost' is set to 'www.starwindsoftware.com'.
5/25 20:13:09.490564 1530 conf: Variable 'UpdatePage' is set to '/updatetracker/index.php'.
5/25 20:13:09.490572 1530 conf: Variable 'UpdatePort' is set to '80'.
5/25 20:13:09.490580 1530 conf: Variable 'UpdateCopyId' is set to '90D938A6-9D7B-466F-8E02-F772B72B2986'.
5/25 20:13:09.490588 1530 conf: Variable 'UpdateLastRequest' is set to '20240520'.
5/25 20:13:09.490594 1530 conf: Variable 'WUSCEnabled' is set to 'yes'.
5/25 20:13:09.490602 1530 conf: Variable 'SrvRestoreStartType' is set to '3'.
5/25 20:13:09.490609 1530 conf: Variable 'SrvWasDisabled' is set to 'yes'.
5/25 20:13:09.490613 1530 conf: Variable 'VaaiExCopyEnabled' is set to 'yes'.
5/25 20:13:09.490620 1530 conf: Variable 'VaaiCawEnabled' is set to 'yes'.
5/25 20:13:09.490625 1530 conf: Variable 'VaaiWriteSameEnabled' is set to 'yes'.
5/25 20:13:09.490629 1530 conf: Variable 'OdxEnabled' is set to 'no'.
5/25 20:13:09.490636 1530 conf: Variable 'OdxOptimalRodSizeMB' is set to '64'.
5/25 20:13:09.490641 1530 conf: Variable 'OdxMaximumRodSizeMB' is set to '256'.
5/25 20:13:09.490648 1530 conf: Variable 'OdxRodTokenDefaultTimeoutSec' is set to '10'.
5/25 20:13:09.490655 1530 conf: Variable 'OdxRodTokenMaximumTimeoutSec' is set to '30'.
5/25 20:13:09.490662 1530 conf: Variable 'Port' is set to '3260'.
5/25 20:13:09.490668 1530 conf: Variable 'Interface' is set to '0.0.0.0'.
5/25 20:13:09.490675 1530 conf: Variable 'BCastEnable' is set to 'yes'.
5/25 20:13:09.490682 1530 conf: Variable 'BCastInterface' is set to '0.0.0.0'.
5/25 20:13:09.490687 1530 conf: Variable 'BCastPort' is set to '3261'.
5/25 20:13:09.490691 1530 conf: Variable 'Login' is set to 'root'.
5/25 20:13:09.490696 1530 conf: Variable 'Password' is set to '##evVRsIJtRmAEEd2sCslZDg=='.
5/25 20:13:09.490703 1530 conf: Variable 'MinBufferSize' is set to '65536'.
5/25 20:13:09.490710 1530 conf: Variable 'AlignmentMask' is set to '0x0000'.
5/25 20:13:09.490714 1530 conf: Variable 'MaxPendingRequests' is set to '256'.
5/25 20:13:09.490719 1530 conf: Variable 'iScsiPingPeriod' is set to '0'.
5/25 20:13:09.490726 1530 conf: Variable 'iScsiDiscoveryListInterfaces' is set to '0'.
5/25 20:13:09.490731 1530 conf: Variable 'ServerIoWorkersCount' is set to '0'.
5/25 20:13:09.490736 1530 conf: Variable 'ServerIoWorkersConcurency' is set to '0'.
5/25 20:13:09.490743 1530 conf: Variable 'iSerListen' is set to ''.
5/25 20:13:09.490750 1530 conf: Variable 'LocalizationDir' is set to 'Localizations'.
5/25 20:13:09.490757 1530 conf: Variable 'DefaultStoragePoolPath' is set to 'My Computer\D'.
5/25 20:13:09.490762 1530 conf: Variable 'ClusterName' is set to ''.
5/25 20:13:09.490767 1530 conf: Variable 'ClusterGUID' is set to ''.
5/25 20:13:09.490772 1530 conf: Variable 'ClusterSettingsVersion' is set to '0'.
5/25 20:13:09.490777 1530 conf: Variable 'ClusterNodes' is set to ''.
5/25 20:13:09.490783 1530 conf: Variable 'ClusterSync' is set to ''.
5/25 20:13:09.490788 1530 conf: Variable 'ClusterHeartbeat' is set to ''.
5/25 20:13:09.490796 1530 conf: Variable 'DataBaseRoot' is set to '.\NotifyDB'.
5/25 20:13:09.490802 1530 conf: Variable 'DBRotationDays' is set to '5'.
5/25 20:13:09.490807 1530 conf: Variable 'DBFileSizeDays' is set to '1'.
5/25 20:13:09.490812 1530 conf: Variable 'PerformanceMonitorEnabled' is set to 'yes'.
5/25 20:13:09.490818 1530 conf: Variable 'PerformanceRoot' is set to '.\PerformanceDB'.
5/25 20:13:09.490825 1530 conf: Variable 'FSMThresholdPercent' is set to '30'.
5/25 20:13:09.490830 1530 conf: Variable 'FSMCheckPeriodSeconds' is set to '30'.
5/25 20:13:09.490835 1530 conf: Variable 'FSMEnabled' is set to 'yes'.
5/25 20:13:09.490839 1530 EventDB: CEventDataBase::Init: wsRootDir = .\NotifyDB
5/25 20:13:09.490852 1530 EventDB: CEventDataBase::InternalInit: wsRootDir = .\NotifyDB
5/25 20:13:09.538146 1530 Srv: StarWindService::checkWorkingSet: Process working set: minimum 204800, maximum 1413120, flags 0xa
5/25 20:13:09.538177 1530 Srv: iScsiServer::additionalWorkingSet: New working set min: 67313664, max: 68521984, flags: 0x9
5/25 20:13:09.538190 1530 Srv: iScsiServer::startWorkers: ServerNodesPerNumaNode = 1
5/25 20:13:09.538194 1530 Srv: iScsiServer::startWorkers: Worker threads per server node: total 8, active 8
5/25 20:13:09.538201 1530 Srv: SwServerNode::SwServerNode: Node 0: NUMA node 0 (16 cores)
5/25 20:13:09.538209 1530 Srv: iScsiServer::startWorkers: ServerDefaultNode = 0
5/25 20:13:09.538222 1530 Srv: SwThreadPool::start: TP[0]: preparing 8 worker threads (8 active)...
5/25 20:13:09.538365 cac Srv: SwThreadPool::workerThread: TP[0]: worker started at cpu 9 (numa 0, mask 0xaaaa), maxEntries 1, priority: 0.
5/25 20:13:09.538439 14c4 Srv: SwThreadPool::workerThread: TP[0]: worker started at cpu 1 (numa 0, mask 0xaaaa), maxEntries 1, priority: 0.
5/25 20:13:09.538482 1494 Srv: SwThreadPool::workerThread: TP[0]: worker started at cpu 5 (numa 0, mask 0xaaaa), maxEntries 1, priority: 0.
5/25 20:13:09.538500 11b8 Srv: SwThreadPool::workerThread: TP[0]: worker started at cpu 1 (numa 0, mask 0xaaaa), maxEntries 1, priority: 0.
5/25 20:13:09.538571 13a8 Srv: SwThreadPool::workerThread: TP[0]: worker started at cpu 9 (numa 0, mask 0xaaaa), maxEntries 1, priority: 0.
5/25 20:13:09.538614 618 Srv: SwThreadPool::workerThread: TP[0]: worker started at cpu 3 (numa 0, mask 0xaaaa), maxEntries 1, priority: 0.
5/25 20:13:09.538708 1c40 Srv: SwThreadPool::workerThread: TP[0]: worker started at cpu 13 (numa 0, mask 0xaaaa), maxEntries 1, priority: 0.
5/25 20:13:09.538748 1728 Srv: SwThreadPool::workerThread: TP[0]: worker started at cpu 15 (numa 0, mask 0xaaaa), maxEntries 1, priority: 0.
5/25 20:13:09.538924 1530 Srv: Licensed to: 'Sebastian Woeckener', 'DOCComputer GmbH', (#2, 0, 0).
5/25 20:13:09.568027 1530 conf: ServerSetup::ApplyLicense: License has a FREE flag.
5/25 20:13:09.568052 1530 Srv: Unlimited number of client hosts allowed.
5/25 20:13:09.568079 1530 conf: *** ServerSetup::CheckSptd: Unable to detect SPTD.
5/25 20:13:09.568097 1530 FileBrowser: CFileBrowser::addImageDir: Directory loaded: *|cdmfv|My Computer|*
5/25 20:13:09.568108 1530 FileBrowser: CFileBrowser::addImageDir: Directory loaded: *|cdmfv|Image Files|img,dat
5/25 20:13:09.568117 1530 FileBrowser: CFileBrowser::addImageDir: Directory loaded: *|cmdfv|VTLs|swdsk
5/25 20:13:09.568123 1530 FileBrowser: CFileBrowser::addImageDir: Directory loaded: *|cmdfv|VTapes|VTape
5/25 20:13:09.568131 1530 FileBrowser: CFileBrowser::addImageDir: Directory loaded: *|cdmfv|Event Logs|txt,log
5/25 20:13:09.568138 1530 FileBrowser: CFileBrowser::addImageDir: Directory loaded: *|cdmfv|Headers|swdsk
5/25 20:13:09.602600 1530 General: SscPort_Init: (build 15159, built Jun  2 2023 14:27:56)
	VendorId  = '        '
	ProductId = '                '
	Revision  = '0001'
5/25 20:13:09.602983 1530 conf: ConfCommand::processNew: 'RamDisk.dll' loaded successfully.
5/25 20:13:09.682881 1530 IMG: SscPort_Init: (build 15159, built Jun  2 2023 14:27:25)
	VendorId  = '        '
	ProductId = '                '
	Revision  = '0001'
	Volumes   = 0
5/25 20:13:09.683776 1530 conf: ConfCommand::processNew: 'ImageFile.dll' loaded successfully.
5/25 20:13:09.684504 1530 conf: ConfCommand::processNew: 'VirtualDvd.dll' loaded successfully.
5/25 20:13:09.716020 1530 General: SscPort_Init: (built Jun  2 2023 14:28:01)
	VendorId  = '        '
	ProductId = '                '
	Revision  = '0001'
	ExeDir    = 'C:\Program Files\StarWind Software\StarWind\'
5/25 20:13:09.716309 1530 conf: ConfCommand::processNew: 'DiskBridge.dll' loaded successfully.
5/25 20:13:09.762414 1530 HA: SscPort_InitEx: OS major version more then 5, then will be used internal transport.
5/25 20:13:09.762507 1530 HA: SscPort_InitEx: (build 15159, built Jun  2 2023 14:28:20)
	VendorId  = '        '
	ProductId = '                '
	Revision  = '0001'
	DefImageDir  = '*\'
	Volumes   = 0
	ExeDir    = 'C:\Program Files\StarWind Software\StarWind\'
5/25 20:13:09.762580 1530 HA: HANode::initializeModule: Params(callback = 0x00007FF63FD02870, pluginHandle = 0x000001D0B9446040, scsiTransportType = 3, nodeShutdownType = close_connections, syncQueueSize = 16, storPerfDegTimeLimitMs = 7000, storPerfDegDetectPeriodMin = 3, m_cmdExecTimeWarningLimitInSec = 10, m_autoSyncPeriodForPerfDegInMin = 30, m_autoSyncPeriodForStorIoErrorInHours = 24, m_iscsiGenCmdSendTimeoutInSec = 10, m_iscsiPingCmdSendTimeoutInSec = 5, m_iscsiPingCmdSendPeriodInSec = 1, m_iscsiConnectRetryPeriodInSec = 5, m_iscsiDisconnectRetryPeriodInSec = 1, m_underlyingStorageTimeoutInSec = 60) ENTERed
5/25 20:13:09.799918 1530 General: DllMain: NetDirect providers are not found.
5/25 20:13:09.800034 1530 conf: ConfCommand::processNew: 'HAImage.dll' loaded successfully.
5/25 20:13:09.841179 1530 conf: ConfCommand::processNew: 'VTL.dll' loaded successfully.
5/25 20:13:09.841998 1530 Plugin: SscPort_InitEx: (build 15159, built Jun  2 2023 14:27:06)
	VendorId  = '        '
	ProductId = '                '
	Revision  = '0001'
	ExeDir    = 'C:\Program Files\StarWind Software\StarWind\'
5/25 20:13:09.842039 1530 Plugin: CSysMan::InitializeModule: Params(p_pCallback = 0x00007FF63FD02870, p_hPluginHandle = 0x000001D0B9446180) ENTERed
5/25 20:13:09.842954 1530 conf: ConfCommand::processNew: 'SysMan.dll' loaded successfully.
5/25 20:13:09.882950 1530 conf: ConfCommand::processNew: 'NVMfTarget.dll' loaded successfully.
5/25 20:13:09.892482 1530 SCHED: Sw_Scheduler::open: The Scheduler is starting.
5/25 20:13:09.892535 1530 conf: Variable 'DefaultAccessPolicy' is set to 'allow'.
5/25 20:13:09.892556 1530 Common: sw_common::Sw_Disk_Header::open: (file: D:\starwind\quorum-image-n2_HA.swdsk, readonly: no).
5/25 20:13:09.898319 1530 Common: sw_common::Sw_Disk_Header::open: (file: D:\starwind\storage-image-n2_HA.swdsk, readonly: no).
5/25 20:13:09.903164 1530 Common: sw_common::Sw_Disk_Header::open: (file: D:\starwind\quorum-image-n2.swdsk, readonly: no).
5/25 20:13:09.907532 1530 Common: sw_common::Sw_Disk_Header::open: (file: D:\starwind\quorum-image-n2.swdsk, readonly: no).
5/25 20:13:09.907753 1728 SCSI: : parameter 'DeviceHeaderPath', value 'My computer\D\starwind\quorum-image-n2.swdsk'.
5/25 20:13:09.907788 1728 SCSI: : parameter 'file', value 'My computer\D\starwind\quorum-image-n2.swdsk'.
5/25 20:13:09.907819 1728 IMG: SscPort_Create: Parsing parameters from control connection: 
5/25 20:13:09.907849 1728 IMG: SscPort_Create: Header path parsed to 'D:\starwind\quorum-image-n2.swdsk'.
5/25 20:13:09.907870 1728 IMG: addParameter: Parameter processed (add): DeviceHeaderPathPhysical = "D:\starwind\quorum-image-n2.swdsk"
5/25 20:13:09.907880 1728 IMG: addParameter: Parameter processed (add): file = "My computer\D\starwind\quorum-image-n2.swdsk"
5/25 20:13:09.907889 1728 Common: sw_common::Sw_Disk_Header::open: (file: D:\starwind\quorum-image-n2.swdsk, readonly: no).
5/25 20:13:09.908234 1728 IMG: SscPort_Create: Parsing the Device Header File 'D:\starwind\quorum-image-n2.swdsk':
5/25 20:13:09.908395 1728 IMG: addParameter: Parameter processed (update): file = "My computer\D\starwind\quorum-image-n2.swdsk" -> "My computer\D\starwind\quorum-image-n2.img"
5/25 20:13:09.908459 1728 IMG: addParameter: Parameter processed (add): CacheMode = "wb"
5/25 20:13:09.908466 1728 IMG: addParameter: Parameter processed (add): CacheFlags = "0"
5/25 20:13:09.908473 1728 IMG: addParameter: Parameter processed (add): CacheBlockExpiryPeriodMS = "0"
5/25 20:13:09.908479 1728 IMG: addParameter: Parameter processed (add): CacheSizeMB = "128"
5/25 20:13:09.908488 1728 IMG: addParameter: Parameter processed (add): SerialId = "29F77B6A437CDC04"
5/25 20:13:09.908495 1728 IMG: addParameter: Parameter processed (add): eui64 = "29F77B6A437CDC04"
5/25 20:13:09.908512 1728 IMG: addParameter: Parameter processed (update): SerialId = "29F77B6A437CDC04" -> "29F77B6A437CDC04"
5/25 20:13:09.908520 1728 IMG: addParameter: Parameter processed (update): eui64 = "29F77B6A437CDC04" -> "29F77B6A437CDC04"
5/25 20:13:09.908593 1728 IMG: SscPort_Create: Opening device 'imagefile1', image file 'My computer\D\starwind\quorum-image-n2.img', buffering=0, async=1, readonly=0.
5/25 20:13:10.235745 1728 debug: Swn_CreateFile: volume name 'D:'.
5/25 20:13:10.235837 1728 debug: *** GetVolumeProperties: \\.\D:: StorageDeviceTrimProperty failed (error 1).
5/25 20:13:10.235876 1728 IMG: ImageFile_Create: 'D:\starwind\quorum-image-n2.img': type 0, geometry: sct 16, trks 32, cyl 40960, TotalSectors: 20971520, SectorSize: 512, PhySectorSize: 4096
5/25 20:13:10.235887 1728 IMG: ImageFile_Create: VendorId 'STARWIND', ProductId 'STARWIND        ', Revision '0001', Serial '29F77B6A437CDC04'
5/25 20:13:10.235938 1728 Cache: StarWind Virtual SAN v8.0.0 (Build 15159, [SwSAN], Win64)
5/25 20:13:10.235946 1728 Cache: Jun  2 2023 14:26:48
5/25 20:13:10.236011 1728 Cache: CacheBase::init: Cache parameters: Mode = 1, Flags = 0, Size = 128 MB, SectorSize = 512, BlockExpiryPeriod = 0, DiskSizeInSectors = 20971520, Blocks = 0x000001D0B9C2B800
5/25 20:13:10.236060 1728 Cache: CacheBase::init: Prefetch Advisor was not created for RAM Cache!
5/25 20:13:10.236095 1728 Cache: CacheBase::init: Worker Thread is started and set to affinity group: 980.
5/25 20:13:10.236119 1728 Cache: CacheBase::init: Worker Thread is started and set to affinity group: 984.
5/25 20:13:10.236147 1728 Cache: CacheBase::init: Worker Thread is started and set to affinity group: 988.
5/25 20:13:10.236185 1728 Cache: CacheBase::init: Worker Thread is started and set to affinity group: 992.
5/25 20:13:10.236214 1728 Cache: CacheBase::init: Worker Thread is started and set to affinity group: 996.
5/25 20:13:10.236244 1e08 Cache: CacheBlocksMemory::getMaxMemoryAvailableForCache: Physical memory total: 66974660 KBs, 65404 MBs, 63 GBs
5/25 20:13:10.236273 1e08 Cache: CacheBlocksMemory::getMaxMemoryAvailableForCache: Physical memory available: 61678252 KBs, 60232 MBs, 58 GBs
5/25 20:13:10.236280 1e08 Cache: CacheBlocksMemory::getMaxMemoryAvailableForCache: Virtual memory available: 137434628564 KBs, 134213504 MBs, 131067 GBs
5/25 20:13:10.236351 1728 IMG: ImageFile_Create: 'D:\starwind\quorum-image-n2.img': disk is SSD, UNMAP supported.
5/25 20:13:10.236373 1728 func: >>> sw_common::scheduler::TaskScheduler::TaskScheduler
5/25 20:13:10.236440 1728 func: <<< sw_common::scheduler::TaskScheduler::TaskScheduler
5/25 20:13:10.236556 1728 SCSI: iScsiDevice::updateDeviceIds: EUI64 retrieved: 29F77B6A437CDC04 (hex)
5/25 20:13:10.236597 1728 SCSI: iScsiDevice::updateDeviceIds: SerialID retrieved: 29F77B6A437CDC04
5/25 20:13:10.236682 1728 SCSI: iScsiDevice::updateDiskSize: Disk 'imagefile1' (10240 MB)
5/25 20:13:10.237039 1530 func: >>> iScsiServer::sendNotification
5/25 20:13:10.237065 1530 func: >>> CEventDataBase::AddRecord
5/25 20:13:10.237073 1530 EventDB: CEventDataBase::AddRecord: Code 274, severity 1, additional strings: 1
5/25 20:13:10.237175 1530 func: <<< CEventDataBase::AddRecord
5/25 20:13:10.237184 1530 func: <<< iScsiServer::sendNotification
5/25 20:13:10.237194 1530 conf: ConfCommand::processNew: Device [0x000001D0B9C30440] 'imagefile1' has been created.
5/25 20:13:10.237224 1530 Common: sw_common::Sw_Disk_Header::open: (file: D:\starwind\quorum-image-n2_HA.swdsk, readonly: no).
5/25 20:13:10.237509 1530 Common: *** Browser_ParsePath: Incorrect path supplied: 'imagefile1'!
5/25 20:13:10.237522 1530 FileBrowser: *** CFileBrowser::parsePath: Only paths specified in 'imgdir' allowed
5/25 20:13:10.237527 1530 Srv: *** iScsiServer::getSscDeviceByStoragePath: Control request failed. Failed to convert virtual path (imagefile1).
5/25 20:13:10.237582 1728 SCSI: : parameter 'DeviceHeaderPath', value 'My computer\D\starwind\quorum-image-n2_HA.swdsk'.
5/25 20:13:10.237599 1728 SCSI: : parameter 'OwnTargetName', value 'iqn.2008-08.com.starwindsoftware:hv02-quorum-target-n2'.
5/25 20:13:10.237604 1728 SCSI: : parameter 'file', value 'My computer\D\starwind\quorum-image-n2_HA.swdsk'.
5/25 20:13:10.237613 1728 SCSI: : parameter 'serialId', value '06E18C60C0F811B3'.
5/25 20:13:10.237622 1728 SCSI: : parameter 'asyncmode', value 'yes'.
5/25 20:13:10.237629 1728 SCSI: : parameter 'readonly', value 'no'.
5/25 20:13:10.237635 1728 SCSI: : parameter 'highavailability', value 'yes'.
5/25 20:13:10.237640 1728 SCSI: : parameter 'buffering', value 'no'.
5/25 20:13:10.237644 1728 SCSI: : parameter 'header', value '65536'.
5/25 20:13:10.237648 1728 SCSI: : parameter 'CacheMode', value 'wb'.
5/25 20:13:10.237652 1728 SCSI: : parameter 'CacheSizeMB', value '128'.
5/25 20:13:10.237754 1728 HA: SscPort_Create: Opening device 'HAImage1', image file 'My computer\D\starwind\quorum-image-n2_HA.swdsk', alua='', storage='imagefile1'.
5/25 20:13:10.237770 1728 Common: sw_common::Sw_Disk_Header::open: (file: D:\starwind\quorum-image-n2_HA.swdsk, readonly: no).
5/25 20:13:10.238340 1728 func: >>> sw_common::scheduler::TaskScheduler::TaskScheduler
5/25 20:13:10.238434 1728 func: <<< sw_common::scheduler::TaskScheduler::TaskScheduler
5/25 20:13:10.238454 1728 func: >>> sw_common::scheduler::TaskScheduler::TaskScheduler
5/25 20:13:10.238562 1728 func: <<< sw_common::scheduler::TaskScheduler::TaskScheduler
5/25 20:13:10.238601 1728 func: >>> HASyncNode::createDevice
5/25 20:13:10.238609 1728 HA: HASyncNode::createDevice: Params(device = 0x000001D0BA3F8530, targetName = iqn.2008-08.com.starwindsoftware:hv02-quorum-target-n2, imageFilePath = D:\starwind\quorum-image-n2_HA.swdsk, storageDeviceName = imagefile1, storageDeviceInterface = 0x000001D0B9BB1960, sectorsPerTrack = 0, tracksPerCylinder = 0, serialIdStr = 06E18C60C0F811B3, hStorageDevice = 0x0000000000000000, pfuncSscPort_Create = 0x0000000000000000, pfuncSscPort_Close = 0x0000000000000000, pfuncSscPort_Prepare = 0x0000000000000000, pfuncSscPort_Dispatch = 0x0000000000000000, pfuncSscPort_CommandCompleted = 0x0000000000000000, pfuncSscPort_ControlRequest = 0x0000000000000000, pfuncSscPort_RegisterSession = 0x0000000000000000, pfuncSscPort_UnregisterSession = 0x0000000000000000, pfuncSscPort_GetDeviceInfo = 0x0000000000000000,aluaNodeGroupStatesStr = (null), flags = 0x1) ENTERed
5/25 20:13:10.238622 1728 Common: sw_common::Sw_Disk_Header::open: (file: D:\starwind\quorum-image-n2_HA.swdsk, readonly: no).
5/25 20:13:10.238984 1728 HA: MaintenanceMode::initialize: Maintenance mode is 'off'.
5/25 20:13:10.292261 1728 HA: HANode::initInquiryData: Inquiry data: VendorId 'STARWIND', ProductId 'STARWIND        ', Revision '0001'
5/25 20:13:10.297388 1728 Common: *** sw_common::Sw_XML_Link_Impl::local: There is no "local" present.
5/25 20:13:10.297406 1728 Common: *** sw_common::Sw_XML_Link_Impl::local: There is no "local" present.
5/25 20:13:10.297413 1728 Common: *** sw_common::Sw_XML_Link_Impl::local: There is no "local" present.
5/25 20:13:10.297515 1728 Common: sw_common::RamBitmapStore::initialize: Sync storage bitmap has been initialized.
5/25 20:13:10.306855 1e2c Common: *** MountTarget: (session(000001D0BA4C7438), local(0.0.0.0), peer(172.16.32.9), port(3260), target(iqn.2008-08.com.starwindsoftware:hv01.lufe.local-quorum-target-n1).
5/25 20:13:10.362760 1724 conf: ConfAclCommand::processNew: Acl record 'allow for partner(s) of iqn.2008-08.com.starwindsoftware:hv02-quorum-target-n2' loaded successfully.
5/25 20:13:10.362765 1728 func: <<< HASyncNode::createDevice
5/25 20:13:10.363354 1728 SCSI: iScsiDevice::updateDeviceIds: EUI64 retrieved: 6E18C60C0F811B3 (hex)
5/25 20:13:10.363409 1728 SCSI: iScsiDevice::updateDeviceIds: SerialID retrieved: 06E18C60C0F811B3
5/25 20:13:10.363544 1728 SCSI: iScsiDevice::updateDiskSize: Disk 'HAImage1' (10240 MB)
5/25 20:13:10.363817 1e10 Common: *** MountTarget: (session(000001D0B9C98A48), local(0.0.0.0), peer(172.16.32.17), port(3260), target(iqn.2008-08.com.starwindsoftware:hv01.lufe.local-quorum-target-n1).
5/25 20:13:10.364215 1530 func: >>> iScsiServer::sendNotification
5/25 20:13:10.364240 1530 func: >>> CEventDataBase::AddRecord
5/25 20:13:10.364247 1530 EventDB: CEventDataBase::AddRecord: Code 274, severity 1, additional strings: 1
5/25 20:13:10.364284 1530 func: <<< CEventDataBase::AddRecord
5/25 20:13:10.364290 1530 func: <<< iScsiServer::sendNotification
5/25 20:13:10.364298 1530 conf: ConfCommand::processNew: Device [0x000001D0BA3EED00] 'HAImage1' has been created.
5/25 20:13:10.364316 1530 Common: sw_common::Sw_Disk_Header::open: (file: D:\starwind\storage-image-n2.swdsk, readonly: no).
5/25 20:13:10.364882 1724 SCHED: Sw_Scheduler::attach: The HAImage1:0 device unit is being registered at the Scheduler.
5/25 20:13:10.364910 1724 SCHED: Sw_Scheduler_Node::add: Attaching HAImage1:0 device unit to the node.
5/25 20:13:10.364920 1724 SCHED: Sw_Scheduler_Node::update: Updating unit 0 tasks set.
5/25 20:13:10.365667 1e2c Common: *** MountTarget: (session(000001D0B9C99588), local(0.0.0.0), peer(172.16.32.9), port(3260), target(iqn.2008-08.com.starwindsoftware:hv01.lufe.local-quorum-target-n1).
5/25 20:13:10.367482 1dcc Common: *** MountTarget: (session(000001D0B9C99348), local(0.0.0.0), peer(172.16.32.1), port(3260), target(iqn.2008-08.com.starwindsoftware:hv01.lufe.local-quorum-target-n1).
5/25 20:13:10.369997 1e10 Common: *** MountTarget: (session(000001D0B9C997C8), local(0.0.0.0), peer(172.16.32.17), port(3260), target(iqn.2008-08.com.starwindsoftware:hv01.lufe.local-quorum-target-n1).
5/25 20:13:10.371170 1530 Common: sw_common::Sw_Disk_Header::open: (file: D:\starwind\storage-image-n2.swdsk, readonly: no).
5/25 20:13:10.371198 1e2c Common: *** MountTarget: (session(000001D0B9C98808), local(0.0.0.0), peer(172.16.32.9), port(3260), target(iqn.2008-08.com.starwindsoftware:hv01.lufe.local-quorum-target-n1).
5/25 20:13:10.371378 1728 SCSI: : parameter 'DeviceHeaderPath', value 'My computer\D\starwind\storage-image-n2.swdsk'.
5/25 20:13:10.371396 1728 SCSI: : parameter 'file', value 'My computer\D\starwind\storage-image-n2.swdsk'.
5/25 20:13:10.371406 1728 IMG: SscPort_Create: Parsing parameters from control connection: 
5/25 20:13:10.371423 1728 IMG: SscPort_Create: Header path parsed to 'D:\starwind\storage-image-n2.swdsk'.
5/25 20:13:10.371433 1728 IMG: addParameter: Parameter processed (add): DeviceHeaderPathPhysical = "D:\starwind\storage-image-n2.swdsk"
5/25 20:13:10.371443 1728 IMG: addParameter: Parameter processed (add): file = "My computer\D\starwind\storage-image-n2.swdsk"
5/25 20:13:10.371447 1728 Common: sw_common::Sw_Disk_Header::open: (file: D:\starwind\storage-image-n2.swdsk, readonly: no).
5/25 20:13:10.371638 1728 IMG: SscPort_Create: Parsing the Device Header File 'D:\starwind\storage-image-n2.swdsk':
5/25 20:13:10.371719 1728 IMG: addParameter: Parameter processed (update): file = "My computer\D\starwind\storage-image-n2.swdsk" -> "My computer\D\starwind\storage-image-n2.img"
5/25 20:13:10.371771 1728 IMG: addParameter: Parameter processed (add): CacheMode = "wb"
5/25 20:13:10.371778 1728 IMG: addParameter: Parameter processed (add): CacheFlags = "0"
5/25 20:13:10.371785 1728 IMG: addParameter: Parameter processed (add): CacheBlockExpiryPeriodMS = "0"
5/25 20:13:10.371790 1728 IMG: addParameter: Parameter processed (add): CacheSizeMB = "128"
5/25 20:13:10.371799 1728 IMG: addParameter: Parameter processed (add): SerialId = "AC1D271C82F69CB3"
5/25 20:13:10.371806 1728 IMG: addParameter: Parameter processed (add): eui64 = "AC1D271C82F69CB3"
5/25 20:13:10.371826 1728 IMG: addParameter: Parameter processed (update): SerialId = "AC1D271C82F69CB3" -> "AC1D271C82F69CB3"
5/25 20:13:10.371832 1728 IMG: addParameter: Parameter processed (update): eui64 = "AC1D271C82F69CB3" -> "AC1D271C82F69CB3"
5/25 20:13:10.371904 1728 IMG: SscPort_Create: Opening device 'imagefile2', image file 'My computer\D\starwind\storage-image-n2.img', buffering=0, async=1, readonly=0.
5/25 20:13:10.373542 1e2c HA: HAPartneriScsiChannel::permanentConnectionPollingThread: Waiting 6 sec before retry sending backward connection command ...
5/25 20:13:10.375070 1dcc Common: *** MountTarget: (session(000001D0B93ED858), local(0.0.0.0), peer(172.16.32.1), port(3260), target(iqn.2008-08.com.starwindsoftware:hv01.lufe.local-quorum-target-n1).
5/25 20:13:10.375862 1e10 Common: *** MountTarget: (session(000001D0B9C98C88), local(0.0.0.0), peer(172.16.32.17), port(3260), target(iqn.2008-08.com.starwindsoftware:hv01.lufe.local-quorum-target-n1).
5/25 20:13:10.377953 1dcc HA: HAPartneriScsiChannel::permanentConnectionPollingThread: Waiting 6 sec before retry sending backward connection command ...
5/25 20:13:10.378794 1e10 HA: HAPartneriScsiChannel::permanentConnectionPollingThread: Waiting 6 sec before retry sending backward connection command ...
5/25 20:13:10.704545 1728 debug: Swn_CreateFile: volume name 'D:'.
5/25 20:13:10.704615 1728 debug: *** GetVolumeProperties: \\.\D:: StorageDeviceTrimProperty failed (error 1).
5/25 20:13:10.704658 1728 IMG: ImageFile_Create: 'D:\starwind\storage-image-n2.img': type 0, geometry: sct 16, trks 32, cyl 12288000, TotalSectors: 6291456000, SectorSize: 512, PhySectorSize: 4096
5/25 20:13:10.704665 1728 IMG: ImageFile_Create: VendorId 'STARWIND', ProductId 'STARWIND        ', Revision '0001', Serial 'AC1D271C82F69CB3'
5/25 20:13:10.704701 1728 Cache: StarWind Virtual SAN v8.0.0 (Build 15159, [SwSAN], Win64)
5/25 20:13:10.704708 1728 Cache: Jun  2 2023 14:26:48
5/25 20:13:10.704748 1728 Cache: CacheBase::init: Cache parameters: Mode = 1, Flags = 0, Size = 128 MB, SectorSize = 512, BlockExpiryPeriod = 0, DiskSizeInSectors = 6291456000, Blocks = 0x000001D0BA4D8D00
5/25 20:13:10.704791 1728 Cache: CacheBase::init: Prefetch Advisor was not created for RAM Cache!
5/25 20:13:10.704827 1728 Cache: CacheBase::init: Worker Thread is started and set to affinity group: 1416.
5/25 20:13:10.704848 608 Cache: CacheBlocksMemory::getMaxMemoryAvailableForCache: Physical memory total: 66974660 KBs, 65404 MBs, 63 GBs
5/25 20:13:10.704873 608 Cache: CacheBlocksMemory::getMaxMemoryAvailableForCache: Physical memory available: 61548088 KBs, 60105 MBs, 58 GBs
5/25 20:13:10.704854 1728 Cache: CacheBase::init: Worker Thread is started and set to affinity group: 1420.
5/25 20:13:10.704880 608 Cache: CacheBlocksMemory::getMaxMemoryAvailableForCache: Virtual memory available: 137434461552 KBs, 134213341 MBs, 131067 GBs
5/25 20:13:10.704924 1728 Cache: CacheBase::init: Worker Thread is started and set to affinity group: 1424.
5/25 20:13:10.704963 1728 Cache: CacheBase::init: Worker Thread is started and set to affinity group: 1428.
5/25 20:13:10.705010 1728 Cache: CacheBase::init: Worker Thread is started and set to affinity group: 1432.
5/25 20:13:10.705223 1728 IMG: ImageFile_Create: 'D:\starwind\storage-image-n2.img': disk is SSD, UNMAP supported.
5/25 20:13:10.705242 1728 func: >>> sw_common::scheduler::TaskScheduler::TaskScheduler
5/25 20:13:10.705327 1728 func: <<< sw_common::scheduler::TaskScheduler::TaskScheduler
5/25 20:13:10.705402 1728 SCSI: iScsiDevice::updateDeviceIds: EUI64 retrieved: AC1D271C82F69CB3 (hex)
5/25 20:13:10.705431 1728 SCSI: iScsiDevice::updateDeviceIds: SerialID retrieved: AC1D271C82F69CB3
5/25 20:13:10.705512 1728 SCSI: iScsiDevice::updateDiskSize: Disk 'imagefile2' (3072000 MB)
5/25 20:13:10.705756 1530 func: >>> iScsiServer::sendNotification
5/25 20:13:10.705775 1530 func: >>> CEventDataBase::AddRecord
5/25 20:13:10.705782 1530 EventDB: CEventDataBase::AddRecord: Code 274, severity 1, additional strings: 1
5/25 20:13:10.705805 1530 func: <<< CEventDataBase::AddRecord
5/25 20:13:10.705812 1530 func: <<< iScsiServer::sendNotification
5/25 20:13:10.705820 1530 conf: ConfCommand::processNew: Device [0x000001D0BA523700] 'imagefile2' has been created.
5/25 20:13:10.705842 1530 Common: sw_common::Sw_Disk_Header::open: (file: D:\starwind\storage-image-n2_HA.swdsk, readonly: no).
5/25 20:13:10.706088 1530 Common: *** Browser_ParsePath: Incorrect path supplied: 'imagefile2'!
5/25 20:13:10.706098 1530 FileBrowser: *** CFileBrowser::parsePath: Only paths specified in 'imgdir' allowed
5/25 20:13:10.706103 1530 Srv: *** iScsiServer::getSscDeviceByStoragePath: Control request failed. Failed to convert virtual path (imagefile2).
5/25 20:13:10.706159 1728 SCSI: : parameter 'DeviceHeaderPath', value 'My computer\D\starwind\storage-image-n2_HA.swdsk'.
5/25 20:13:10.706180 1728 SCSI: : parameter 'OwnTargetName', value 'iqn.2008-08.com.starwindsoftware:hv02-storage-target-n2'.
5/25 20:13:10.706187 1728 SCSI: : parameter 'file', value 'My computer\D\starwind\storage-image-n2_HA.swdsk'.
5/25 20:13:10.706194 1728 SCSI: : parameter 'serialId', value '3CE74B0D41DF5092'.
5/25 20:13:10.706200 1728 SCSI: : parameter 'asyncmode', value 'yes'.
5/25 20:13:10.706207 1728 SCSI: : parameter 'readonly', value 'no'.
5/25 20:13:10.706213 1728 SCSI: : parameter 'highavailability', value 'yes'.
5/25 20:13:10.706218 1728 SCSI: : parameter 'buffering', value 'no'.
5/25 20:13:10.706222 1728 SCSI: : parameter 'header', value '65536'.
5/25 20:13:10.706226 1728 SCSI: : parameter 'CacheMode', value 'wb'.
5/25 20:13:10.706231 1728 SCSI: : parameter 'CacheSizeMB', value '128'.
5/25 20:13:10.706313 1728 HA: SscPort_Create: Opening device 'HAImage2', image file 'My computer\D\starwind\storage-image-n2_HA.swdsk', alua='', storage='imagefile2'.
5/25 20:13:10.706319 1728 Common: sw_common::Sw_Disk_Header::open: (file: D:\starwind\storage-image-n2_HA.swdsk, readonly: no).
5/25 20:13:10.706569 1728 func: >>> sw_common::scheduler::TaskScheduler::TaskScheduler
5/25 20:13:10.706792 1728 func: <<< sw_common::scheduler::TaskScheduler::TaskScheduler
5/25 20:13:10.706835 1728 func: >>> sw_common::scheduler::TaskScheduler::TaskScheduler
5/25 20:13:10.706903 1728 func: <<< sw_common::scheduler::TaskScheduler::TaskScheduler
5/25 20:13:10.706932 1728 func: >>> HASyncNode::createDevice
5/25 20:13:10.706938 1728 HA: HASyncNode::createDevice: Params(device = 0x000001D0BA5CD460, targetName = iqn.2008-08.com.starwindsoftware:hv02-storage-target-n2, imageFilePath = D:\starwind\storage-image-n2_HA.swdsk, storageDeviceName = imagefile2, storageDeviceInterface = 0x000001D0B9BADC60, sectorsPerTrack = 0, tracksPerCylinder = 0, serialIdStr = 3CE74B0D41DF5092, hStorageDevice = 0x0000000000000000, pfuncSscPort_Create = 0x0000000000000000, pfuncSscPort_Close = 0x0000000000000000, pfuncSscPort_Prepare = 0x0000000000000000, pfuncSscPort_Dispatch = 0x0000000000000000, pfuncSscPort_CommandCompleted = 0x0000000000000000, pfuncSscPort_ControlRequest = 0x0000000000000000, pfuncSscPort_RegisterSession = 0x0000000000000000, pfuncSscPort_UnregisterSession = 0x0000000000000000, pfuncSscPort_GetDeviceInfo = 0x0000000000000000,aluaNodeGroupStatesStr = (null), flags = 0x1) ENTERed
5/25 20:13:10.706953 1728 Common: sw_common::Sw_Disk_Header::open: (file: D:\starwind\storage-image-n2_HA.swdsk, readonly: no).
5/25 20:13:10.707266 1728 HA: MaintenanceMode::initialize: Maintenance mode is 'off'.
5/25 20:13:10.759750 1728 HA: HANode::initInquiryData: Inquiry data: VendorId 'STARWIND', ProductId 'STARWIND        ', Revision '0001'
5/25 20:13:10.764848 1728 Common: *** sw_common::Sw_XML_Link_Impl::local: There is no "local" present.
5/25 20:13:10.764865 1728 Common: *** sw_common::Sw_XML_Link_Impl::local: There is no "local" present.
5/25 20:13:10.764872 1728 Common: *** sw_common::Sw_XML_Link_Impl::local: There is no "local" present.
5/25 20:13:10.764986 1728 Common: sw_common::RamBitmapStore::initialize: Sync storage bitmap has been initialized.
5/25 20:13:10.771578 19d0 Common: *** MountTarget: (session(000001D0B93EE638), local(0.0.0.0), peer(172.16.32.9), port(3260), target(iqn.2008-08.com.starwindsoftware:hv01.lufe.local-storage-target-n1).
5/25 20:13:10.776505 1ec0 Common: *** MountTarget: (session(000001D0B9C99C48), local(0.0.0.0), peer(172.16.32.17), port(3260), target(iqn.2008-08.com.starwindsoftware:hv01.lufe.local-storage-target-n1).
5/25 20:13:10.777393 19d0 Common: *** MountTarget: (session(000001D0B9C99108), local(0.0.0.0), peer(172.16.32.9), port(3260), target(iqn.2008-08.com.starwindsoftware:hv01.lufe.local-storage-target-n1).
5/25 20:13:10.826880 1ec4 conf: ConfAclCommand::processNew: Acl record 'allow for partner(s) of iqn.2008-08.com.starwindsoftware:hv02-storage-target-n2' loaded successfully.
5/25 20:13:10.826897 1728 func: <<< HASyncNode::createDevice
5/25 20:13:10.827430 1728 SCSI: iScsiDevice::updateDeviceIds: EUI64 retrieved: 3CE74B0D41DF5092 (hex)
5/25 20:13:10.827505 1728 SCSI: iScsiDevice::updateDeviceIds: SerialID retrieved: 3CE74B0D41DF5092
5/25 20:13:10.827664 1728 SCSI: iScsiDevice::updateDiskSize: Disk 'HAImage2' (3072000 MB)
5/25 20:13:10.828369 1530 func: >>> iScsiServer::sendNotification
5/25 20:13:10.828393 1530 func: >>> CEventDataBase::AddRecord
5/25 20:13:10.828400 1530 EventDB: CEventDataBase::AddRecord: Code 274, severity 1, additional strings: 1
5/25 20:13:10.828424 1530 func: <<< CEventDataBase::AddRecord
5/25 20:13:10.828431 1530 func: <<< iScsiServer::sendNotification
5/25 20:13:10.828440 1530 conf: ConfCommand::processNew: Device [0x000001D0C274ECC0] 'HAImage2' has been created.
5/25 20:13:10.829149 1ec4 SCHED: Sw_Scheduler::attach: The HAImage2:0 device unit is being registered at the Scheduler.
5/25 20:13:10.829166 1ec4 SCHED: Sw_Scheduler_Node::add: Attaching HAImage2:0 device unit to the node.
5/25 20:13:10.829172 1ec4 SCHED: Sw_Scheduler_Node::update: Updating unit 0 tasks set.
5/25 20:13:10.829189 1728 Srv: iScsiServer::addTargetCallback: Creating target 'iqn.2008-08.com.starwindsoftware:hv02-quorum-target-n2', type 0, device list 'HAImage1'...
5/25 20:13:10.833886 19d0 Common: *** MountTarget: (session(000001D0B9C99A08), local(0.0.0.0), peer(172.16.32.9), port(3260), target(iqn.2008-08.com.starwindsoftware:hv01.lufe.local-storage-target-n1).
5/25 20:13:10.833975 1ec0 Common: *** MountTarget: (session(000001D0C2845418), local(0.0.0.0), peer(172.16.32.17), port(3260), target(iqn.2008-08.com.starwindsoftware:hv01.lufe.local-storage-target-n1).
5/25 20:13:10.834017 1e68 Common: *** MountTarget: (session(000001D0BA4ED498), local(0.0.0.0), peer(172.16.32.1), port(3260), target(iqn.2008-08.com.starwindsoftware:hv01.lufe.local-storage-target-n1).
5/25 20:13:10.836617 19d0 HA: HAPartneriScsiChannel::permanentConnectionPollingThread: Waiting 6 sec before retry sending backward connection command ...
Cheers,
Sebastian
Attachments
screenshot.jpg
screenshot.jpg (125.14 KiB) Viewed 4200 times
yaroslav (staff)
Staff
Posts: 2475
Joined: Mon Nov 18, 2019 11:11 am

Sun May 26, 2024 9:08 am

Stop the service on both nodes.
Go to HA config files and ser sync status value in the config to 1 for the section that corresponds to the device. Do for each decice.
That marks HAs as synchronized.
Start the service on the node where you marked the devices as synchronized and check the data.
If data is OK, start another node and let sync happen.
Method to fix it https://knowledgebase.starwindsoftware. ... -blackout/
Also remove write-back caching https://knowledgebase.starwindsoftware. ... -l1-cache/
sebsom
Posts: 2
Joined: Sat May 25, 2024 7:35 pm

Sun May 26, 2024 12:25 pm

Hi,
thanks for the quick reply!
If I'm not at the wrong place, the status is already set to 1. Am i right that the HA config ist a *-image-n*_HA.swdsk ?

Thats my file:

Code: Select all

<?xml version="1.0" encoding="UTF-8"?>
<header signature="StarWind" version="1.1">
  <device active="true" plugin="HAImage" name="HAImage">
    <storages>
      <storage id="1" type="device" name="HAImage" lun="0x0">
        <interval size="3000" units="GB"/>
        <inquiry>
          <serial_id>3CE74B0D41DF5092</serial_id>
          <vendor id="STARWIND"/>
          <product id="STARWIND" revision="0001"/>
          <eui_64>3CE74B0D41DF5092</eui_64>
        </inquiry>
        <geometry>
          <sector size="512" psize="4096"/>
          <track sectors="16"/>
          <cylinder tracks="32" count="65535"/>
        </geometry>
        <caching>
          <cache type="write-back" size="128" units="MB" level="1">
            <storages>
              <storage_ref id="1"/>
            </storages>
          </cache>
        </caching>
      </storage>
    </storages>
  </device>
  <system>
    <resources>
      <storages>
        <storage id="1" name="RAM" type="RAM">
          <interval size="128" units="MB"/>
        </storage>
        <storage id="2" name="imagefile2" type="device" lun="0x0">
          <interval size="3000" units="GB"/>
        </storage>
        <storage id="3" name="iqn.2008-08.com.starwindsoftware:hv02-storage-target-n2" type="remote" lun="0x0">
          <transport type="iSCSI">
            <links>
              <link id="1" type="data" priority="1" connections="1">
                <peer ip="172.16.32.10" port="3260"/>
              </link>
              <link id="2" type="data" priority="1" connections="1">
                <peer ip="172.16.32.18" port="3260"/>
              </link>
              <link id="3" type="control" priority="1" connections="1">
                <peer ip="172.16.32.2" port="3260"/>
              </link>
            </links>
          </transport>
        </storage>
      </storages>
      <network/>
    </resources>
  </system>
  <node id="1" name="HAImage" shut="false" active="true" flags="0">
    <storages>
      <storage_ref id="2"/>
    </storages>
    <parameters>
      <type>1</type>
      <priority>0</priority>
      <auto_sync>true</auto_sync>
[color=#FF0000]      <sync_status>1</sync_status>[/color]
      <sync_delay>50</sync_delay>
      <sync_traffic_share>50</sync_traffic_share>
      <failover_conf>0</failover_conf>
      <last_sync_snap_id>0</last_sync_snap_id>
      <alua_access_state>0</alua_access_state>
      <maintenance_mode>false</maintenance_mode>
    </parameters>
  </node>
  <node id="2" name="iqn.2008-08.com.starwindsoftware:hv02-storage-target-n2" shut="false" active="true">
    <storages>
      <storage_ref id="3"/>
    </storages>
    <parameters>
      <type>1</type>
      <priority>1</priority>
      <sync_status>1</sync_status>
      <alua_access_state>1</alua_access_state>
      <type_bitmap>RAM</type_bitmap>
    </parameters>
  </node>
</header>
                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                           
...and at the console the synchonization status is still non synchronized
yaroslav (staff)
Staff
Posts: 2475
Joined: Mon Nov 18, 2019 11:11 am

Sun May 26, 2024 1:52 pm

Try marking sync_status 1 only the first occurance. Set the latter to 0.
Make sure to edit the files while StarWindService is stopped.
Last but not least, remove write back cache: should make such incidents less frequent.
savorymare
Posts: 1
Joined: Tue May 28, 2024 10:17 am
Contact:

Tue May 28, 2024 10:18 am

Thanks, got it working. :)
yaroslav (staff)
Staff
Posts: 2475
Joined: Mon Nov 18, 2019 11:11 am

Tue May 28, 2024 11:20 am

Hi,

Nice to read that!
Post Reply