pbhite
Enthusiast
Enthusiast

500 Internal Server Error After 2.12 to 2.13 Upgrade

Jump to solution

Just ran the App Volumes Manager installer for 2.13 on our current 2.12.1 server with a local SQL Express DB. After the install finished successfully (which does not have any options to select for the upgrade), our agents can't connect and I can't login - it just returns a 500 internal server error. The login page displays and our domain is listed in the drop-down. The service is starting fine and everything in the logs seems to check out until we go to log in. I tried fiddling with the ODBC connector, changing to a local sa account, made sure there the local computer account was in SQL with dbo permissions on the database, etc. Here's the error in the production######.log file that appears immediately after the login process and just before the 500 error is returned:

ERROR      Manager: Unhandled request exception: nil can't be coerced into Fixnum

In the svmanager_setup.log file, I see all the db tables being created successfully, but there is this error just before the "finished successfully" message

Granting database access to REDACTED\VMW17APPVOL$

console_handle_fault: Exception ActiveRecord::StatementInvalid: ODBC::Error: 42000 (15247) [Microsoft][ODBC SQL Server Driver][SQL Server]User does not have permission to perform this action.: CREATE LOGIN [REDACTED\VMW17APPVOL$] FROM WINDOWS

#<ActiveRecord::StatementInvalid: ODBC::Error: 42000 (15247) [Microsoft][ODBC SQL Server Driver][SQL Server]User does not have permission to perform this action.: CREATE LOGIN [REDACTED\VMW17APPVOL$] FROM WINDOWS>

However, I can confirm that the computer account already exists in SQL and has dbo permissions to the AppVol db (and sysadmin permissions on the SQL instance itself), so this may just be an erroneous error because the account already existed prior to the upgrade.

1 Solution

Accepted Solutions
Raymond_W
VMware Employee
VMware Employee

I'm happy to announce that App Volumes 2.13.1 already has been released with a fix for this issue.

You can read the release notes here, and download App Volumes 2.13.1 here.

Kind regards,

Raymond

Kind regards, Raymond Twitter: @raymond_himself

View solution in original post

0 Kudos
23 Replies
sabarishkumarr
VMware Employee
VMware Employee

@pbhite Can you add more log lines from production######.log when the error happens, it will help root cause the issue.

0 Kudos
jahegyi
Enthusiast
Enthusiast

I am having the exact same issue after upgrading to 2.13 in our test environment.

Here are additional lines that appear after the same error from the original post:

P4932R5 ERROR    Manager: Inspecting Array (7961680) (from log block)

