[Solved] Sunstone authentication bad decrypt

ccesario · October 12, 2016, 3:27pm

Hello, after I upgrade my OpenNebula System from 5.0.2 to version 5.1.80 using CentOS/RHEL 7 repository, according Front-end Installation — OpenNebula 5.2.1 documentation

(yum -y update)

I’m getting the following errors when I tri authenticate by Sunstone:

Wed Oct 12 16:10:11 2016 [Z0][ReM][D]: Req:1520 UID:0 VirtualMachinePoolInfo invoked , -2, -1, -1, -1
Wed Oct 12 16:10:11 2016 [Z0][ReM][D]: Req:1520 UID:0 VirtualMachinePoolInfo result SUCCESS, “<VM_POOL>24<…”
Wed Oct 12 16:10:11 2016 [Z0][ReM][D]: Req:4560 UID:0 VirtualMachinePoolInfo invoked , -2, -1, -1, -1
Wed Oct 12 16:10:11 2016 [Z0][ReM][D]: Req:4560 UID:0 VirtualMachinePoolInfo result SUCCESS, “<VM_POOL>24<…”
Wed Oct 12 16:10:17 2016 [Z0][ReM][D]: Req:0 UID:2 UserInfo invoked , -1
Wed Oct 12 16:10:17 2016 [Z0][ReM][D]: Req:0 UID:2 UserInfo result SUCCESS, “2<GID…”
Wed Oct 12 16:10:17 2016 [Z0][AuM][D]: Message received: LOG I 2 Command execution fail: /var/lib/one/remotes/auth/server_cipher/authenticate serveradmin 15c7ae542d8de1ed95eaa87e03e1c61e4857298e ****

Wed Oct 12 16:10:17 2016 [Z0][AuM][I]: Command execution fail: /var/lib/one/remotes/auth/server_cipher/authenticate serveradmin 15c7ae542d8de1ed95eaa87e03e1c61e4857298e ****
Wed Oct 12 16:10:17 2016 [Z0][AuM][D]: Message received: LOG E 2 bad decrypt

Wed Oct 12 16:10:17 2016 [Z0][AuM][I]: bad decrypt
Wed Oct 12 16:10:17 2016 [Z0][AuM][D]: Message received: LOG I 2 ExitCode: 255

Wed Oct 12 16:10:17 2016 [Z0][AuM][I]: ExitCode: 255
Wed Oct 12 16:10:17 2016 [Z0][AuM][D]: Message received: AUTHENTICATE FAILURE 2 bad decrypt

