On Sat, Dec 19, 2015 at 2:15 PM, Gianluca Cecchi <gianluca.cecchi@gmail.com> wrote:
Hello.

I updated my test self hosted engine vm to 3.6.1 and to CentOS 7.2.

Now it seems it isn't able to to login to webadmin due to this in engine.log
(field is empty in web admin gui)
 
2015-12-19 13:59:05,182 ERROR [org.ovirt.engine.core.bll.aaa.LoginBaseCommand] (default task-17) [] 
Can't login because authentication profile 'internal' doesn't exist.

Is it an already known problem?


Here the output of the engine-setup run today and completead at 13:30.
https://drive.google.com/file/d/0BwoPbcrMv8mveWlPdmh6MkV5cDA/view?usp=sharing

Last lines in messages something like this:

Dec 19 13:30:45 ractorshe ovirt-websocket-proxy.py: ovirt-websocket-proxy[21225] INFO msg:824   - Deny non-SSL/TLS connections
Dec 19 13:30:45 ractorshe journal: 2015-12-19 13:30:45,958 ovirt-websocket-proxy: INFO msg:824   - proxying from *:6100 to targets in /dummy
Dec 19 13:30:45 ractorshe ovirt-websocket-proxy.py: ovirt-websocket-proxy[21225] INFO msg:824   - proxying from *:6100 to targets in /dummy
Dec 19 13:30:55 ractorshe systemd: serial-getty@ttyS0.service holdoff time over, scheduling restart.
Dec 19 13:30:55 ractorshe systemd: Stopping Serial Getty on ttyS0...
Dec 19 13:30:55 ractorshe systemd: Starting Serial Getty on ttyS0...
Dec 19 13:30:55 ractorshe systemd: Started Serial Getty on ttyS0.
Dec 19 13:31:05 ractorshe systemd: serial-getty@ttyS0.service holdoff time over, scheduling restart.
Dec 19 13:31:05 ractorshe systemd: Stopping Serial Getty on ttyS0...
Dec 19 13:31:05 ractorshe systemd: Starting Serial Getty on ttyS0...
Dec 19 13:31:05 ractorshe systemd: Started Serial Getty on ttyS0.
Then I see a seven lines of this sequence:
^@^@^@^@^@^@^@^@^@^@