[

    [ 0] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/domain_controller.rb:35:in `**'",

    [ 1] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/domain_controller.rb:35:in `block in fetch_available_controllers'",

    [ 2] "C:in `each'",

    [ 3] "C:in `each'",

    [ 4] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/domain_controller.rb:33:in `fetch_available_controllers'",

    [ 5] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/cvo/ldap/dc_provider.rb:43:in `fetch_domain_controllers'",

    [ 6] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/cvo/ldap/dc_provider.rb:47:in `copy_or_fetch_domain_controllers'",

    [ 7] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/cvo/ldap/dc_provider.rb:11:in `initialize'",

    [ 8] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/cvo/ldap/repository.rb:269:in `new'",

    [ 9] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/cvo/ldap/repository.rb:269:in `get_dc_provider'",

    [10] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/cvo/ldap/repository.rb:26:in `get_domain_controllers'",

    [11] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/cvo/ldap/proxy.rb:904:in `domain_host_configurations'",

    [12] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/cvo/ldap/proxy.rb:875:in `block in first_multi_host_success'",

    [13] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/cvo/ldap/proxy.rb:873:in `each'",

    [14] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/cvo/ldap/proxy.rb:873:in `first_multi_host_success'",

    [15] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/cvo/ldap/proxy.rb:113:in `connected?'",

    [16] "C:/Program Files (x86)/CloudVolumes/Manager/app/controllers/login_controller.rb:69:in `login'",

    [17] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/actionpack-3.2.22.5/lib/action_controller/metal/implicit_render.rb:4:in `send_action'",

    [18] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/actionpack-3.2.22.5/lib/abstract_controller/base.rb:167:in `process_action'",

    [19] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/actionpack-3.2.22.5/lib/action_controller/metal/rendering.rb:10:in `process_action'",

    [20] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/actionpack-3.2.22.5/lib/abstract_controller/callbacks.rb:18:in `block in process_action'",

    [21] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/activesupport-3.2.22.5/lib/active_support/callbacks.rb:448:in `block in _run__185341199__process_action__632522664__callbacks'",

    [22] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/activesupport-3.2.22.5/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_1917'",

    [23] "C:/Program Files (x86)/CloudVolumes/Manager/app/controllers/application_controller.rb:207:in `wrap_request'",

    [24] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/activesupport-3.2.22.5/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_1917'",

    [25] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/activesupport-3.2.22.5/lib/active_support/callbacks.rb:414:in `_run__185341199__process_action__632522664__callbacks'",

    [26] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/activesupport-3.2.22.5/lib/active_support/callbacks.rb:405:in `__run_callback'",

    [27] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/activesupport-3.2.22.5/lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks'",

    [28] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/activesupport-3.2.22.5/lib/active_support/callbacks.rb:81:in `run_callbacks'",

    [29] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/actionpack-3.2.22.5/lib/abstract_controller/callbacks.rb:17:in `process_action'",

    [30] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/actionpack-3.2.22.5/lib/action_controller/metal/rescue.rb:29:in `process_action'",

    [31] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/actionpack-3.2.22.5/lib/action_controller/metal/instrumentation.rb:30:in `block in process_action'",

    [32] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/activesupport-3.2.22.5/lib/active_support/notifications.rb:123:in `block in instrument'",

    [33] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/activesupport-3.2.22.5/lib/active_support/notifications/instrumenter.rb:20:in `instrument'",

    [34] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/activesupport-3.2.22.5/lib/active_support/notifications.rb:123:in `instrument'",

    [35] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/actionpack-3.2.22.5/lib/action_controller/metal/instrumentation.rb:29:in `process_action'",

    [36] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/actionpack-3.2.22.5/lib/action_controller/metal/params_wrapper.rb:207:in `process_action'",

    [37] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/activerecord-3.2.22.5/lib/active_record/railties/controller_runtime.rb:18:in `process_action'",

    [38] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/actionpack-3.2.22.5/lib/abstract_controller/base.rb:121:in `process'",

    [39] "C:/Program Files (x86)/CloudVolumes/Manager/vendor/bundle/ruby/2.2.0/gems/actionpack-3.2.22.5/lib/abstract_controller/rendering.rb:46:in `process'"

]

[2017-10-23 13:16:54 UTC]      P4932R5  INFO   Rendered text template (0.0ms)

[2017-10-23 13:16:54 UTC]      P4932R5  INFO Completed 500 Internal Server Error in 1765.7ms

0 Kudos
Ray_handels
Virtuoso
Virtuoso

Just did the upgrade in test enviornment and found out that when the manager is upgraded it seems to force it to LDAPS. If you don;t have that you can't log in anymore.

The moment you do see the loginpage showing up your database is okay.

You could try (and please try at your own risk, make sure to backup the db and blablabla... Smiley Happy )

Your base configuration is stored in the svconfigurations table. There is a column there that is called ad_ldaps. My guess is that you need to change it to 0 to enable LDAP instead of secure LDAP but this is a wild guess I must say.

pbhite
Enthusiast
Enthusiast

I suspect this is the correct answer, LDAPS gets flipped on automatically. If someone else can confirm, I'll mark it as the right answer.

I actually just wiped out the server and started over on Friday (it was pre-production anyways) and during the reinstall I found that LDAPS just simply would not work. I made sure to use the same cacert.pem and adCert.pem files that we had created from the initial install, but no matter what I did LDAPS never worked. We are on plaintext LDAP for now.

sabarishkumarr
VMware Employee
VMware Employee

Now with 2.13 LDAPS is the preferred option to Connect to Active Directory domain, But It does not flip the flag to LDAPS if it was already configured over LDAP (plain text).