Wed Oct 12 16:10:17 2016 [Z0][AuM][E]: Auth Error: bad decrypt
Wed Oct 12 16:10:17 2016 [Z0][ReM][D]: Req:4000 UID:-1 UserInfo invoked , -1
Wed Oct 12 16:10:17 2016 [Z0][ReM][E]: Req:4000 UID:- UserInfo result FAILURE [UserInfo] User couldn’t be authenticated, aborting call.
Wed Oct 12 16:10:35 2016 [Z0][MKP][D]: Monitoring marketplace OpenNebula Public (0)
Wed Oct 12 16:10:35 2016 [Z0][MKP][D]: Marketplace OpenNebula Public (0) successfully monitored.
Wed Oct 12 16:10:41 2016 [Z0][ReM][D]: Req:4752 UID:0 VirtualMachinePoolInfo invoked , -2, -1, -1, -1
Wed Oct 12 16:10:41 2016 [Z0][ReM][D]: Req:4752 UID:0 VirtualMachinePoolInfo result SUCCESS, “<VM_POOL>24<…”
Wed Oct 12 16:10:41 2016 [Z0][ReM][D]: Req:5024 UID:0 VirtualMachinePoolInfo invoked , -2, -1, -1, -1
Wed Oct 12 16:10:41 2016 [Z0][ReM][D]: Req:5024 UID:0 VirtualMachinePoolInfo result SUCCESS, “<VM_POOL>24<…”
Wed Oct 12 16:11:01 2016 [Z0][InM][D]: Monitoring datastore default (1)
Wed Oct 12 16:11:01 2016 [Z0][InM][D]: Monitoring datastore files (2)
Wed Oct 12 16:11:01 2016 [Z0][InM][D]: Monitoring datastore datastore1 (100)
Wed Oct 12 16:11:01 2016 [Z0][ImM][D]: Datastore default (1) successfully monitored.
Wed Oct 12 16:11:01 2016 [Z0][ImM][D]: Datastore files (2) successfully monitored.
Wed Oct 12 16:11:01 2016 [Z0][ReM][D]: Req:9936 UID:0 HostPoolInfo invoked
Wed Oct 12 16:11:01 2016 [Z0][ReM][D]: Req:9936 UID:0 HostPoolInfo result SUCCESS, “<HOST_POOL><ID…”
Wed Oct 12 16:11:01 2016 [Z0][ReM][D]: Req:9136 UID:0 SystemConfig invoked
Wed Oct 12 16:11:01 2016 [Z0][ReM][D]: Req:9136 UID:0 SystemConfig result SUCCESS, “<AUTH_MAD>…”
Wed Oct 12 16:11:01 2016 [Z0][ReM][D]: Req:6224 UID:0 HostInfo invoked , 0
Wed Oct 12 16:11:01 2016 [Z0][ReM][D]: Req:6224 UID:0 HostInfo result SUCCESS, “0<NAM…”
Wed Oct 12 16:11:01 2016 [Z0][ImM][I]: Command execution fail: /var/lib/one/remotes/datastore/vcenter/monitor PERTX0RSSVZFUl9BQ1RJT05fREFUQT48REFUQVNUT1JFPjxJRD4xMDA8L0lEPjxVSUQ+MjwvVUlEPjxHSUQ+MDwvR0lEPjxVTkFNRT5DbG91ZEFkbWluPC9VTkFNRT48R05BTUU+b25lYWRtaW48L0dOQU1FPjxOQU1FPmRhdGFzdG9yZTE8L05BTUU+PFBFUk1JU1NJT05TPjxPV05FUl9VPjE8L09XTkVSX1U+PE9XTkVSX00+MTwvT1dORVJfTT48T1dORVJfQT4wPC9PV05FUl9BPjxHUk9VUF9VPjE8L0dST1VQX1U+PEdST1VQX00+MDwvR1JPVVBfTT48R1JPVVBfQT4wPC9HUk9VUF9BPjxPVEhFUl9VPjA8L09USEVSX1U+PE9USEVSX00+MDwvT1RIRVJfTT48T1RIRVJfQT4wPC9PVEhFUl9BPjwvUEVSTUlTU0lPTlM+PERTX01BRD48IVtDREFUQVt2Y2VudGVyXV0+PC9EU19NQUQ+PFRNX01BRD48IVtDREFUQVt2Y2VudGVyXV0+PC9UTV9NQUQ+PEJBU0VfUEFUSD48IVtDREFUQVsvdmFyL2xpYi9vbmUvL2RhdGFzdG9yZXMvMTAwXV0+PC9CQVNFX1BBVEg+PFRZUEU+MDwvVFlQRT48RElTS19UWVBFPjA8L0RJU0tfVFlQRT48U1RBVEU+MDwvU1RBVEU+PENMVVNURVJTPjxJRD4wPC9JRD48L0NMVVNURVJTPjxUT1RBTF9NQj4yNzc1MDQ8L1RPVEFMX01CPjxGUkVFX01CPjY4MDUyPC9GUkVFX01CPjxVU0VEX01CPjIwOTQ1MjwvVVNFRF9NQj48SU1BR0VTPjwvSU1BR0VTPjxURU1QTEFURT48Q0xPTkVfVEFSR0VUPjwhW0NEQVRBW05PTkVdXT48L0NMT05FX1RBUkdFVD48RElTS19UWVBFPjwhW0NEQVRBW0ZJTEVdXT48L0RJU0tfVFlQRT48RFNfTUFEPjwhW0NEQVRBW3ZjZW50ZXJdXT48L0RTX01BRD48TE5fVEFSR0VUPjwhW0NEQVRBW05PTkVdXT48L0xOX1RBUkdFVD48UkVTVFJJQ1RFRF9ESVJTPjwhW0NEQVRBWy9dXT48L1JFU1RSSUNURURfRElSUz48U0FGRV9ESVJTPjwhW0NEQVRBWy92YXIvdG1wXV0+PC9TQUZFX0RJUlM+PFRNX01BRD48IVtDREFUQVt2Y2VudGVyXV0+PC9UTV9NQUQ+PFZDRU5URVJfQ0xVU1RFUj48IVtDREFUQVtDbHVzdGVyQ2xvdWRdXT48L1ZDRU5URVJfQ0xVU1RFUj48L1RFTVBMQVRFPjwvREFUQVNUT1JFPjwvRFNfRFJJVkVSX0FDVElPTl9EQVRBPg== 100
Wed Oct 12 16:11:01 2016 [Z0][ImM][I]: Error monitoring datastore1. Reason: Error decrypting vCenter password
Wed Oct 12 16:11:01 2016 [Z0][ImM][I]: ExitCode: 255
Wed Oct 12 16:11:01 2016 [Z0][ImM][E]: Error monitoring datastore 100: LQ==. Decoded info: -

