OpenNebula 6.0 Authentication stopped working

AaronLea · April 28, 2021, 2:23pm

Hello everybody
I started installing Opennebula 6.0 3 weeks ago. Thanks to the good instructions, that worked relatively well.
When I tried to log in today I got the message “Invalid username or password” or “OpenNebula is not running or there was a server exception. Please check the server logs.”

in the server logs it is roughly the same everywhere.
/oned.log:

Wed Apr 28 13:47:47 2021 [Z0] [AuM] [E]: Token has expired.
Wed Apr 28 13:47:47 2021 [Z0] [ReM] [D]: Req: 8352 UID: -1 IP: 127.0.0.1 one.system.config invoked
Wed Apr 28 13:47:47 2021 [Z0] [ReM] [E]: Req: 8352 UID: - one.system.config result FAILURE [one.system.config] User couldn't be authenticated, aborting call.
Wed Apr 28 13:47:49 2021 [Z0] [AuM] [E]: Token has expired.
Wed Apr 28 13:47:49 2021 [Z0] [ReM] [D]: Req: 2272 UID: -1 IP: 127.0.0.1 one.system.config invoked
Wed Apr 28 13:47:49 2021 [Z0] [ReM] [E]: Req: 2272 UID: - one.system.config result FAILURE [one.system.config] User couldn't be authenticated, aborting call.

/sunstone.log:

Wed Apr 28 13:46:06 2021 [E]: user.info error: [one.user.info] User couldn't be authenticated, aborting call.
Wed Apr 28 13:46:06 2021 [I]: 10.100.110.118 - - [28 / Apr / 2021: 13: 46: 06 +0200] "POST / login HTTP / 1.1" 500 - 0.2463

even the CLI does not work
onevm list
[one.vmpool.info] User couldn't be authenticated, aborting call.

The user data of the oneadmin have not been changed since the first use, the MySQL database still contains the correct password for the user as SHA-256 hash.

At the time of the first error I cannot find any log entries that lead me to the solution
/oned.log:

Tue Apr 27 14:56:59 2021 [Z0] [ReM] [D]: Req: 8816 UID: 0 IP: 127.0.0.1 one.zone.raftstatus invoked
Tue Apr 27 14:56:59 2021 [Z0] [ReM] [D]: Req: 8816 UID: 0 one.zone.raftstatus result SUCCESS, "<RAFT> <SERVER_ID> -1 <..."
Tue Apr 27 14:56:59 2021 [Z0] [ReM] [D]: Req: 6928 UID: 0 IP: 127.0.0.1 one.vmpool.infoextended invoked, -2, -1, -1, -1
Tue Apr 27 14:56:59 2021 [Z0] [ReM] [D]: Req: 6928 UID: 0 one.vmpool.infoextended result SUCCESS, "<VM_POOL> <VM> <ID> 418 ..."
Tue Apr 27 14:56:59 2021 [Z0] [ReM] [D]: Req: 8288 UID: 0 IP: 127.0.0.1 one.vmpool.infoextended invoked, -2, -1, -1, -1
Tue Apr 27 14:56:59 2021 [Z0] [ReM] [D]: Req: 8288 UID: 0 one.vmpool.infoextended result SUCCESS, "<VM_POOL> <VM> <ID> 418 ..."
Tue Apr 27 14:57:14 2021 [Z0] [AuM] [E]: Token has expired.
Tue Apr 27 14:57:14 2021 [Z0] [ReM] [D]: Req: 8016 UID: -1 IP: 127.0.0.1 one.zone.raftstatus invoked
Tue Apr 27 14:57:14 2021 [Z0] [ReM] [E]: Req: 8016 UID: - one.zone.raftstatus result FAILURE [one.zone.raftstatus] User couldn't be authenticated, aborting call.
Tue Apr 27 14:57:25 2021 [Z0] [DBM] [I]: Purging obsolete LogDB records: 0 records purged. Log state: 0.0 - 0.0
Tue Apr 27 14:57:25 2021 [Z0] [DBM] [I]: Purging obsolete federated LogDB records: 0 records purged. Federated log size: 0.
Tue Apr 27 14:57:28 2021 [Z0] [ReM] [D]: Req: 1456 UID: 1 IP: 127.0.0.1 one.documentpool.info invoked, -2, -1, -1, 100
Tue Apr 27 14:57:28 2021 [Z0] [ReM] [D]: Req: 1456 UID: 1 one.documentpool.info result SUCCESS, "<DOCUMENT_POOL> </ DOC ..."
Tue Apr 27 14:57:28 2021 [Z0] [ReM] [D]: Req: 1280 UID: 1 IP: 127.0.0.1 one.vmpool.monitoring invoked, -2, 0
Tue Apr 27 14:57:28 2021 [Z0] [ReM] [D]: Req: 1280 UID: 1 one.vmpool.monitoring result SUCCESS, "<MONITORING_DATA> <MO ..."
Tue Apr 27 14:57:28 2021 [Z0] [ReM] [D]: Req: 7072 UID: 1 IP: 127.0.0.1 one.vmpool.infoextended invoked, -2, -1, -1, -1, " "
Tue Apr 27 14:57:28 2021 [Z0] [ReM] [D]: Req: 7072 UID: 1 one.vmpool.infoextended result SUCCESS, "<VM_POOL> <VM> <ID> 418 ..."
Tue Apr 27 14:57:29 2021 [Z0] [AuM] [E]: Token has expired.
Tue Apr 27 14:57:29 2021 [Z0] [ReM] [D]: Req: 9568 UID: -1 IP: 127.0.0.1 one.zone.raftstatus invoked
Tue Apr 27 14:57:29 2021 [Z0] [ReM] [E]: Req: 9568 UID: - one.zone.raftstatus result FAILURE [one.zone.raftstatus] User couldn't be authenticated, aborting call.
Tue Apr 27 14:57:44 2021 [Z0] [AuM] [E]: Token has expired.
Tue Apr 27 14:57:44 2021 [Z0] [ReM] [D]: Req: 9072 UID: -1 IP: 127.0.0.1 one.zone.raftstatus invoked
Tue Apr 27 14:57:44 2021 [Z0] [ReM] [E]: Req: 9072 UID: - one.zone.raftstatus result FAILURE [one.zone.raftstatus] User couldn't be authenticated, aborting call.
Tue Apr 27 14:57:59 2021 [Z0] [AuM] [E]: Token has expired.
Tue Apr 27 14:57:59 2021 [Z0] [ReM] [D]: Req: 4784 UID: -1 IP: 127.0.0.1 one.zone.raftstatus invoked
Tue Apr 27 14:57:59 2021 [Z0] [ReM] [E]: Req: 4784 UID: - one.zone.raftstatus result FAILURE [one.zone.raftstatus] User couldn't be authenticated, aborting call.

/sunstone.log:

Tue Apr 27 11:48:49 2021 [I]: 10.100.110.118 - - [27/Apr/2021:11:48:49 +0200] "POST /vm/407/guac/vnc HTTP/1.1" 200 - 0.0301
Tue Apr 27 11:49:31 2021 [I]: 10.100.110.118 - - [27/Apr/2021:11:49:31 +0200] "GET /vm/418?csrftoken=36d51b1c94168865c727e06703b69af4c6f34921b2dab9d896b2cd905d06a03b HTTP/1.1" 200 - 0.0161
Tue Apr 27 11:49:31 2021 [I]: 10.100.110.118 - - [27/Apr/2021:11:49:31 +0200] "POST /vm/418/guac/vnc HTTP/1.1" 200 - 0.0298
Wed Apr 28 06:36:02 2021 [I]: 10.100.110.118 - - [28/Apr/2021:06:36:02 +0200] "GET / HTTP/1.1" 200 - 0.0021
Wed Apr 28 06:36:02 2021 [I]: 10.100.110.118 - - [28/Apr/2021:06:36:02 +0200] "GET /dist/login.js HTTP/1.1" 304 - 0.0005
Wed Apr 28 06:36:02 2021 [I]: 10.100.110.118 - - [28/Apr/2021:06:36:02 +0200] "GET /images/ajax-loader.gif HTTP/1.1" 304 - 0.0005
Wed Apr 28 06:36:02 2021 [I]: 10.100.110.118 - - [28/Apr/2021:06:36:02 +0200] "GET /images/opennebula-5.0.png HTTP/1.1" 304 - 0.0003
Wed Apr 28 06:37:13 2021 [E]: user.info error: [one.user.info] User couldn't be authenticated, aborting call.
Wed Apr 28 06:37:13 2021 [I]: 10.100.110.118 - - [28/Apr/2021:06:37:13 +0200] "POST /login HTTP/1.1" 500 - 0.2469
Wed Apr 28 06:37:21 2021 [E]: user.info error: [one.user.info] User couldn't be authenticated, aborting call.
Wed Apr 28 06:37:21 2021 [I]: 10.100.110.118 - - [28/Apr/2021:06:37:21 +0200] "POST /login HTTP/1.1" 500 - 0.0175
Wed Apr 28 06:39:13 2021 [E]: User oneadmin could not be authenticated
Wed Apr 28 06:39:13 2021 [E]: [one.user.info] User couldn't be authenticated, aborting call.
Wed Apr 28 06:39:13 2021 [I]: Unauthorized login attempt
Wed Apr 28 06:39:13 2021 [I]: 10.100.110.118 - - [28/Apr/2021:06:39:13 +0200] "POST /login HTTP/1.1" 401 - 0.0121

System information:

OS: Debian GNU / Linux 10
ONE: OpenNebula 6.0.0 (3218016d)

The times on all participating servers are synchronized via NTP.
Restarting the entire infrastructure does not change the problem.

Do any of you have any ideas where I could look?

I would like to avoid emptying the database if at all possible, as some time has gone into setting up the environment and this work would otherwise be lost. Unless someone has an idea how I can reliably backup everything without having access to Opennebula.

Thank you for your support.

cgonzalez · April 29, 2021, 7:45am

HI @AaronLea

Can you share the content of /var/lib/one/.one folder? Are the oneadmin credentials properly defined in /var/lib/one/.one/one_auth? (this file is used by CLI interface to authenticate itself).

AaronLea · April 29, 2021, 8:17am

Hi @cgonzalez

ls -lah /var/lib/one/.one

drwx------ 2 oneadmin disk 4.0K Apr 29 08:56 .
drwxr-x— 16 oneadmin oneadmin 4.0K Apr 29 09:20 …
-rw------- 1 oneadmin disk 77 Apr 13 14:56 ec2_auth
-rw-r–r-- 1 oneadmin disk 32 Apr 12 08:31 fireedge_key
-rw------- 1 oneadmin disk 77 Apr 13 14:56 occi_auth
-rw------- 1 oneadmin disk 18 Apr 29 08:56 one_auth
-rw------- 1 oneadmin disk 77 Apr 13 14:56 oneflow_auth
-rw------- 1 oneadmin disk 77 Apr 13 14:56 onegate_auth
-rw------- 1 oneadmin disk 65 Apr 12 08:31 one_key
-rw------- 1 oneadmin disk 77 Apr 13 14:56 sunstone_auth

In the /var/lib/one/.one/one_auth is the oneadmin and the Password in Plain text

oneadmin:oneadmin

In the other *_auth Files are:

serveradmin:ee3d73373ed80915803b5cf9dbe88adb0126c6127f492bc5c46d37d147d5c9e3

cgonzalez · April 29, 2021, 9:08am

It seems that the content is correct. Just a couple of questions to confirm:

oneadmin user password is oneadmin too, right?
Are you running the CLI commands from the frontend node as oneadmin user?

Lest’s start by debugging just the CLI as probably the same problem is affecting both of them. Could you share the output of SELECT body FROM user_pool WHERE oid = 0?

Also, it would be useful if you can perform a oneuser show 0 command and send us the entries in oned.log corresponding to that call to check which user is CLI trying to use.

AaronLea · April 29, 2021, 9:45am

To your questions:

Yes, the onadmin password ist oneadmin.
I’ve tried both root and oneadmin.

SLQ answer (i changed the SSH_PUBLIC_KEY in this Printout):

