Bug 1025402 - log spam when handling async tasks
log spam when handling async tasks
Status: CLOSED CURRENTRELEASE
Product: oVirt
Classification: Community
Component: ovirt-engine-core (Show other bugs)
3.3
x86_64 Linux
unspecified Severity unspecified
: ---
: 3.5.0
Assigned To: Ravi Nori
bugs@ovirt.org
infra
: Triaged
: 1026459 (view as bug list)
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2013-10-31 11:28 EDT by Allon Mureinik
Modified: 2016-02-10 14:35 EST (History)
8 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2014-04-30 11:43:42 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: Infra
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Allon Mureinik 2013-10-31 11:28:43 EDT
Description of problem:
Async tasks cause lots "spam" in the log file, includes errornous listing of org.ovirt.thread in class names (see below)



Version-Release number of selected component (if applicable):
Tested with upstream master, commit hash fbee8fe0a55dfe800b5e447eb094ed02ea83d750.

How reproducible:
100%

Steps to Reproduce:
Anything that involves async tasks - e.g.:
1. Create a VM
2. Take a (cold) snapshot
3. Merged the snapshot

Actual results:
Log is full of spam:
2013-10-31 16:39:27,692 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.pool-6-thread-18) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 9ebd6916-4ba7-4f9d-afde-0032d4e62e99
2013-10-31 16:39:27,693 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.pool-6-thread-18) START, SPMClearTaskVDSCommand( storagePoolId = 5849b030-626e-47cb-ad90-3ce782d831b3, ignoreFailoverLimit = false, taskId = 9ebd6916-4ba7-4f9d-afde-0032d4e62e99), log id: 35537a08
2013-10-31 16:39:27,695 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.pool-6-thread-18) START, HSMClearTaskVDSCommand(HostName = h, HostId = e6ad8c25-3a8d-4ce7-9809-974151e413d9, taskId=9ebd6916-4ba7-4f9d-afde-0032d4e62e99), log id: 7b70be91
2013-10-31 16:39:27,773 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.pool-6-thread-18) FINISH, HSMClearTaskVDSCommand, log id: 7b70be91
2013-10-31 16:39:27,774 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.pool-6-thread-18) FINISH, SPMClearTaskVDSCommand, log id: 35537a08
2013-10-31 16:39:27,789 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.pool-6-thread-18) BaseAsyncTask::RemoveTaskFromDB: Removed task 9ebd6916-4ba7-4f9d-afde-0032d4e62e99 from DataBase
2013-10-31 16:39:27,790 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.org.ovirt.thread.pool-6-thread-18) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 44b1ef6c-8634-4e00-9632-b66125e36f22

Expected results:
Clean, readable, logs.

Additional info:
Comment 1 Allon Mureinik 2013-11-05 07:59:17 EST
*** Bug 1026459 has been marked as a duplicate of this bug. ***
Comment 2 Sandro Bonazzola 2014-03-04 04:21:30 EST
This is an automated message.
Re-targeting all non-blocker bugs still open on 3.4.0 to 3.4.1.
Comment 3 Ravi Nori 2014-04-30 11:38:31 EDT
Unable to reproduce this issue in current master. The log looks good

2014-04-30 11:32:45,164 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-41) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 2d17c02c-187f-4f0f-9d16-b617484a623d
2014-04-30 11:32:45,165 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-41) START, SPMClearTaskVDSCommand( storagePoolId = 2eb8eafa-ef84-479a-ab27-1b57f4b720e5, ignoreFailoverLimit = false, taskId = 2d17c02c-187f-4f0f-9d16-b617484a623d), log id: 1e6f264b
2014-04-30 11:32:45,166 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-41) START, HSMClearTaskVDSCommand(HostName = 192.168.1.123, HostId = c76c77b3-7c48-42b3-9b19-6a088d41c77c, taskId=2d17c02c-187f-4f0f-9d16-b617484a623d), log id: 133b1589
2014-04-30 11:32:45,265 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-41) FINISH, HSMClearTaskVDSCommand, log id: 133b1589
2014-04-30 11:32:45,266 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-41) FINISH, SPMClearTaskVDSCommand, log id: 1e6f264b
2014-04-30 11:32:45,271 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-41) BaseAsyncTask::RemoveTaskFromDB: Removed task 2d17c02c-187f-4f0f-9d16-b617484a623d from DataBase
Comment 4 Greg Sheremeta 2014-04-30 11:41:29 EDT
Ravi, I'm pretty sure this got fixed way back in 3.3. I haven't seen since maybe 5 days I first noticed.
Comment 5 Ravi Nori 2014-04-30 11:43:42 EDT
Thanks Greg, closing as works for me
Comment 6 Allon Mureinik 2014-04-30 12:04:22 EDT
(In reply to Greg Sheremeta from comment #4)
> Ravi, I'm pretty sure this got fixed way back in 3.3. I haven't seen since
> maybe 5 days I first noticed.

(In reply to Ravi Nori from comment #5)
> Thanks Greg, closing as works for me

Changing close reason to UPSTREAM, as comments 4 and 5 concur this was indeed an issue back in some build of 3.3 (where the bug was reported), but was indeed fixed.
Comment 7 Pavel Stehlik 2014-08-12 10:35:25 EDT
This is upstream.

Note You need to log in before you can comment on or make changes to this bug.