Manageiq: Sporadic failures with fix_auth

[Fryguy]

https://travis-ci.com/github/ManageIQ/manageiq/jobs/482314040#L719

Failures:

  1) FixAuth::AuthModel#authentications #recrypt should raise exception for bad encryption

     Failure/Error: expect { subject.fix_passwords(bad) }.to raise_error(ManageIQ::Password::PasswordError)

       expected ManageIQ::Password::PasswordError but nothing was raised

     # ./spec/tools/fix_auth/auth_model_spec.rb:84:in `block (4 levels) in <top (required)>'

Finished in 6 minutes 20 seconds (files took 23.47 seconds to load)

6594 examples, 1 failure, 1 pending

Failed examples:

rspec ./spec/tools/fix_auth/auth_model_spec.rb:83 # FixAuth::AuthModel#authentications #recrypt should raise exception for bad encryption

Randomized with seed 63041

https://travis-ci.com/github/ManageIQ/manageiq/jobs/482035822#L744

  1) FixAuth::AuthConfigModel#request_tasks upgrades request (find with prefix, do not stringify keys)

     Failure/Error: expect(new_options[:sysprep_domain_password]).to be_encrypted(pass)

       expected: "v2:{np5Ic073+KV6linyemO2mg==}" to be encrypted and decrypt to "password"

     # ./spec/tools/fix_auth/auth_config_model_spec.rb:75:in `block (3 levels) in <top (required)>'

Finished in 8 minutes 35 seconds (files took 20.11 seconds to load)

5368 examples, 1 failure, 2 pending

Failed examples:

rspec ./spec/tools/fix_auth/auth_config_model_spec.rb:67 # FixAuth::AuthConfigModel#request_tasks upgrades request (find with prefix, do not stringify keys)

Randomized with seed 20012

[Fryguy]

@kbrock I'm not sure what changed that could affect this, but we've had 2 sporadic fix_auth issues that seem kind of related. Can you take a look?

[kbrock]

I'll dive into this more.

We did change this code when changing the v1/v2 interface. Specifically the use case around having a multiple keys and recrypt-ing.

The tale of two keys

Encryption software works in an interesting way. It decrypts an encrypted string and then does a checksum to ensure that the decryption key used was appropriate for the encrypted string. But it is possible that while using the wrong decryption key yields gibberish, the checksum passes and it thinks that the key was correct and the decryption worked. It is a low odds for sure, but for every pair of encryption keys, there are probably just a hand full of phrases that will fool the crc checksum.

So it is possible that the encryption key and decryption key, hit this crc check error. But we should not see a swath of this type of errors - especially with the way that we have changed our apis. It is possible that we didn't get our logic correct so it exposes us to this situation more than before.

I guess it is also possible that the after block doesn't properly clean things up.

[Fryguy]

Is this related to https://github.com/ManageIQ/manageiq-gems-pending/pull/513 ?

[jrafanie]

I had the second issue happen just now, the build log is gone now that I restarted it but it was this one:

  1) FixAuth::AuthConfigModel#request_tasks upgrades request (find with prefix, do not stringify keys)

     Failure/Error: expect(new_options[:sysprep_domain_password]).to be_encrypted(pass)

       expected: "v2:{np5Ic073+KV6linyemO2mg==}" to be encrypted and decrypt to "password"

     # ./spec/tools/fix_auth/auth_config_model_spec.rb:75:in `block (3 levels) in <top (required)>'

[kbrock]

Is this related to ManageIQ/manageiq-gems-pending#513 ?
-- @Fryguy

not that PR in particular, but that group of changes. it is probably related to the API changes in setting keys for miq-password and possibly the recrypt code in miq-password.

[kbrock]

did the behavior of decrypting an empty string change and return a nil instead of returning a blank string or something?

I wonder if we need to rework the rescue block in there. The old rescue block was quite complex before. That may have avoided the problem we are seeing now. Or are the test failures we are seeing having nothing to do with the recrypt code?

recrypt has a ||= and I wonder if that is what is messing us up.

[Fryguy]

I don't think so... We haven't touched that in a while

[Fryguy]