Currently the system are running these packages versions:

opennebula-sunstone-5.1.80-1.x86_64
opennebula-common-5.1.80-1.x86_64
opennebula-5.1.80-1.x86_64
opennebula-server-5.1.80-1.x86_64
opennebula-ruby-5.1.80-1.x86_64
opennebula-flow-5.1.80-1.x86_64

Using CLI i can run the one* commands without problem.

There are any procedure to fix it? I did not found nothing in official documentation.

Thanks in advance

-Carlos

ccesario · October 12, 2016, 11:34pm

Additional info:

[root@localhost one]# oneuser show 1 -x

<USER>
  <ID>1</ID>
  <GID>0</GID>
  <GROUPS>
    <ID>0</ID>
  </GROUPS>
  <GNAME>oneadmin</GNAME>
  <NAME>serveradmin</NAME>
  <PASSWORD><![CDATA[5baa61e4c9b93f3f0682250b6cf8331b7ee68fd8]]></PASSWORD>
  <AUTH_DRIVER><![CDATA[server_cipher]]></AUTH_DRIVER>
  <ENABLED>1</ENABLED>
  <TEMPLATE>
    <TOKEN_PASSWORD><![CDATA[942b3ba171f538aae6c180e358a26aa827e278c6]]></TOKEN_PASSWORD>
  </TEMPLATE>
  <DATASTORE_QUOTA/>
  <NETWORK_QUOTA/>
  <VM_QUOTA>
    <VM>
      <CPU><![CDATA[-1]]></CPU>
      <CPU_USED><![CDATA[0]]></CPU_USED>
      <MEMORY><![CDATA[-1]]></MEMORY>
      <MEMORY_USED><![CDATA[0]]></MEMORY_USED>
      <SYSTEM_DISK_SIZE><![CDATA[-1]]></SYSTEM_DISK_SIZE>
      <SYSTEM_DISK_SIZE_USED><![CDATA[0]]></SYSTEM_DISK_SIZE_USED>
      <VMS><![CDATA[-1]]></VMS>
      <VMS_USED><![CDATA[0]]></VMS_USED>
    </VM>
  </VM_QUOTA>
  <IMAGE_QUOTA/>
  <DEFAULT_USER_QUOTAS>
    <DATASTORE_QUOTA/>
    <NETWORK_QUOTA/>
    <VM_QUOTA/>
    <IMAGE_QUOTA/>
  </DEFAULT_USER_QUOTAS>
</USER>


[root@localhost .one]# for file in $(ls); do echo $file; cat $file; echo -----; done
ec2_auth
serveradmin:5baa61e4c9b93f3f0682250b6cf8331b7ee68fd8
-----
occi_auth
serveradmin:5baa61e4c9b93f3f0682250b6cf8331b7ee68fd8
-----
one_auth
oneadmin:password
-----
oneflow_auth
serveradmin:5baa61e4c9b93f3f0682250b6cf8331b7ee68fd8
-----
onegate_auth
serveradmin:5baa61e4c9b93f3f0682250b6cf8331b7ee68fd8
-----
one_key
5baa61e4c9b93f3f0682250b6cf8331b7ee68fd8
-----
sunstone_auth
serveradmin:5baa61e4c9b93f3f0682250b6cf8331b7ee68fd8
-----

Any tip folks?

Best regards,

-Carlos

ruben · October 13, 2016, 10:07am