and then the start of the VM (cause d by leaving maintenance)
Dec 19 13:34:14 ractorshe rsyslogd: [origin software="rsyslogd" swVersion="7.4.7" x-pid="484" x-info="http://www.rsyslog.com"] s
tart
Dec 19 13:34:14 ractorshe rsyslogd-2307: warning: ~ action is deprecated, consider using the 'stop' statement instead [try http://www.rsyslog.com/e/2307 ]
Dec 19 13:34:09 ractorshe journal: Runtime journal is using 8.0M (max 794.3M, leaving 1.1G of free 7.7G, current limit 794.3M).
Dec 19 13:34:09 ractorshe kernel: Initializing cgroup subsys cpuset
Dec 19 13:34:09 ractorshe kernel: Initializing cgroup subsys cpu
..

the shutdown was not clean because I see also this during the start 
Dec 19 13:34:10 ractorshe kernel: input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/
serio1/input/input2
Dec 19 13:34:10 ractorshe kernel: tsc: Refined TSC clocksource calibration: 2260.990 MHz
Dec 19 13:34:12 ractorshe systemd-fsck: /dev/vda1: Clearing orphaned inode 272353 (uid=0, gid=0, mode=0100600, size=43056)
Dec 19 13:34:12 ractorshe systemd-fsck: /dev/vda1: Clearing orphaned inode 272352 (uid=0, gid=0, mode=0100600, size=16)


first lines of postgresql-Sat.log in /var/lib/pgsql/data/pg_log are:

WARNING:  column "user_role_title" has type "unknown"
DETAIL:  Proceeding with relation creation anyway.
LOG:  database system was interrupted; last known up at 2015-12-19 12:28:54 UTC
FATAL:  the database system is starting up
LOG:  database system was not properly shut down; automatic recovery in progress
LOG:  redo starts at 1/1FDFCAC8
LOG:  record with zero length at 1/20A06E50
LOG:  redo done at 1/20A06E20
LOG:  last completed transaction was at log time 2015-12-19 12:31:19.33468+00
FATAL:  the database system is starting up
FATAL:  the database system is starting up
FATAL:  the database system is starting up
LOG:  autovacuum launcher started
LOG:  database system is ready to accept connections
ERROR:  insert or update on table "storage_domain_dynamic" violates foreign key constraint "fk_storage_domain_dynamic_storage_domain_static"
DETAIL:  Key (id)=(00000000-0000-0000-0000-000000000000) is not present in table "storage_domain_static".
CONTEXT:  SQL statement "INSERT INTO storage_domain_dynamic(available_disk_size, id, used_disk_size)
                VALUES(v_available_disk_size, v_id, v_used_disk_size)"
        PL/pgSQL function insertstorage_domain_dynamic(integer,uuid,integer) line 3 at SQL statement
STATEMENT:  select * from insertstorage_domain_dynamic($1, $2, $3) as result
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  received fast shutdown request
LOG:  aborting any active transactions
LOG:  autovacuum launcher shutting down
FATAL:  terminating connection due to administrator command
LOG:  shutting down
LOG:  database system is shut down
LOG:  database system was shut down at 2015-12-19 12:47:22 UTC
LOG:  autovacuum launcher started
LOG:  database system is ready to accept connections
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_7"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_7"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_7"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_7"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_7"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_7"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_7"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_4"."tt_temp22" in database "engine"
LOG:  autovacuum: found orphan temp table "pg_temp_7"."tt_temp22" in database "engine"
LOG:  received fast shutdown request
LOG:  aborting any active transactions
LOG:  autovacuum launcher shutting down
LOG:  shutting down
LOG:  database system is shut down
LOG:  database system was shut down at 2015-12-19 12:55:07 UTC
LOG:  database system is ready to accept connections
LOG:  autovacuum launcher started
ERROR:  insert or update on table "storage_domain_dynamic" violates foreign key constraint "fk_storage_domain_dynamic_storage_domain_static"
DETAIL:  Key (id)=(00000000-0000-0000-0000-000000000000) is not present in table "storage_domain_static".
CONTEXT:  SQL statement "INSERT INTO storage_domain_dynamic(available_disk_size, id, used_disk_size)
                VALUES(v_available_disk_size, v_id, v_used_disk_size)"

SO I think something wrong has remained inside the database, even if I don't understand what and why...

What I see in messages of hypervisor around the time the engine VM went down:
Dec 19 13:30:01 ractor systemd: Starting Session 1636 of user root.
Dec 19 13:31:19 ractor sanlock[1239]: 2015-12-19 13:31:19+0100 827362 [1239]: s1 kill 3110 sig 9 count 1
Dec 19 13:31:19 ractor sanlock[1239]: 2015-12-19 13:31:19+0100 827362 [1239]: dead 3110 ci 3 count 1
Dec 19 13:31:19 ractor journal: internal error: End of file from monitor
Dec 19 13:31:19 ractor kernel: ovirtmgmt: port 2(vnet0) entered disabled state
Dec 19 13:31:19 ractor kernel: device vnet0 left promiscuous mode
Dec 19 13:31:19 ractor kernel: ovirtmgmt: port 2(vnet0) entered disabled state
Dec 19 13:31:19 ractor kvm: 2 guests now active
Dec 19 13:31:19 ractor systemd-machined: Machine qemu-HostedEngine terminated.
Dec 19 13:31:21 ractor journal: ovirt-ha-broker cpu_load_no_engine.EngineHealth ERROR Failed to read vm stats: [Errno 2] No such file or directory: '/proc/3110/stat'
Dec 19 13:31:21 ractor journal: vdsm root WARNING File: /var/lib/libvirt/qemu/channels/7b0ff898-0a9e-4b97-8292-1d9f2a0a6683.com.redhat.rhevm.vdsm already removed
Dec 19 13:31:21 ractor journal: vdsm root WARNING File: /var/lib/libvirt/qemu/channels/7b0ff898-0a9e-4b97-8292-1d9f2a0a6683.org.qemu.guest_agent.0 already removed

Gianluca