<div dir="ltr"><div><br></div><div class="gmail_extra"><br><div class="gmail_quote">On Sat, Dec 19, 2015 at 2:15 PM, Gianluca Cecchi <span dir="ltr">&lt;<a href="mailto:gianluca.cecchi@gmail.com" target="_blank">gianluca.cecchi@gmail.com</a>&gt;</span> wrote:<br><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><div dir="ltr">Hello.<div><br></div><div>I updated my test self hosted engine vm to 3.6.1 and to CentOS 7.2.</div><div><br></div><div>Now it seems it isn&#39;t able to to login to webadmin due to this in engine.log</div><div>(field is empty in web admin gui)</div><div> </div><div><div>2015-12-19 13:59:05,182 ERROR [org.ovirt.engine.core.bll.aaa.LoginBaseCommand] (default task-17) [] </div><div>Can&#39;t login because authentication profile &#39;internal&#39; doesn&#39;t exist.</div></div><div><br></div><div>Is it an already known problem?</div></div></blockquote><div><br></div><div><br></div><div>Here the output of the engine-setup run today and completead at 13:30.</div><div><a href="https://drive.google.com/file/d/0BwoPbcrMv8mveWlPdmh6MkV5cDA/view?usp=sharing" target="_blank">https://drive.google.com/file/d/0BwoPbcrMv8mveWlPdmh6MkV5cDA/view?usp=sharing</a><br></div><div><br></div><div>Last lines in messages something like this:</div><div><br></div><div><div>Dec 19 13:30:45 ractorshe ovirt-websocket-proxy.py: ovirt-websocket-proxy[21225] INFO msg:824   - Deny non-SSL/TLS connections</div><div>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</div><div>Dec 19 13:30:45 ractorshe ovirt-websocket-proxy.py: ovirt-websocket-proxy[21225] INFO msg:824   - proxying from *:6100 to targets in /dummy</div><div>Dec 19 13:30:55 ractorshe systemd: serial-getty@ttyS0.service holdoff time over, scheduling restart.</div><div>Dec 19 13:30:55 ractorshe systemd: Stopping Serial Getty on ttyS0...</div><div>Dec 19 13:30:55 ractorshe systemd: Starting Serial Getty on ttyS0...</div><div>Dec 19 13:30:55 ractorshe systemd: Started Serial Getty on ttyS0.</div><div>Dec 19 13:31:05 ractorshe systemd: serial-getty@ttyS0.service holdoff time over, scheduling restart.</div><div>Dec 19 13:31:05 ractorshe systemd: Stopping Serial Getty on ttyS0...</div><div>Dec 19 13:31:05 ractorshe systemd: Starting Serial Getty on ttyS0...</div><div>Dec 19 13:31:05 ractorshe systemd: Started Serial Getty on ttyS0.</div></div><div>Then I see a seven lines of this sequence:</div><div>^@^@^@^@^@^@^@^@^@^@<br></div><div><br></div><div>and then the start of the VM (cause d by leaving maintenance)</div><div><div>Dec 19 13:34:14 ractorshe rsyslogd: [origin software=&quot;rsyslogd&quot; swVersion=&quot;7.4.7&quot; x-pid=&quot;484&quot; x-info=&quot;<a href="http://www.rsyslog.com" target="_blank">http://www.rsyslog.com</a>&quot;] s</div><div>tart</div><div>Dec 19 13:34:14 ractorshe rsyslogd-2307: warning: ~ action is deprecated, consider using the &#39;stop&#39; statement instead [try <a href="http://www.rsyslog.com/e/2307" target="_blank">http://www.rsyslog.com/e/2307</a> ]</div><div>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).</div><div>Dec 19 13:34:09 ractorshe kernel: Initializing cgroup subsys cpuset</div><div>Dec 19 13:34:09 ractorshe kernel: Initializing cgroup subsys cpu</div></div><div>..</div><div><br></div><div>the shutdown was not clean because I see also this during the start </div><div><div><div>Dec 19 13:34:10 ractorshe kernel: input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/</div><div>serio1/input/input2</div><div>Dec 19 13:34:10 ractorshe kernel: tsc: Refined TSC clocksource calibration: 2260.990 MHz</div><div>Dec 19 13:34:12 ractorshe systemd-fsck: /dev/vda1: Clearing orphaned inode 272353 (uid=0, gid=0, mode=<a href="tel:0100600" value="+390100600" target="_blank">0100600</a>, size=43056)</div><div>Dec 19 13:34:12 ractorshe systemd-fsck: /dev/vda1: Clearing orphaned inode 272352 (uid=0, gid=0, mode=<a href="tel:0100600" value="+390100600" target="_blank">0100600</a>, size=16)</div></div><div><br></div><br></div><div>first lines of postgresql-Sat.log in /var/lib/pgsql/data/pg_log are:</div><div><br></div><div><div>WARNING:  column &quot;user_role_title&quot; has type &quot;unknown&quot;</div><div>DETAIL:  Proceeding with relation creation anyway.</div><div>LOG:  database system was interrupted; last known up at 2015-12-19 12:28:54 UTC</div><div>FATAL:  the database system is starting up</div><div>LOG:  database system was not properly shut down; automatic recovery in progress</div><div>LOG:  redo starts at 1/1FDFCAC8</div><div>LOG:  record with zero length at 1/20A06E50</div><div>LOG:  redo done at 1/20A06E20</div><div>LOG:  last completed transaction was at log time 2015-12-19 12:31:19.33468+00</div><div>FATAL:  the database system is starting up</div><div>FATAL:  the database system is starting up</div><div>FATAL:  the database system is starting up</div><div>LOG:  autovacuum launcher started</div><div>LOG:  database system is ready to accept connections</div><div>ERROR:  insert or update on table &quot;storage_domain_dynamic&quot; violates foreign key constraint &quot;fk_storage_domain_dynamic_storage_domain_static&quot;</div><div>DETAIL:  Key (id)=(00000000-0000-0000-0000-000000000000) is not present in table &quot;storage_domain_static&quot;.</div><div>CONTEXT:  SQL statement &quot;INSERT INTO storage_domain_dynamic(available_disk_size, id, used_disk_size)</div><div>                VALUES(v_available_disk_size, v_id, v_used_disk_size)&quot;</div><div>        PL/pgSQL function insertstorage_domain_dynamic(integer,uuid,integer) line 3 at SQL statement</div><div>STATEMENT:  select * from insertstorage_domain_dynamic($1, $2, $3) as result</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div></div><div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  received fast shutdown request</div><div>LOG:  aborting any active transactions</div><div>LOG:  autovacuum launcher shutting down</div><div>FATAL:  terminating connection due to administrator command</div><div>LOG:  shutting down</div><div>LOG:  database system is shut down</div><div>LOG:  database system was shut down at 2015-12-19 12:47:22 UTC</div><div>LOG:  autovacuum launcher started</div><div>LOG:  database system is ready to accept connections</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_7&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_7&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_7&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div></div><div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_7&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_7&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_7&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_7&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_4&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  autovacuum: found orphan temp table &quot;pg_temp_7&quot;.&quot;tt_temp22&quot; in database &quot;engine&quot;</div><div>LOG:  received fast shutdown request</div><div>LOG:  aborting any active transactions</div><div>LOG:  autovacuum launcher shutting down</div><div>LOG:  shutting down</div><div>LOG:  database system is shut down</div><div>LOG:  database system was shut down at 2015-12-19 12:55:07 UTC</div><div>LOG:  database system is ready to accept connections</div><div>LOG:  autovacuum launcher started</div><div>ERROR:  insert or update on table &quot;storage_domain_dynamic&quot; violates foreign key constraint &quot;fk_storage_domain_dynamic_storage_domain_static&quot;</div><div>DETAIL:  Key (id)=(00000000-0000-0000-0000-000000000000) is not present in table &quot;storage_domain_static&quot;.</div><div>CONTEXT:  SQL statement &quot;INSERT INTO storage_domain_dynamic(available_disk_size, id, used_disk_size)</div><div>                VALUES(v_available_disk_size, v_id, v_used_disk_size)&quot;</div></div><div><br></div><div>SO I think something wrong has remained inside the database, even if I don&#39;t understand what and why...</div><div><br></div><div>What I see in messages of hypervisor around the time the engine VM went down:</div><div><div>Dec 19 13:30:01 ractor systemd: Starting Session 1636 of user root.</div><div>Dec 19 13:31:19 ractor sanlock[1239]: 2015-12-19 13:31:19+0100 827362 [1239]: s1 kill 3110 sig 9 count 1</div><div>Dec 19 13:31:19 ractor sanlock[1239]: 2015-12-19 13:31:19+0100 827362 [1239]: dead 3110 ci 3 count 1</div><div>Dec 19 13:31:19 ractor journal: internal error: End of file from monitor</div><div>Dec 19 13:31:19 ractor kernel: ovirtmgmt: port 2(vnet0) entered disabled state</div><div>Dec 19 13:31:19 ractor kernel: device vnet0 left promiscuous mode</div><div>Dec 19 13:31:19 ractor kernel: ovirtmgmt: port 2(vnet0) entered disabled state</div><div>Dec 19 13:31:19 ractor kvm: 2 guests now active</div><div>Dec 19 13:31:19 ractor systemd-machined: Machine qemu-HostedEngine terminated.</div><div>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: &#39;/proc/3110/stat&#39;</div><div>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</div><div>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</div></div><div><br></div><div>Gianluca</div><div><br></div></div></div></div>