Also the certificate file used for LDAPS - Active Directory verification is <Manager Install Dir>\config\adCA.pem

Regarding the original issue, seems to be an issue when some domain_controllers were down before migration (2.12) and then migrating to (2.13)

We have raised an internal issue and Engineering team is working on the resolution

However to work around the issue you can update failure_count column in domain_controllers table to 0

SQL> update domain_controllers set failure_count=0;

FlexpodVDIGuy
Contributor
Contributor

By any chance that anyone install App Volume 2.13 in any drives other than "C"?

We've successfully installed the App Volume in E Drive but the svmanager service no where to be found in either UI or registry.

We've also try to overwrite the DB since this is in the lab environment but no luck.

the only thing stands out in the svmanager_setup.log are these lines

####Copy any dependencies from dependencies\windows

The system cannot find the file specified.

File not found-*

0 Files(s) copied

(No idea what files are failing or copying)

then on the bottom of the log with RubyEncoder unable to load the following files

rgloader225.mingw.x64

rgloader225.mingw

database migration failed

LoadError:cannot load such file -- tiny_tds

(I assuming it has something to do with the file that was not copy because in the E Drive?)

0 Kudos
Norm_vB
Contributor
Contributor

We are also unable to logon to our test App Volumes server after upgrading from v2.12.1 to v2.13.0. 

Error message is 'invalid username or password' when using a valid account. 

The service account used to connect to AD is also valid.

production000001 log entries:

[2017-10-25 01:46:42 UTC]        P2432 ERROR      RADIR: Invalid Active Directory credentials

[2017-10-25 01:46:42 UTC]    P2432R138  INFO      RADIR: Connection to AD domaincontrollername failed - Took 100.07ms

[2017-10-25 01:46:42 UTC]    P2432R138 ERROR       LDAP: Unable to connect to ActiveDirectory @ domaincontrollername

[2017-10-25 01:46:42 UTC]    P2432R138 ERROR       LDAP: No connected adapter was found

[2017-10-25 01:46:42 UTC]    P2432R138  WARN        Cvo: ActiveDirectory service account failed, using current user "adminaccountname" to verify administrator access

[2017-10-25 01:46:42 UTC]    P2432R138  INFO      RADIR: serviceaccountname connecting to AD domaincontrollername  using port 389 with ssl sets to false (ssl_verify: true)

[2017-10-25 01:46:42 UTC]        P2432  INFO      RADIR: LDAP bind failed: #<OpenStruct code=0, message="Success">. Failed with result code: 49 and error message: 8009030C: LdapErr: DSID-0C09056D, comment: AcceptSecurityContext error, data 52e, v2580

***removed duplicate lines***

[2017-10-25 01:46:42 UTC]    P2432R138  WARN    Manager: Invalid username or password for "adminaccountname"

[2017-10-25 01:46:42 UTC]    P2432R138  INFO   Rendered login/login.html.erb (2.0ms)

[2017-10-25 01:46:42 UTC]    P2432R138  INFO      RADIR: Cleared the NAME_CACHE cache

[2017-10-25 01:46:42 UTC]    P2432R138  INFO      RADIR: Cleared the NAME_CACHE cache

[2017-10-25 01:46:42 UTC]    P2432R138  INFO      RADIR: Cleared the NAME_CACHE cache

[2017-10-25 01:46:42 UTC]    P2432R138  INFO Completed 200 OK in 707.0ms (Views: 1.8ms | ActiveRecord: 26.0ms)

0 Kudos
AndyHeywood
Contributor
Contributor

We also get the issue as shown by Norm_vB - have gone back to 2.12 until a fix is issued

0 Kudos
thelights
Contributor
Contributor

Agree I saw the same problem. Certificates looks good, but despite that, it will not connect.

You mention you're back on plaintext LDAP now. How exactly did you manage that?

0 Kudos
pstover
Enthusiast
Enthusiast

Saw the same thing.  Flipped DB parameter True to False for ad_ldaps and no success.  Rolled back to 2.12.1 where LDAPS 636 works fine.

0 Kudos
pstover
Enthusiast
Enthusiast