Got one again - https://travis-ci.com/github/ManageIQ/manageiq/jobs/495533954#L895-L898

  1) FixAuth::AuthModel#authentications #recrypt should raise exception for bad encryption

     Failure/Error: expect { subject.fix_passwords(bad) }.to raise_error(ManageIQ::Password::PasswordError)

       expected ManageIQ::Password::PasswordError but nothing was raised

     # ./spec/tools/fix_auth/auth_model_spec.rb:84:in `block (4 levels) in <top (required)>'

[Fryguy]

I wonder if this is because of parallel specs....wonder if they are clobbering each others v2 keys, perhaps by not using tmp path locations that are unique? I can't understand how the follow could possibly happen otherwise:

https://travis-ci.com/github/ManageIQ/manageiq/jobs/496103931#L823

  1) FixAuth::AuthModel#miq_database upgrades

     Failure/Error: expect(subject.fix_passwords(newer).session_secret_token).to eq(enc_new)

       expected: "v2:{BkTmRrehAeNfBdFKDPvIIA==}"

            got: "v2:{RvdmXnwDZNYuicK1J0H0OQ==}"

       (compared using ==)

     # ./spec/tools/fix_auth/auth_model_spec.rb:124:in `block (3 levels) in <top (required)>'

[kbrock]

I thought all v2 keys were in memory tests. don't remember writing anything to disk for these tests

[Fryguy]

Oh maybe? I assumed v2_keys had to be on disk.

[jrafanie]

I thought all v2 keys were in memory tests. don't remember writing anything to disk for these tests

I don't know if you've identified the issue causing this failure and if it's fixed in https://github.com/ManageIQ/manageiq/pull/21178 but it's easy enough to recreate in the auth_config_model_spec.rb locally without PARALLEL or anything. Just crank up the count of times it runs the test and it fails most times, even multiple times.

Note, I tried the same thing with the manageiq-password test suite and couldn't get it to fail no matter how many times I forced each test to run.

It does occur fairly easy with the fix_auth test though so perhaps it's specific with this test or setup. See below.

diff --git a/spec/tools/fix_auth/auth_config_model_spec.rb b/spec/tools/fix_auth/auth_config_model_spec.rb
index e3b9086476..67ffac3737 100644
--- a/spec/tools/fix_auth/auth_config_model_spec.rb
+++ b/spec/tools/fix_auth/auth_config_model_spec.rb
@@ -48,7 +48,8 @@ RSpec.describe FixAuth::AuthConfigModel do
     end
   end

-  context "#request_tasks" do
+1000.times do |i|
+  context "#request_tasks #{i}" do
     subject { FixAuth::FixMiqRequestTask }
     let(:request) do
       subject.create(
@@ -76,3 +77,4 @@ RSpec.describe FixAuth::AuthConfigModel do
     end
   end
 end
+end

joerafaniello@Joes-MBP-2 manageiq % be rspec spec/tools/fix_auth/auth_config_model_spec.rb
** override_gem("manageiq-gems-pending", :path=>"/Users/joerafaniello/Code/manageiq-gems-pending") at /Users/joerafaniello/Code/manageiq/bundler.d/Gemfile.dev.rb:13
** Using session_store: ActionDispatch::Session::MemoryStore
** ManageIQ master, codename: Morphy

Randomized with seed 48240
.........................................................................................................................................................................................................F...........................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................F...................................................................................................................................................................................................

Failures:

  1) FixAuth::AuthConfigModel#request_tasks 630 upgrades request (find with prefix, do not stringify keys)
     Failure/Error: expect(new_options[:sysprep_domain_password]).to be_encrypted(pass)
       expected: "v2:{xQQXbxWHMAarXYxni/o8fw==}" to be encrypted and decrypt to "password"
     # ./spec/tools/fix_auth/auth_config_model_spec.rb:76:in `block (4 levels) in <top (required)>'
     # /Users/joerafaniello/.gem/ruby/2.6.6/gems/webmock-3.13.0/lib/webmock/rspec.rb:37:in `block (2 levels) in <top (required)>'

  2) FixAuth::AuthConfigModel#request_tasks 334 upgrades request (find with prefix, do not stringify keys)
     Failure/Error: expect(new_options[:sysprep_domain_password]).to be_encrypted(pass)
       expected: "v2:{DFtIFBQDjOkXeeYfw2Zlhg==}" to be encrypted and decrypt to "password"
     # ./spec/tools/fix_auth/auth_config_model_spec.rb:76:in `block (4 levels) in <top (required)>'
     # /Users/joerafaniello/.gem/ruby/2.6.6/gems/webmock-3.13.0/lib/webmock/rspec.rb:37:in `block (2 levels) in <top (required)>'