Somehow, the password for opennebula services has been changed, this should
not happen during an upgrade.Can you confirm that you did not change them?

Reset serveradmin password:

Change it in oned, note that passwd is hashed

oneuser passwd --sha1 serveradmin  <new_passwd>

Update auth files wit passwd in plain text

echo "serveradmin:<new_passwd>" > sunstone_auth

Cheers

ccesario · October 13, 2016, 11:40am

Hello @ruben,

Thank you by your answer!

Yes, I did not change none. I did not touched in none config. Only using yum tool.

Even following your suggests, the problem persist.

[root@localhost ~]# oneuser passwd --sha1 serveradmin password
[root@localhost ~]# echo "serveradmin:password" > /var/lib/one/.one/sunstone_auth 
[root@localhost ~]# systemctl restart opennebula.service
[root@localhost ~]# systemctl restart opennebula-sunstone.service
[root@localhost ~]# oneuser list
  ID NAME            GROUP      AUTH           VMS            MEMORY         CPU
   0 oneadmin        oneadmin   core             -                 -           -
   1 serveradmin     oneadmin   server_c   0 /   -      0M /       -   0.0 /   -
   2 demo            demo       core       0 /   5      0M /    4.9G   0.0 / 6.0
[root@localhost ~]#

The log result:

Thu Oct 13 12:33:22 2016 [Z0][ReM][D]: Req:1120 UID:3 UserInfo invoked , -1
Thu Oct 13 12:33:22 2016 [Z0][ReM][D]: Req:1120 UID:3 UserInfo result SUCCESS, “3<GID…”
Thu Oct 13 12:33:22 2016 [Z0][AuM][D]: Message received: LOG I 4 Command execution fail: /var/lib/one/remotes/auth/server_cipher/authenticate serveradmin 5baa61e4c9b93f3f0682250b6cf8331b7ee68fd8 ****

Thu Oct 13 12:33:22 2016 [Z0][AuM][I]: Command execution fail: /var/lib/one/remotes/auth/server_cipher/authenticate serveradmin 5baa61e4c9b93f3f0682250b6cf8331b7ee68fd8 ****
Thu Oct 13 12:33:22 2016 [Z0][AuM][D]: Message received: LOG E 4 bad decrypt

Thu Oct 13 12:33:22 2016 [Z0][AuM][I]: bad decrypt
Thu Oct 13 12:33:22 2016 [Z0][AuM][D]: Message received: LOG I 4 ExitCode: 255

Thu Oct 13 12:33:22 2016 [Z0][AuM][I]: ExitCode: 255
Thu Oct 13 12:33:22 2016 [Z0][AuM][D]: Message received: AUTHENTICATE FAILURE 4 bad decrypt

Thu Oct 13 12:33:22 2016 [Z0][AuM][E]: Auth Error: bad decrypt
Thu Oct 13 12:33:22 2016 [Z0][ReM][D]: Req:8240 UID:-1 UserInfo invoked , -1
Thu Oct 13 12:33:22 2016 [Z0][ReM][E]: Req:8240 UID:- UserInfo result FAILURE [UserInfo] User couldn’t be authenticated, aborting call.

Any other tip?

Best regards,

-Carlos

ruben · October 13, 2016, 1:40pm

Sorry, I cannot reproduce it. Your fisrt setup was wrong because the
password in OpenNebula and sunstone_auth were the same; and OpenNebula
stores a hash of the password. try to restart again sunstone, (make sure it
is not running)…

ruben · October 13, 2016, 1:42pm

Also make sure that you updated the right files, as they are read by
Sunstone server /var/lib/one/.one/sunstone.auth

ruben · October 13, 2016, 1:48pm

Hold on, there were a bug with serveradmin auth in beta, and now I’m not
sure if the packages got that. can you check line 167 of one_auth_mad.rb,

timeout = arg.to_i

ccesario · October 13, 2016, 2:02pm

Hi @ruben,

I already restart several times the service and recheck the files.

In the line 167 of one_auth_mad.rb file I got this

[root@localhost one]# sed -n ‘167p’ /usr/lib/one/mads/one_auth_mad.rb
rc = LocalCommand.run(command, log_method(request_id))
[root@localhost one]#

best regards,

Carlos

ccesario · October 13, 2016, 6:22pm

Hi @ruben,