<USER><ID>0</ID><GID>0</GID><GROUPS><ID>0</ID></GROUPS><GNAME>oneadmin</GNAME><NAME>oneadmin</NAME><PASSWORD><![CDATA[a560f64750a7b82e630e56e560744e20f23b7adcbe4d44b186bb1189cf4e04cd]]></PASSWORD><AUTH_DRIVER><![CDATA[core]]></AUTH_DRIVER><ENABLED>1</ENABLED><LOGIN_TOKEN><TOKEN>oneadmin</TOKEN><EXPIRATION_TIME>1619528229</EXPIRATION_TIME><EGID>-1</EGID></LOGIN_TOKEN><TEMPLATE><SSH_PUBLIC_KEY><![CDATA[ssh-rsa **********************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************== lippdefault
]]></SSH_PUBLIC_KEY><SUNSTONE><DEFAULT_VIEW><![CDATA[admin]]></DEFAULT_VIEW><LANG><![CDATA[en_US]]></LANG><TABLE_DEFAULT_PAGE_LENGTH><![CDATA[100]]></TABLE_DEFAULT_PAGE_LENGTH></SUNSTONE><TOKEN_PASSWORD><![CDATA[5d659e8d58d1d9f1fe6faf807ae9864cd47497740939f93d3e5e0d66c8a804ff]]></TOKEN_PASSWORD></TEMPLATE></USER>

and the oneuser show 0 (performt on 11:25:06)

Thu Apr 29 11:25:00 2021 [Z0][AuM][E]: Token has expired.
Thu Apr 29 11:25:00 2021 [Z0][ReM][D]: Req:2608 UID:-1 IP:127.0.0.1 one.system.config invoked
Thu Apr 29 11:25:00 2021 [Z0][ReM][E]: Req:2608 UID:- one.system.config result FAILURE [one.system.config] User couldn’t be authenticated, aborting call.
Thu Apr 29 11:25:02 2021 [Z0][AuM][E]: Token has expired.
Thu Apr 29 11:25:02 2021 [Z0][ReM][D]: Req:4736 UID:-1 IP:127.0.0.1 one.system.config invoked
Thu Apr 29 11:25:02 2021 [Z0][ReM][E]: Req:4736 UID:- one.system.config result FAILURE [one.system.config] User couldn’t be authenticated, aborting call.
Thu Apr 29 11:25:04 2021 [Z0][AuM][E]: Token has expired.
Thu Apr 29 11:25:04 2021 [Z0][ReM][D]: Req:7824 UID:-1 IP:127.0.0.1 one.system.config invoked
Thu Apr 29 11:25:04 2021 [Z0][ReM][E]: Req:7824 UID:- one.system.config result FAILURE [one.system.config] User couldn’t be authenticated, aborting call.
Thu Apr 29 11:25:06 2021 [Z0][AuM][E]: Token has expired.
Thu Apr 29 11:25:06 2021 [Z0][ReM][D]: Req:9136 UID:-1 IP:127.0.0.1 one.system.config invoked
Thu Apr 29 11:25:06 2021 [Z0][ReM][E]: Req:9136 UID:- one.system.config result FAILURE [one.system.config] User couldn’t be authenticated, aborting call.
Thu Apr 29 11:25:06 2021 [Z0][AuM][E]: Token has expired.
Thu Apr 29 11:25:06 2021 [Z0][ReM][D]: Req:32 UID:-1 IP:127.0.0.1 one.user.info invoked , 0, false
Thu Apr 29 11:25:06 2021 [Z0][ReM][E]: Req:32 UID:- one.user.info result FAILURE [one.user.info] User couldn’t be authenticated, aborting call.
Thu Apr 29 11:25:08 2021 [Z0][AuM][E]: Token has expired.
Thu Apr 29 11:25:08 2021 [Z0][ReM][D]: Req:1824 UID:-1 IP:127.0.0.1 one.system.config invoked
Thu Apr 29 11:25:08 2021 [Z0][ReM][E]: Req:1824 UID:- one.system.config result FAILURE [one.system.config] User couldn’t be authenticated, aborting call.
Thu Apr 29 11:25:10 2021 [Z0][AuM][E]: Token has expired.
Thu Apr 29 11:25:10 2021 [Z0][ReM][D]: Req:3152 UID:-1 IP:127.0.0.1 one.system.config invoked
Thu Apr 29 11:25:10 2021 [Z0][ReM][E]: Req:3152 UID:- one.system.config result FAILURE [one.system.config] User couldn’t be authenticated, aborting call.
Thu Apr 29 11:25:12 2021 [Z0][AuM][E]: Token has expired.
Thu Apr 29 11:25:12 2021 [Z0][ReM][D]: Req:528 UID:-1 IP:127.0.0.1 one.system.config invoked
Thu Apr 29 11:25:12 2021 [Z0][ReM][E]: Req:528 UID:- one.system.config result FAILURE [one.system.config] User couldn’t be authenticated, aborting call.