Finished in 8.17 seconds (files took 15.06 seconds to load)
1001 examples, 2 failures

Failed examples:

rspec './spec/tools/fix_auth/auth_config_model_spec.rb[1:632:1]' # FixAuth::AuthConfigModel#request_tasks 630 upgrades request (find with prefix, do not stringify keys)
rspec './spec/tools/fix_auth/auth_config_model_spec.rb[1:336:1]' # FixAuth::AuthConfigModel#request_tasks 334 upgrades request (find with prefix, do not stringify keys)

Randomized with seed 48240

joerafaniello@Joes-MBP-2 manageiq % be rspec spec/tools/fix_auth/auth_config_model_spec.rb
** override_gem("manageiq-gems-pending", :path=>"/Users/joerafaniello/Code/manageiq-gems-pending") at /Users/joerafaniello/Code/manageiq/bundler.d/Gemfile.dev.rb:13
** Using session_store: ActionDispatch::Session::MemoryStore
** ManageIQ master, codename: Morphy

Randomized with seed 50568
..........................................................................................................................................................................................................................................................F............................................................................................................................................................................................................................F.........................................................................................F..........................................................................................................................................F...................................................................................................F...................................................................................................................................................................................F....................

Failures:

  1) FixAuth::AuthConfigModel#request_tasks 192 upgrades request (find with prefix, do not stringify keys)
     Failure/Error: expect(new_options[:sysprep_domain_password]).to be_encrypted(pass)
       expected: "v2:{fmnC7KQaqxEeuOm7TsjXyw==}" to be encrypted and decrypt to "password"
     # ./spec/tools/fix_auth/auth_config_model_spec.rb:76:in `block (4 levels) in <top (required)>'
     # /Users/joerafaniello/.gem/ruby/2.6.6/gems/webmock-3.13.0/lib/webmock/rspec.rb:37:in `block (2 levels) in <top (required)>'

  2) FixAuth::AuthConfigModel#request_tasks 735 upgrades request (find with prefix, do not stringify keys)
     Failure/Error: expect(new_options[:sysprep_domain_password]).to be_encrypted(pass)
       expected: "v2:{gyN/UvEAA4zU03WttaF+VA==}" to be encrypted and decrypt to "password"
     # ./spec/tools/fix_auth/auth_config_model_spec.rb:76:in `block (4 levels) in <top (required)>'
     # /Users/joerafaniello/.gem/ruby/2.6.6/gems/webmock-3.13.0/lib/webmock/rspec.rb:37:in `block (2 levels) in <top (required)>'

  3) FixAuth::AuthConfigModel#request_tasks 522 upgrades request (find with prefix, do not stringify keys)
     Failure/Error: expect(new_options[:sysprep_domain_password]).to be_encrypted(pass)
       expected: "v2:{Q4aOWAlKccxrIU74vjpuHA==}" to be encrypted and decrypt to "password"
     # ./spec/tools/fix_auth/auth_config_model_spec.rb:76:in `block (4 levels) in <top (required)>'
     # /Users/joerafaniello/.gem/ruby/2.6.6/gems/webmock-3.13.0/lib/webmock/rspec.rb:37:in `block (2 levels) in <top (required)>'

  4) FixAuth::AuthConfigModel#request_tasks 483 upgrades request (find with prefix, do not stringify keys)
     Failure/Error: expect(new_options[:sysprep_domain_password]).to be_encrypted(pass)
       expected: "v2:{UM4wbTxyacWRrldMOTsbQg==}" to be encrypted and decrypt to "password"
     # ./spec/tools/fix_auth/auth_config_model_spec.rb:76:in `block (4 levels) in <top (required)>'
     # /Users/joerafaniello/.gem/ruby/2.6.6/gems/webmock-3.13.0/lib/webmock/rspec.rb:37:in `block (2 levels) in <top (required)>'

  5) FixAuth::AuthConfigModel#request_tasks 401 upgrades request (find with prefix, do not stringify keys)
     Failure/Error: expect(new_options[:sysprep_domain_password]).to be_encrypted(pass)
       expected: "v2:{djAYxZp9KvdlTF2PU1BneA==}" to be encrypted and decrypt to "password"
     # ./spec/tools/fix_auth/auth_config_model_spec.rb:76:in `block (4 levels) in <top (required)>'
     # /Users/joerafaniello/.gem/ruby/2.6.6/gems/webmock-3.13.0/lib/webmock/rspec.rb:37:in `block (2 levels) in <top (required)>'

  6) FixAuth::AuthConfigModel#request_tasks 687 upgrades request (find with prefix, do not stringify keys)
     Failure/Error: expect(new_options[:sysprep_domain_password]).to be_encrypted(pass)
       expected: "v2:{fKc5BiuJtenAlPzYiutg8g==}" to be encrypted and decrypt to "password"
     # ./spec/tools/fix_auth/auth_config_model_spec.rb:76:in `block (4 levels) in <top (required)>'
     # /Users/joerafaniello/.gem/ruby/2.6.6/gems/webmock-3.13.0/lib/webmock/rspec.rb:37:in `block (2 levels) in <top (required)>'