Just verified that if you are LDAP 389 and you upgrade that you see the same service failure.  My production log file looks like below when the error occurs:

[2017-10-27 01:55:45 UTC]       P620R5 ERROR    Manager: Unhandled request exception: nil can't be coerced into Fixnum

[2017-10-27 01:55:45 UTC]       P620R5 ERROR    Manager: Inspecting Array (9257840) (from log block)

[

    [ 0] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/domain_controller.rb:35:in `**'",

    [ 1] "C:/Program Files (x86)/CloudVolumes/Manager/app/models/domain_controller.rb:35:in `block in fetch_available_controllers'",

    [ 2] "C:in `each'",

    [ 3] "C:in `each'",

    [ 4] "C:/Program Files

0 Kudos
KISCharlie
Contributor
Contributor

I ran into the same issue today.   We are hosting multiple client domains on a single App Volumes deployment.

The oddity for us was that only one of the domains failed.   I attempted to edit the offending domain and reenter the password and received a message (which pops up so fast that I had to use a screen video capture program to see it) that said:

Active Directory Domain updated successfully.  But, ["Failed to update user \"DOMAIN\USERNAME\" . [\"Active Directory query failed: [\\\"Unable to connect to ActiveDirectory @ IPADDRESS\\\", \\\
"No connected adapter was found\\\", \\\"Unable to connect to ActiveDirectory @ IPADDRESS\\\", \\\"No connected adapter was found\\\", \\\"Unable to locate LDAP entry for \\\\\\"DOMAIN\\\\\\DOMAIN\\\\\\USERNAME\\\\\\"\\\"]\"]"]

(I found all of the quote escaping rather amusing)

What I just found was that, for that domain, the user ID in the AD Domain configuration had been specified in the DOMAIN\USERNAME format while the rest only had the username.  I changed it to just USERNAME and the domain would connect again and user logins are working

It seems that prior to 2.13, specifying the login ID as DOMAIN\USERNAME is acceptable but now it is not.

0 Kudos
GLTStephen
Contributor
Contributor

Literally same issue as origional poster after upgrading to 2.13. Case is opened to vmware at the moment.

0 Kudos
Joe1393
Enthusiast
Enthusiast

I had the exact same issue but I found a fix.  Before upgrading to 2.13, change your LDAP config to just basic ldap.  Do the upgrade and make sure you can sign in.  Then download your CA root cert in PEM(Base64) format.  Save that file in "C:\Program Files (x86)\CloudVolumes\Manager\config\adCA.pem".  Next, create a system variable named "SSL_CERT_FILE" and set it's value to the file path "C:\Program Files (x86)\CloudVolumes\Manager\config\adCA.pem".  Restart the appvolumes manager service, sign in and change your LDAP settings back to LDAPS.  You should also notice that under Configuration -> Settings -> Advanced Settings that "Certificate Authority File" now says (Exists).

SSL.PNG

Hope that helps

GLTStephen
Contributor
Contributor

I am fine to try those changes, but am currently in a state with the error. Is there any trick to successfully rolling back? Do i just have to wait for vmware support to acknowledge the issue.

0 Kudos
Joe1393
Enthusiast
Enthusiast

I just rolled back to 2.12.  I'm not sure about compatibility and continuing to run that way after trying to update to 2.13 but it's good enough to at least sign in and change the settings.

0 Kudos
pstover
Enthusiast
Enthusiast

Even if I use LDAP 389 with 2.12, I fail all auth after 2.13 upgrade.  I use UPN for the LDAP bind with 2.12 but have also tested with domain\username without success on an upgrade.

0 Kudos
SrGr1m
Contributor
Contributor

This is a known issues. You can call VMware Tech support which has a fix. Or you can wait until 2.13.1. Which should be out next week, hopefully.

Raymond_W
VMware Employee
VMware Employee

I'm happy to announce that App Volumes 2.13.1 already has been released with a fix for this issue.

You can read the release notes here, and download App Volumes 2.13.1 here.

Kind regards,

Raymond

Kind regards, Raymond Twitter: @raymond_himself
0 Kudos