cgonzalez · April 29, 2021, 10:12am

I think the problem is related with a Fireedge vulnerability fixed in 6.0.0.1 (EE 6.0.1 and CE 6.0.0.1 Available for Download).

In order to recover your environment please stop opennebula-fireedge service, update oneadmin user and remove the LOGIN_TOKEN section:

UPDATE user_pool SET body = '<USER><ID>0</ID><GID>0</GID><GROUPS><ID>0</ID></GROUPS><GNAME>oneadmin</GNAME><NAME>oneadmin</NAME><PASSWORD><![CDATA[a560f64750a7b82e630e56e560744e20f23b7adcbe4d44b186bb1189cf4e04cd]]></PASSWORD><AUTH_DRIVER><![CDATA[core]]></AUTH_DRIVER><ENABLED>1</ENABLED><TEMPLATE><SSH_PUBLIC_KEY><![CDATA[ssh-rsa **********************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************== lippdefault]]></SSH_PUBLIC_KEY><SUNSTONE><DEFAULT_VIEW><![CDATA[admin]]></DEFAULT_VIEW><LANG><![CDATA[en_US]]></LANG><TABLE_DEFAULT_PAGE_LENGTH><![CDATA[100]]></TABLE_DEFAULT_PAGE_LENGTH></SUNSTONE><TOKEN_PASSWORD><![CDATA[5d659e8d58d1d9f1fe6faf807ae9864cd47497740939f93d3e5e0d66c8a804ff]]></TOKEN_PASSWORD></TEMPLATE></USER>' WHERE oid = 0;

(remember to put the right ssh key again in the query above)

After that, please update to the newest version 6.0.0.1 to make sure the error doesn’t happen again. After the upgrade you should be able to start the fireedge service again.

Also, I suggest to check all your users and remove every token that have been created automatically by OpenNebula. If you’re not using tokens you can run oneuser token-delete-all <username> to make sure every token is removed.

AaronLea · April 29, 2021, 11:20am

Hi @cgonzalez

Thank you for your support. as far as I can see it all works again.

cgonzalez · April 29, 2021, 11:21am

Nice to hear that! Thanks for the feedback!

KarlAustin · June 7, 2021, 2:24pm

We experienced this issue on 6.0.0.0, so fixed it and updated to 6.0.0.1 - it’s just happened again.

Rahul_Sharma · December 2, 2021, 11:10am

Hello @cgonzalez ,
I too have a query related to authentication:
We have created an API endpoint using XML-RPC API, but facing issues with authentication. Is there any method to check whether the user is authenticated user?
How can we perform authentication from Sunstone as credentials can’t be passed from sunstone to API endpoints?
Hopefully query is being drafted in explanatory way.

Looking for some inputs.

Thanks!

Topic		Replies	Views
User couldn't be authenticated, aborting call Community Support	12	11801	March 4, 2015
I can't login OpenNebula interface? Community Support	1	544	June 20, 2018
[SOLVED] Upgraded to latest opennebula, now can't login to sunstone (Down) Community Support solved	5	1845	November 1, 2019
User couldn't be authenticated, aborting call. GUI says invalid username or password General	17	2746	March 14, 2019
Login opennebula Community Support	22	2806	April 8, 2022

OpenNebula 6.0 Authentication stopped working

Related Topics