Finished in 6.35 seconds (files took 12.92 seconds to load)
1001 examples, 6 failures

Failed examples:

rspec './spec/tools/fix_auth/auth_config_model_spec.rb[1:194:1]' # FixAuth::AuthConfigModel#request_tasks 192 upgrades request (find with prefix, do not stringify keys)
rspec './spec/tools/fix_auth/auth_config_model_spec.rb[1:737:1]' # FixAuth::AuthConfigModel#request_tasks 735 upgrades request (find with prefix, do not stringify keys)
rspec './spec/tools/fix_auth/auth_config_model_spec.rb[1:524:1]' # FixAuth::AuthConfigModel#request_tasks 522 upgrades request (find with prefix, do not stringify keys)
rspec './spec/tools/fix_auth/auth_config_model_spec.rb[1:485:1]' # FixAuth::AuthConfigModel#request_tasks 483 upgrades request (find with prefix, do not stringify keys)
rspec './spec/tools/fix_auth/auth_config_model_spec.rb[1:403:1]' # FixAuth::AuthConfigModel#request_tasks 401 upgrades request (find with prefix, do not stringify keys)
rspec './spec/tools/fix_auth/auth_config_model_spec.rb[1:689:1]' # FixAuth::AuthConfigModel#request_tasks 687 upgrades request (find with prefix, do not stringify keys)

Randomized with seed 50568

[Fryguy]

Awesome find @jrafanie ... no ones been able to get a reproducer.

[Fryguy]

manageiq-password 1.0/master branch completely changed re-crypt - I've been trying to get to the 1.0 release in https://github.com/ManageIQ/manageiq/pull/21178 , but I have to change a ton of repos and haven't had a chance.

[jrafanie]

Awesome find @jrafanie ... no ones been able to get a reproducer.

Yay, given enough 👀 , any issue is solvable!

[jrafanie]

manageiq-password 1.0/master branch completely changed re-crypt - I've been trying to get to the 1.0 release in #21178 , but I have to change a ton of repos and haven't had a chance.

Do you think it's fixed in 1.0?

[Fryguy]

depends what the problem is...I'll dig into this

[Fryguy]

Ok, I dug in and I think I know what the issue is. With ManageIQ::Password, there is a possibility that 2 independent keys can decrypt the same crypttext "successfully", where "successfully" means it doesn't blow up, but does _not_ imply that it decrypts the crypttext "properly". @kbrock said as much in https://github.com/ManageIQ/manageiq/issues/21042#issuecomment-777737994 . For example:

$ irb
> require "manageiq-password"

> ManageIQ::Password.v2_key = ManageIQ::Password::Key.new(nil, "uXfIgSAUq5Oz8goc/zI8HOOo0SI++Sd9mfpgBanYIM4=")
> enc = ManageIQ::Password.new.encrypt("password")
=> "v2:{BkTmRrehAeNfBdFKDPvIIA==}"

