10:17 a.m.
Hello,
oVirt 3.2.1 on F18
One mgmt server + one host.
At some point the host had some problem and was rebooted
at reboot ther was a problem because I got
detected unhandled Python exception in '/usr/share/vdsm/vdsm'
watching at
http://www.ovirt.org/Troubleshooting
I verified that for some reason vdsmd.log was root.root.
So I set correct permissions and restarted the node.
Now it stays at "unassigned" status from an engine point of view, that
I don't know what means...
In node messages
Jul 14 16:55:02 management02 vdsm vds WARNING Unable to load the json
rpc server module. Please make sure it is installed.
[root@management02 ~]# systemctl status vdsmd
vdsmd.service - Virtual Desktop Server Manager
Loaded: loaded (/usr/lib/systemd/system/vdsmd.service; enabled)
Active: active (running) since Sun 2013-07-14 16:54:58 CEST; 6min ago
Process: 1015 ExecStart=/lib/systemd/systemd-vdsmd start
(code=exited, status=0/SUCCESS)
Main PID: 2128 (respawn)
CGroup: name=systemd:/system/vdsmd.service
├─2128 /bin/bash -e /usr/share/vdsm/respawn --minlifetime 10
--daemon --masterpid /var/run/vdsm/respawn....
├─2131 /usr/bin/python /usr/share/vdsm/vdsm
├─2151 /usr/bin/sudo -n /usr/bin/python
/usr/share/vdsm/supervdsmServer.py 62a4a000-a73a-4e2c-b1a8-25e24...
└─2152 /usr/bin/python /usr/share/vdsm/supervdsmServer.py
62a4a000-a73a-4e2c-b1a8-25e24587b558 2131 /var...
Jul 14 16:54:58 management02.localdomain.local runuser[2125]:
pam_unix(runuser:session): session opened for user vdsm ...d=0)
Jul 14 16:54:58 management02.localdomain.local runuser[2125]:
pam_unix(runuser:session): session closed for user vdsm
Jul 14 16:54:58 management02.localdomain.local systemd-vdsmd[1015]:
[27B blob data]
Jul 14 16:54:58 management02.localdomain.local systemd[1]: Started
Virtual Desktop Server Manager.
Jul 14 16:54:59 management02.localdomain.local python[2131]:
DIGEST-MD5 client step 2
Jul 14 16:54:59 management02.localdomain.local python[2131]:
DIGEST-MD5 client step 2
Jul 14 16:54:59 management02.localdomain.local python[2131]:
DIGEST-MD5 client step 3
Jul 14 16:54:59 management02.localdomain.local vdsm[2131]: vdsm
fileUtils WARNING Dir /rhev/data-center/mnt already exists
Jul 14 16:55:02 management02.localdomain.local vdsm[2131]: vdsm vds
WARNING Unable to load the json rpc server module....led.
Jul 14 16:55:04 management02.localdomain.local vdsm[2131]: vdsm
fileUtils WARNING Dir /rhev/data-center/hsm-tasks alre...ists
In vdsm.log
torageRefresh::DEBUG::2013-07-14
16:55:01,919::misc::1064::SamplingMethod::(__call__) Returning last
result
MainProcess|storageRefresh::DEBUG::2013-07-14
16:55:01,921::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd
of=/sys/class
/scsi_host/host0/scan' (cwd None)
MainProcess|storageRefresh::DEBUG::2013-07-14
16:55:01,932::iscsi::402::Storage.ISCSI::(forceIScsiScan) Performing
SCSI scan, th
is will take up to 30 seconds
MainThread::INFO::2013-07-14 16:55:02,085::momIF::36::MOM::(__init__)
Starting up MOM
MainThread::INFO::2013-07-14
16:55:02,091::vmChannels::140::vds::(settimeout) Setting channels'
timeout to 30 seconds.
VM Channels Listener::INFO::2013-07-14
16:55:02,091::vmChannels::128::vds::(run) Starting VM channels
listener thread.
MainThread::WARNING::2013-07-14
16:55:02,139::clientIF::175::vds::(_prepareBindings) Unable to load
the json rpc server module. Please make sure it is installed.
storageRefresh::DEBUG::2013-07-14
16:55:04,290::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo
-n /sbin/multipath' (cwd None)
storageRefresh::DEBUG::2013-07-14
16:55:04,341::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err>
= ''; <rc> = 0
storageRefresh::DEBUG::2013-07-14
16:55:04,342::lvm::477::OperationMutex::(_invalidateAllPvs) Operation
'lvm invalidate operation' got the operation mutex
storageRefresh::DEBUG::2013-07-14
16:55:04,342::lvm::479::OperationMutex::(_invalidateAllPvs) Operation
'lvm invalidate operation' released the operation mutex
storageRefresh::DEBUG::2013-07-14
16:55:04,342::lvm::488::OperationMutex::(_invalidateAllVgs) Operation
'lvm invalidate operation' got the operation mutex
storageRefresh::DEBUG::2013-07-14
16:55:04,343::lvm::490::OperationMutex::(_invalidateAllVgs) Operation
'lvm invalidate operation' released the operation mutex
storageRefresh::DEBUG::2013-07-14
16:55:04,343::lvm::508::OperationMutex::(_invalidateAllLvs) Operation
'lvm invalidate operation' got the operation mutex
storageRefresh::DEBUG::2013-07-14
16:55:04,343::lvm::510::OperationMutex::(_invalidateAllLvs) Operation
'lvm invalidate operation' released the operation mutex
storageRefresh::DEBUG::2013-07-14
16:55:04,344::misc::1064::SamplingMethod::(__call__) Returning last
result
storageRefresh::WARNING::2013-07-14
16:55:04,344::fileUtils::185::fileUtils::(createdir) Dir
/rhev/data-center/hsm-tasks already exists
full engine logs and vdsm logs here
https://docs.google.com/file/d/0BwoPbcrMv8mvTXpFNmw3UG9NVzg/edit?usp=sharing
and
https://docs.google.com/file/d/0BwoPbcrMv8mvRDViZGo1S1hRcUU/edit?usp=sharing
thanks for any help.
I should use them tomorrow, they kept ok for many weeks, but Murphy is
always alive ;-)
Gianluca
10:35 a.m.
Gianluca Cecchi wrote:
Hello,
oVirt 3.2.1 on F18
One mgmt server + one host.
At some point the host had some problem and was rebooted
at reboot ther was a problem because I got
detected unhandled Python exception in '/usr/share/vdsm/vdsm'
watching at
http://www.ovirt.org/Troubleshooting
I verified that for some reason vdsmd.log was root.root.
So I set correct permissions and restarted the node.
OK, I have had this too and managed to get out of it uptil now, maybe my
experience will help you, may you have already tried what I'm going to
suggest.
Put the host in maintenance, login with ssh on the host and restart the
vdsmd service, activate the host.
I think I amended vdsms logrotate.conf with a user statement so that it
wouldn't make root owner of vdsmd.log. There is a race condition that
has been fixed I think in 3.2.2 and onwards.
Hope this helps you,
Joop
12:12 p.m.
Il giorno 14/lug/2013 17:35, "Joop" <jvdwege(a)xs4all.nl> ha scritto:
Gianluca Cecchi wrote:
>
> Hello,
>
> oVirt 3.2.1 on F18
> One mgmt server + one host.
>
> At some point the host had some problem and was rebooted
> at reboot ther was a problem because I got
>
> detected unhandled Python exception in '/usr/share/vdsm/vdsm'
>
> watching at
> http://www.ovirt.org/Troubleshooting
>
> I verified that for some reason vdsmd.log was root.root.
> So I set correct permissions and restarted the node.
>
>
OK, I have had this too and managed to get out of it uptil now, maybe my
experience
will help you, may you have already tried what I'm going to
suggest.
Put the host in maintenance, login with ssh on the host and restart
the
vdsmd service, activate the host.
I think I amended vdsms logrotate.conf with a user statement so that it
wouldn't make root owner of vdsmd.log. There is a race condition that has
been fixed I think in 3.2.2 and onwards.
Hope this helps you,
Joop
I'm going to check but it seems to me that I could only select "host has
rebooted" that failed because "unassigned" is not a good starting point to
set it.
Not sure I could put in maintenance. ..
Gianluca
1:43 a.m.
On Sun 14 Jul 2013 08:12:21 PM IDT, Gianluca Cecchi wrote:
Il giorno 14/lug/2013 17:35, "Joop" <jvdwege(a)xs4all.nl
<mailto:jvdwege@xs4all.nl>> ha scritto:
>
> Gianluca Cecchi wrote:
>>
>> Hello,
>>
>> oVirt 3.2.1 on F18
>> One mgmt server + one host.
>>
>> At some point the host had some problem and was rebooted
>> at reboot ther was a problem because I got
>>
>> detected unhandled Python exception in '/usr/share/vdsm/vdsm'
>>
>> watching at
>> http://www.ovirt.org/Troubleshooting
>>
>> I verified that for some reason vdsmd.log was root.root.
>> So I set correct permissions and restarted the node.
>>
>>
>
> OK, I have had this too and managed to get out of it uptil now,
maybe my experience will help you, may you have already tried what I'm
going to suggest.
> Put the host in maintenance, login with ssh on the host and restart
the vdsmd service, activate the host.
>
> I think I amended vdsms logrotate.conf with a user statement so that
it wouldn't make root owner of vdsmd.log. There is a race condition
that has been fixed I think in 3.2.2 and onwards.
>
> Hope this helps you,
>
> Joop
>
I'm going to check but it seems to me that I could only select "host
has rebooted" that failed because "unassigned" is not a good starting
point to set it.
Not sure I could put in maintenance. ..
Gianluca
Unfortunatly you can't. "unassigned" puts the host in transition and
its status should be transited automatically by the engine. Its a bug
that it didn't
move to any other state - Non-operational/up/non-responsive etc.
Can you help me with a stacktrace of your engine with the output of
"jstack -l <jboss-pid>?
_______________________________________________
Users mailing list
Users(a)ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
1:59 a.m.
On Mon, Jul 15, 2013 at 8:43 AM, Roy Golan wrote:
>
Unfortunatly you can't. "unassigned" puts the host in transition and its
status should be transited automatically by the engine. Its a bug that it
didn't
move to any other state - Non-operational/up/non-responsive etc.
Can you help me with a stacktrace of your engine with the output of "jstack
-l <jboss-pid>?
In fact after my final recover operations (change permissions of
vdsm.log and reboot of host and engine servers), after a few hours I
connected to the infra and I discovered that actually it recovered
automatically after a few minutes of engine reboot, putting online
host and all related storage domains and I was able to start without
problems my VMs again.
If confirmed fixed in 3.2.2 I'm going to update in coming days after
this activity I had to do today.
details:
reboot of host at 16:54 with start of vdsmd
reboot of engine at 17:34
these logs in engine should show host becoming operational again after
4 minutes if I understand correctly
2013-07-14 17:37:41,658 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (Defaul
tQuartzScheduler_Worker-7) spmStart polling ended, spm status: SPM
2013-07-14 17:37:41,660 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (De
faultQuartzScheduler_Worker-7) START, HSMClearTaskVDSCommand(HostName
= management02, HostId = 605a7
bda-a122-40be-a5ea-8f12e11484be,
taskId=11aef1c7-cc52-42d4-b884-bbb1e3810260), log id: 2d48c7f0
2013-07-14 17:37:41,668 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(DefaultQuartzScheduler_Worker-7) FINISH, HSMClearTaskVDSCommand, log
id: 2d48c7f0
2013-07-14 17:37:41,668 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(DefaultQuartzScheduler_Worker-7) FINISH, SpmStartVDSCommand, return:
org.ovirt.engine.core.common.businessentities.SpmStatusResult@57ce4b98,
log id: 27089775
2013-07-14 17:37:41,672 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(DefaultQuartzScheduler_Worker-7) Initialize Irs proxy from vds:
management02
2013-07-14 17:37:51,385 WARN
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(DefaultQuartzScheduler_Worker-6) Storage Domain
24f30005-1f28-474d-9855-14932f8e0f1e:EXP_DOMAIN was reported by Host
management02 as Active in Pool bc50e9ae-0206-47bb-929f-c5aaf653fb14,
moving to active status
2013-07-14 17:37:51,393 WARN
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(DefaultQuartzScheduler_Worker-6) Storage Domain
9b9fef06-694e-4ec4-b090-73508cf11119:222b30001551a8c76 was reported by
Host management02 as Active in Pool
bc50e9ae-0206-47bb-929f-c5aaf653fb14, moving to active status
Thanks again
Gianluca
2:57 a.m.
On Mon 15 Jul 2013 09:59:01 AM IDT, Gianluca Cecchi wrote:
On Mon, Jul 15, 2013 at 8:43 AM, Roy Golan wrote:
>>
> Unfortunatly you can't. "unassigned" puts the host in transition and
its
> status should be transited automatically by the engine. Its a bug that it
> didn't
> move to any other state - Non-operational/up/non-responsive etc.
>
> Can you help me with a stacktrace of your engine with the output of "jstack
> -l <jboss-pid>?
>
In fact after my final recover operations (change permissions of
vdsm.log and reboot of host and engine servers), after a few hours I
connected to the infra and I discovered that actually it recovered
automatically after a few minutes of engine reboot, putting online
host and all related storage domains and I was able to start without
problems my VMs again.
If confirmed fixed in 3.2.2 I'm going to update in coming days after
this activity I had to do today.
details:
reboot of host at 16:54 with start of vdsmd
reboot of engine at 17:34
these logs in engine should show host becoming operational again after
4 minutes if I understand correctly
this is the expected behavior.
I'm not sure if the vdsm.log being root has been handled in 3.2.2. can
someone confirm that? (or just post the question to the vdsm list or at
ovirt irc channel)
2013-07-14 17:37:41,658 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (Defaul
tQuartzScheduler_Worker-7) spmStart polling ended, spm status: SPM
2013-07-14 17:37:41,660 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (De
faultQuartzScheduler_Worker-7) START, HSMClearTaskVDSCommand(HostName
= management02, HostId = 605a7
bda-a122-40be-a5ea-8f12e11484be,
taskId=11aef1c7-cc52-42d4-b884-bbb1e3810260), log id: 2d48c7f0
2013-07-14 17:37:41,668 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(DefaultQuartzScheduler_Worker-7) FINISH, HSMClearTaskVDSCommand, log
id: 2d48c7f0
2013-07-14 17:37:41,668 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(DefaultQuartzScheduler_Worker-7) FINISH, SpmStartVDSCommand, return:
org.ovirt.engine.core.common.businessentities.SpmStatusResult@57ce4b98,
log id: 27089775
2013-07-14 17:37:41,672 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(DefaultQuartzScheduler_Worker-7) Initialize Irs proxy from vds:
management02
2013-07-14 17:37:51,385 WARN
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(DefaultQuartzScheduler_Worker-6) Storage Domain
24f30005-1f28-474d-9855-14932f8e0f1e:EXP_DOMAIN was reported by Host
management02 as Active in Pool bc50e9ae-0206-47bb-929f-c5aaf653fb14,
moving to active status
2013-07-14 17:37:51,393 WARN
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(DefaultQuartzScheduler_Worker-6) Storage Domain
9b9fef06-694e-4ec4-b090-73508cf11119:222b30001551a8c76 was reported by
Host management02 as Active in Pool
bc50e9ae-0206-47bb-929f-c5aaf653fb14, moving to active status
Thanks again
Gianluca
4152
days inactive
4153
days old
5 comments
3 participants
participants (3)
-
Gianluca Cecchi -
Joop -
Roy Golan