Volume will be assigned but not attached

[Seranor20111014]

Hello,

We are using App Volumes 2.9 with two vCenters.

At this time there are two AppStacks available.

Assign an AppStack to Vms within the vCenter 1 works like a charm, Volume is assigned an attached.

Assign the same AppStack to a VM which resides on the second vCenter it will be assigned, but not attached, the error message is:

"Rejected all 1 volumes because they are invalid or have no accessible volume file"

AppVolumes Agent 2.9 is installed and shows up as connected.

Account for both vCenters is administrator@vsphere.local with full admin rights.

Debug Log entry:

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG        Cvo: Assigning and attaching 1 volumes

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   Computer Load (0.0ms)  EXEC sp_executesql N'SELECT TOP (1) [computers].* FROM [computers] WHERE [computers].[id] = 5'

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   Snapvol Load (0.0ms)  EXEC sp_executesql N'SELECT TOP (1) [snapvols].* FROM [snapvols] WHERE [snapvols].[id] = N''3'''

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG    (15.6ms)  EXEC sp_executesql N'SELECT COUNT(*) FROM [snapvol_members] WHERE [snapvol_members].[target_id] = 5 AND [snapvol_members].[target_type] = N''Computer'' AND [snapvol_members].[snapvol_id] = 3'

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   SQL (15.6ms)  BEGIN TRANSACTION

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   SQL (0.0ms)  EXEC sp_executesql N'INSERT INTO [snapvol_members] ([created_at], [mount_prefix], [persistent], [priority], [snapvol_id], [target_id], [target_type], [updated_at]) OUTPUT CAST(COALESCE(INSERTED.id, @@IDENTITY, SCOPE_IDENTITY()) AS bigint) VALUES (@0, @1, @2, @3, @4, @5, @6, @7)', N'@0 datetime, @1 nvarchar(100), @2 bit, @3 int, @4 int, @5 int, @6 nvarchar(255), @7 datetime', @0 = '2015-06-22T08:17:10.223', @1 = N'', @2 = 1, @3 = 0, @4 = 3, @5 = 5, @6 = N'Computer', @7 = '2015-06-22T08:17:10.223'  [["created_at", Mon, 22 Jun 2015 08:17:10 UTC +00:00], ["mount_prefix", ""], ["persistent", true], ["priority", 0], ["snapvol_id", 3], ["target_id", 5], ["target_type", "Computer"], ["updated_at", Mon, 22 Jun 2015 08:17:10 UTC +00:00]]

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   SQL (0.0ms)  EXEC sp_executesql N'UPDATE [computers] SET [assignment_count] = COALESCE([assignment_count], 0) + 1 WHERE [computers].[id] = 5; SELECT @@ROWCOUNT AS AffectedRows'

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG    (0.0ms)  EXEC sp_executesql N'SELECT @@ROWCOUNT As AffectedRows'

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   SQL (0.0ms)  EXEC sp_executesql N'UPDATE [snapvols] SET [assignment_count] = COALESCE([assignment_count], 0) + 1 WHERE [snapvols].[id] = 3; SELECT @@ROWCOUNT AS AffectedRows'

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG    (0.0ms)  EXEC sp_executesql N'SELECT @@ROWCOUNT As AffectedRows'

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   SQL (0.0ms)  COMMIT TRANSACTION

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   SQL (0.0ms)  BEGIN TRANSACTION

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   SQL (15.6ms)  EXEC sp_executesql N'INSERT INTO [log_records] ([admin_user_id], [created_at], [end_at], [extra], [ip_address], [message], [pending_activity_id], [reason], [source_id], [source_type], [target_id], [target_type], [uuid]) OUTPUT CAST(COALESCE(INSERTED.id, @@IDENTITY, SCOPE_IDENTITY()) AS bigint) VALUES (@0, @1, @2, @3, @4, @5, @6, @7, @8, @9, @10, @11, @12)', N'@0 int, @1 datetime, @2 datetime, @3 nvarchar(255), @4 nvarchar(255), @5 nvarchar(max), @6 int, @7 nvarchar(255), @8 int, @9 nvarchar(255), @10 int, @11 nvarchar(255), @12 nvarchar(255)', @0 = 3, @1 = '2015-06-22T08:17:10.254', @2 = NULL, @3 = NULL, @4 = N'10.31.64.39', @5 = N'Success', @6 = NULL, @7 = N'Assign', @8 = 5, @9 = N'Computer', @10 = 3, @11 = N'Snapvol', @12 = NULL  [["admin_user_id", 3], ["created_at", Mon, 22 Jun 2015 08:17:10 UTC +00:00], ["end_at", nil], ["extra", nil], ["ip_address", "10.31.64.39"], ["message", "Success"], ["pending_activity_id", nil], ["reason", "Assign"], ["source_id", 5], ["source_type", "Computer"], ["target_id", 3], ["target_type", "Snapvol"], ["uuid", nil]]

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   SQL (0.0ms)  COMMIT TRANSACTION

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   Machine Load (15.6ms)  EXEC sp_executesql N'SELECT TOP (1) [machines].* FROM [machines] WHERE [machines].[id] = 5'

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   MachineManager Load (0.0ms)  EXEC sp_executesql N'SELECT TOP (1) [machine_managers].* FROM [machine_managers] WHERE [machine_managers].[id] = 2'

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   Credential Load (0.0ms)  EXEC sp_executesql N'SELECT TOP (1) [credentials].* FROM [credentials] WHERE [credentials].[id] = 2'

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG        Cvo: Using VCENTER2 credentials to create vCenter adapter.

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG        Cvo: Creating a new VcenterAdapter for #<Thread:0x4fdc550>

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG        Cvo: Caching "#<Cvo::Hypervisor::VcenterAdapter:0x4fd63b8>" under "vcenter1004157590" from "#<Thread:0x4fdc550>"

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   RvSphere: Connecting to VMware administrator@vsphere.local@VCENTER2 (#<Thread:0x4fdc550>)

[2015-06-22 08:17:10 UTC] P5740R2  INFO   RvSphere: Connection to VMware administrator@vsphere.local@VCENTER2 succeeded - Took 109ms

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   RvSphere: Server: "VMware vCenter Server 5.5.0 build-2646482" License: "VMware VirtualCenter Server"

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   RvSphere: Found 1 virtual machine(s) matching InstanceUuid "5016c1be-46ee-5248-148a-023832868c87"

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   Snapvol Load (0.0ms)  EXEC sp_executesql N'SELECT TOP (1) [snapvols].* FROM [snapvols] WHERE [snapvols].[provision_uuid] = N''5016c1be-46ee-5248-148a-023832868c87'''

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG    (15.6ms)  EXEC sp_executesql N'SELECT COUNT(*) FROM [snapvol_attachments] WHERE (uuid = N''5016c1be-46ee-5248-148a-023832868c87'' AND (source_id != 5 OR source_type != N''Computer''))'

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   OperatingSystem Load (0.0ms)  EXEC sp_executesql N'SELECT TOP (1) [operating_systems].* FROM [operating_systems] WHERE [operating_systems].[major_version] = N''6'' AND [operating_systems].[minor_version] = N''1'' AND [operating_systems].[product_type] = 1 AND [operating_systems].[proc_arch] = 9'

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG    (15.6ms)  EXEC sp_executesql N'SELECT COUNT(*) FROM [snapvol_operating_systems] WHERE [snapvol_operating_systems].[snapvol_id] = 3'

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG    (0.0ms)  EXEC sp_executesql N'SELECT COUNT(*) FROM [snapvol_operating_systems] WHERE [snapvol_operating_systems].[snapvol_id] = 3 AND [snapvol_operating_systems].[operating_system_id] = 6'

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG    (15.6ms)  EXEC sp_executesql N'SELECT COUNT(*) FROM [snapvols] WHERE [snapvols].[provision_uuid] = N''5016c1be-46ee-5248-148a-023832868c87'''

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG    (0.0ms)  EXEC sp_executesql N'SELECT COUNT(*) FROM [computers] WHERE [computers].[is_server] = 0 AND (disabled_at IS NULL) AND (computers.mount_count > 0) AND (created_at <= ''20150622 08:17:10.535'')'

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG    (0.0ms)  EXEC sp_executesql N'SELECT COUNT(DISTINCT [computers].[id]) FROM [computers] INNER JOIN [snapvol_attachments] ON [snapvol_attachments].[source_id] = [computers].[id] AND [snapvol_attachments].[source_type] = N''Computer'' WHERE [computers].[is_server] = 0 AND [snapvol_attachments].[source_type] = ''Computer'''

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG    (0.0ms)  EXEC sp_executesql N'SELECT COUNT(*) FROM [snapvol_attachments] WHERE [snapvol_attachments].[source_id] = 5 AND [snapvol_attachments].[source_type] = N''Computer'''

[2015-06-22 08:17:10 UTC] P5740R2  INFO        Cvo: Mounting volumes for "Computer <DOMAIN\MACHINE$>" to "Computer <DOMAIN\MACHINE$>" on "Windows Desktop OS"

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG        Cvo: Using VCENTER2 credentials to create vCenter adapter.

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG        Cvo: Creating a new VcenterAdapter for #<Thread:0x4fdc550>

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG        Cvo: Caching "#<Cvo::Hypervisor::VcenterAdapter:0x5034ea0>" under "vcenter1004157590" from "#<Thread:0x4fdc550>"

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   RvSphere: Connecting to VMware administrator@vsphere.local@VCENTER2 (#<Thread:0x4fdc550>)

[2015-06-22 08:17:10 UTC] P5740R2  INFO   RvSphere: Connection to VMware administrator@vsphere.local@VCENTER2 succeeded - Took 94ms

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   RvSphere: Server: "VMware vCenter Server 5.5.0 build-2646482" License: "VMware VirtualCenter Server"

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   RvSphere: Found 1 virtual machine(s) matching InstanceUuid "5016c1be-46ee-5248-148a-023832868c87"

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   SQL (0.0ms)  EXEC sp_executesql N'SELECT [storage_locations].[id] FROM [storage_locations] WHERE [storage_locations].[name] IN (N''S_BSAG_ESX_TRANS_B_001'', N''es-esx-c104_local'', N''E_BSAG_CLT_G_001'', N''E_BSAG_CLT_G_002'', N''E_BSAG_CLT_G_003'', N''E_BSAG_CLT_G_004'', N''E_BSAG_CLT_G_005'', N''E_BSAG_CLT_G_006'', N''E_BSAG_CLT_G_007'', N''E_BSAG_CLT_S_001'', N''E_BSAG_CLT_S_002'', N''E_BSAG_CLT_B_001'', N''E_BSAG_EXT_CL1_LIV_S_002'') AND [storage_locations].[machine_manager_id] = 2'

[2015-06-22 08:17:10 UTC] P5740R2 DEBUG   SnapvolFile Load (0.0ms)  EXEC sp_executesql N'SELECT TOP (1) [snapvol_files].* FROM [snapvol_files] WHERE [snapvol_files].[snapvol_id] = 3 AND [snapvol_files].[missing] = 0 AND [snapvol_files].[reachable] = 1 AND [snapvol_files].[storage_location_id] IN (29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 45) ORDER BY attachment_count ASC, created_at DESC'

[2015-06-22 08:17:10 UTC] P5740R2 ERROR        Cvo: Rejected all 1 volumes because they are invalid or have no accessible volume file

[2015-06-22 08:17:11 UTC] P5740R2 DEBUG   SQL (0.0ms)  BEGIN TRANSACTION

[2015-06-22 08:17:11 UTC] P5740R2 DEBUG   SQL (15.6ms)  EXEC sp_executesql N'INSERT INTO [system_messages] ([created_at], [message_key], [message_time], [message_value], [more]) OUTPUT CAST(COALESCE(INSERTED.id, @@IDENTITY, SCOPE_IDENTITY()) AS bigint) VALUES (@0, @1, @2, @3, @4)', N'@0 datetime, @1 nvarchar(255), @2 datetime, @3 nvarchar(max), @4 nvarchar(max)', @0 = '2015-06-22T08:17:11.003', @1 = NULL, @2 = '2015-06-22T08:17:11.003', @3 = N'Rejected all 1 volumes because they are invalid or have no accessible volume file', @4 = NULL  [["created_at", Mon, 22 Jun 2015 08:17:11 UTC +00:00], ["message_key", nil], ["message_time", Mon, 22 Jun 2015 08:17:11 UTC +00:00], ["message_value", "Rejected all 1 volumes because they are invalid or have no accessible volume file"], ["more", nil]]

[2015-06-22 08:17:11 UTC] P5740R2 DEBUG   SQL (0.0ms)  COMMIT TRANSACTION

[2015-06-22 08:17:11 UTC] P5740R2  INFO        Cvo: Attached 0 volume(s) for "Computer <DOMAIN\MACHINE$>"

[2015-06-22 08:17:11 UTC] P5740R2 DEBUG        Cvo: Rejecting temporary adapters under "temporary#<Thread:0x4fdc550>" reserved from "#<Thread:0x4fdc550>"

[2015-06-22 08:17:11 UTC] P5740R2 DEBUG        Cvo: Releasing 3 adapters from 2 pools reserved from "#<Thread:0x4fdc550>"

[2015-06-22 08:17:11 UTC] P5740R2 DEBUG        Cvo: There are now 2 pools with 3 total items

[2015-06-22 08:17:11 UTC] P5740R2 DEBUG Session loaded during this request? true

[2015-06-22 08:17:11 UTC] P5740R2 DEBUG Time spend garbage collecting this request: 0.187ms

[2015-06-22 08:17:11 UTC] P5740R2  INFO Completed 200 OK in 1107.7ms (Views: 0.0ms | ActiveRecord: 171.6ms)

Can someone help here?

Kind Regards

Stephan

[dmmcsherry · Accepted solution]

If you are using two vCenters, you need to make sure that you select datastores from both vCenters. In this case, you probably have the location that you set up by default, but you will also need to do an import selecting the same shared datastore on the other vCenter. If you look at the locations under a specific appstack, it should list out the vCenter(s) along with what storage it is using. If there is nothing listed for vCenter2, you will need to do an import from a datastore available on that vCenter. This may be the same exact datastore you are using on vCenter1, but it needs to be imported under vCenter2.

Hopefully that makes sense. Essentially because AppVolumes is sending vCenter commands, there is no way for AppVolumes to send a command to vCenter2 for storage that exists on vCenter1, therefore you see the following line:

[2015-06-22 08:17:10 UTC] P5740R2 ERROR        Cvo: Rejected all 1 volumes because they are invalid or have no accessible volume file

[Seranor20111014]

Hello,

@dmmcsherry: Thank you, that solved it!

Maybe VMware will put this information into the documentation in the future, because the neither error message isn't that clear nor the console shows a hint about that fact.

Thank you again, you saved my day 🙂

Kind Regards

Stephan

[dmmcsherry]

No problem, glad to help. The documentation for AppVolumes could definitely use some improvement, and it's getting better with each version, but definitely still lacking a lot of the in depth information I have come to expect from most VMware documentation. A lot for us has been trial and error until we figure it out.

[chris_halstead]

I am getting the same error on 2.9 with a single esx host and a single datastore.   Have you seen this before in this scenario?

[admin]

VMware KB: Using single ESXi host as the Machine Manager in VMware App Volumes generates error: "app...