Only to report the procedure:

After remove all packs and reinstall (using yum) and restore database content, I’m able to login on Sunstone.
I needed to change the vCenter credentials, because I was getting error bad decrypt on vCenter monitoring.

But, even Sunstone are working, I still see these errors in log file.

Thu Oct 13 19:19:29 2016 [Z0][AuM][D]: Message received: LOG I 257 Command execution fail: /var/lib/one/remotes/auth/server_cipher/authenticate serveradmin 5baa61e4c9b93f3f0682250b6cf8331b7ee68fd8 ****

Thu Oct 13 19:19:29 2016 [Z0][AuM][I]: Command execution fail: /var/lib/one/remotes/auth/server_cipher/authenticate serveradmin 5baa61e4c9b93f3f0682250b6cf8331b7ee68fd8 ****
Thu Oct 13 19:19:29 2016 [Z0][AuM][D]: Message received: LOG D 257 authenticate: Authenticating serveradmin, with password 5baa61e4c9b93f3f0682250b6cf8331b7ee68fd8 (f1oj2j5DSlygv4b6iM2AiurwcRjcMCZQXJ7s8fVR598pcQO5XxNOodx1i3V/DyhV)

Thu Oct 13 19:19:29 2016 [Z0][AuM][I]: authenticate: Authenticating serveradmin, with password 5baa61e4c9b93f3f0682250b6cf8331b7ee68fd8 (f1oj2j5DSlygv4b6iM2AiurwcRjcMCZQXJ7s8fVR598pcQO5XxNOodx1i3V/DyhV)
Thu Oct 13 19:19:29 2016 [Z0][AuM][D]: Message received: LOG E 257 bad decrypt

Thu Oct 13 19:19:29 2016 [Z0][AuM][I]: bad decrypt
Thu Oct 13 19:19:29 2016 [Z0][AuM][D]: Message received: LOG I 257 ExitCode: 255

Thu Oct 13 19:19:29 2016 [Z0][AuM][I]: ExitCode: 255
Thu Oct 13 19:19:29 2016 [Z0][AuM][D]: Message received: AUTHENTICATE FAILURE 257 bad decrypt

Thu Oct 13 19:19:29 2016 [Z0][AuM][E]: Auth Error: bad decrypt
Thu Oct 13 19:19:29 2016 [Z0][ReM][D]: Req:6560 UID:-1 DocumentPoolInfo invoked , -2, -1, -1, 100
Thu Oct 13 19:19:29 2016 [Z0][ReM][E]: Req:6560 UID:- DocumentPoolInfo result FAILURE [DocumentPoolInfo] User couldn't be authenticated, aborting call.

But I don’t see errors in Sunstone GUI.

Any other tip!?

best regards,

-Carlos

ruben · October 14, 2016, 8:55am

This is probably from oneflow server, oneflow_auth not updated?

ccesario · October 14, 2016, 2:59pm

Hi @ruben,

All packs were updated.
Look

[root@localhost one]# rpm -qa | grep -i opennebul
opennebula-sunstone-5.1.80-1.x86_64
opennebula-common-5.1.80-1.x86_64
opennebula-5.1.80-1.x86_64
opennebula-server-5.1.80-1.x86_64
opennebula-ruby-5.1.80-1.x86_64
opennebula-flow-5.1.80-1.x86_64

Best regards,

-Carlos

ccesario · October 14, 2016, 7:19pm

Hi @ruben,

After update the /var/lib/one/.one/oneflow_auth file the log does not show errors

echo "serveradmin:<new_passwd>" > oneflow_auth

I will try investigate the root cause of this.

Thank you by your help!

-Carlos

Topic		Replies	Views
Upgrade 5.8.5 to 5.10.0-1. Users can't login in Sunstone Community Support	3	1034	November 27, 2019
Authentication user problem after upgrade 5.12 -> 6.0.2 upgrade GUI - Sunstone	2	444	July 15, 2021
Reg sunstone - auth error Community Support	1	1642	May 13, 2015
[SOLVED] User couldn't be authenticated - Sunstone GUI - Sunstone solved	14	4366	February 24, 2020
Can't Auth after DB Restore Community Support	3	403	July 9, 2019

[Solved] Sunstone authentication bad decrypt

Related Topics