#
# Decrypting with a different key you would expect it to blow up
#
> ManageIQ::Password.keys["alt"] = ManageIQ::Password::Key.new(nil, "Hb6wJyP+NxsNHZiHeagXGdgGo3h4c8XsaE5U7/8XexA=")
> dec = ManageIQ::Password.new.decrypt(enc, ManageIQ::Password.keys["alt"])
# Traceback (most recent call last):
#    5: from (pry):6:in `__pry__'
#    4: from ~/.gem/ruby/2.7.2/gems/manageiq-password-0.3.0/lib/manageiq/password.rb:41:in `decrypt'
#    3: from ~/.gem/ruby/2.7.2/gems/manageiq-password-0.3.0/lib/manageiq/password.rb:236:in `decrypt64'
#    2: from ~/.gem/ruby/2.7.2/gems/manageiq-password-0.3.0/lib/manageiq/password.rb:232:in `decrypt'
#    1: from ~/.gem/ruby/2.7.2/gems/manageiq-password-0.3.0/lib/manageiq/password.rb:264:in `apply'
# ~/.gem/ruby/2.7.2/gems/manageiq-password-0.3.0/lib/manageiq/password.rb:264:in `final': bad decrypt (OpenSSL::Cipher::CipherError)
#    2: from (pry):6:in `__pry__'
#    1: from ~/.gem/ruby/2.7.2/gems/manageiq-password-0.3.0/lib/manageiq/password.rb:40:in `decrypt'
# ~/.gem/ruby/2.7.2/gems/manageiq-password-0.3.0/lib/manageiq/password.rb:43:in `rescue in decrypt': can not decrypt v2_key encrypted string (ManageIQ::Password::PasswordError)

#
# But sometimes it *doesn't* blow up, even though it also doesn't decrypt it properly
#
> ManageIQ::Password.keys["alt"] = ManageIQ::Password::Key.new(nil, "XamduEwrkgMSeLjl+LQeutAWsLgKi3tR1mdEtclDPyM=")
> dec = ManageIQ::Password.new.decrypt(enc, ManageIQ::Password.keys["alt"])
=> "\xEF\xED\x8AY[\xE0\xB0\xE6\u0016\xD0\xFF\\>\xA4\xF2"

Note: these keys were extracted from passing/failing tests for this specific plaintext (password). If you change the plaintext you need to find new colliding keys.

---

The way recrypt is written, if first tries to decrypt with the legacy key, expecting it to blow up on unencrypted strings and strings already encrypted with the new key. After blowing up, it then will try decrypting with the new key. This allows recrypt to deal with any strings that are already recrypted, making it idempotent.

However, since it _relies_ on it blowing up, there are chances where recrypt will "successfully" convert these passwords into garbage, which is what this test is failing on.

---

I'm a little stumped on how to actually fix this...need to put my thinking cap on 🤔

[Fryguy]

FWIW, I created the following spec to simplify recreation:

In auth_config_model_spec.rb:

  describe "ManageIQ::Password#decrypt" do
    context "good" do
      let(:legacy_key) { ManageIQ::Password::Key.new(nil, "Hb6wJyP+NxsNHZiHeagXGdgGo3h4c8XsaE5U7/8XexA=") }

      it "works" do
        expect(ManageIQ::Password.new.recrypt(enc_new)).to be_encrypted(pass)
      end
    end

    context "bad" do
      let(:legacy_key) { ManageIQ::Password::Key.new(nil, "XamduEwrkgMSeLjl+LQeutAWsLgKi3tR1mdEtclDPyM=") }

      it "works" do
        expect(ManageIQ::Password.new.recrypt(enc_new)).to be_encrypted(pass)
      end
    end
  end

[jrafanie]

The way recrypt is written, if first tries to decrypt with the legacy key, expecting it to blow up on unencrypted strings and strings already encrypted with the new key. After blowing up, it then will try decrypting with the new key. This allows recrypt to deal with any strings that are already recrypted, making it idempotent.

I mentioned this in chat....can we check if the encoding is valid after decrypt?

irb(main):002:0> "\xEF\xED\x8AY[\xE0\xB0\xE6\u0016\xD0\xFF\\>\xA4\xF2".valid_encoding?
=> false

In other words, can it raise an InvalidEncoding exception (note, I don't see this as an actual exception class in the Encoding namespace 🤷 , so I guess you'd have to create it) in the low level decrypt on invalid encodings so you can continue to catch exceptions in recrypt and handle them properly?

[Fryguy]

That's a brilliant idea. Let me give that a try.

[Fryguy]

That worked great @jrafanie - fixed in #21239