[ovirt-users] VM failed to start | Bad volume specification

Wed Feb 25 12:15:02 UTC 2015

Hi Vered,

Yes... it's new VM...even some of the old vm those can run previousely but
now can not run now...

On Wed, Feb 25, 2015 at 3:07 PM, Vered Volansky <vered at redhat.com> wrote:

>
>
> ----- Original Message -----
> > From: "Punit Dambiwal" <hypunit at gmail.com>
> > To: users at ovirt.org
> > Sent: Wednesday, February 25, 2015 6:19:53 AM
> > Subject: [ovirt-users] VM failed to start | Bad volume specification
> >
> > Hi,
> >
> > I try to start the VM but it's failed to start...and through the
> following
> > error :-
> >
> > VM vm1 is down with error. Exit message: Bad volume specification
> {'index':
> > 0, 'iface': 'virtio', 'type': 'disk', 'format': 'raw', 'bootOrder': '1',
> > 'address': {'slot': '0x07', 'bus': '0x00', 'domain': '0x0000', 'type':
> > 'pci', 'function': '0x0'}, 'volumeID':
> > '60c73bf0-d190-420b-917c-04aa00e52f10', 'apparentsize': '1073741824',
> > 'imageID': '8ca66096-bd47-460d-9e09-2966e45b471b', 'specParams': {},
> > 'readonly': 'false', 'domainID': 'e732a82f-bae9-4368-8b98-dedc1c3814de',
> > 'reqsize': '0', 'deviceId': '8ca66096-bd47-460d-9e09-2966e45b471b',
> > 'truesize': '1054048256', 'poolID':
> '00000002-0002-0002-0002-000000000145',
> > 'device': 'disk', 'shared': 'false', 'propagateErrors': 'off',
> 'optional':
> > 'false'}.
> >
> > Please help me to solve this issue....
> >
> > Thanks,
> > Punit
> >
> > _______________________________________________
> > Users mailing list
> > Users at ovirt.org
> > http://lists.ovirt.org/mailman/listinfo/users
> >
>
>
> Please send engine and vdsm logs, it's impossible to help you without
> context.
> What's the history of the VM you were unable to start?
> Is it a new VM?
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ovirt.org/pipermail/users/attachments/20150225/1af75735/attachment-0001.html>
-------------- next part --------------
2015-02-25 20:09:34,786 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [35e576bb] Correlation ID: 35e576bb, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:35,114 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-9) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:35,182 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-9) [33b9d4a7] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:35,183 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-9) [7a411572] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:35,187 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-9) [7a411572] Correlation ID: 7a411572, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:35,281 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-16) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:35,290 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-6) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:35,341 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-6) [4e9b126d] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:35,342 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-6) [76c94fc] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:35,345 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [76c94fc] Correlation ID: 76c94fc, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:35,722 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-7) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:35,765 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-7) [253fea4d] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:35,767 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-7) [46feb2b8] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:35,770 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-7) [46feb2b8] Correlation ID: 46feb2b8, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:36,533 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-5) [382fdfa4] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:36,534 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-5) [570f8b47] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:36,541 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [570f8b47] Correlation ID: 570f8b47, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:36,713 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-19) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:36,760 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-19) [107d6299] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:36,761 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-19) [7cee7ca5] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:36,767 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-19) [7cee7ca5] Correlation ID: 7cee7ca5, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:37,374 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-4) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:37,739 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-14) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:37,784 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-14) [629b8ba3] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:37,786 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-14) [4d898156] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:37,790 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-14) [4d898156] Correlation ID: 4d898156, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:38,142 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-16) [62611cca] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:38,144 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-16) [7d3958db] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:38,160 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-16) [7d3958db] Correlation ID: 7d3958db, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:38,721 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-15) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:38,725 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-21) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:38,764 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-15) [38132028] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:38,766 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-15) [7ea52181] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:38,769 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-15) [7ea52181] Correlation ID: 7ea52181, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:38,902 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-43) [2d7f42d6] START, GlusterVolumesListVDSCommand(HostName = compute3, HostId = 0cb414f1-2cee-4deb-a8fe-540dd6b7aa89), log id: 77476657
2015-02-25 20:09:39,775 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-3) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:39,777 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged in.
2015-02-25 20:09:39,835 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-3) [10796206] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:39,837 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-3) [1f7fa0d] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:39,845 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [1f7fa0d] Correlation ID: 1f7fa0d, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:39,934 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterTasksListVDSCommand] (DefaultQuartzScheduler_Worker-5) [2e249f33] START, GlusterTasksListVDSCommand(HostName = compute6, HostId = 772232e9-d75c-495e-a9d4-2e6479cb44d8), log id: 7fa59574
2015-02-25 20:09:39,955 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-9) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:39,998 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-9) [299c8c22] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:39,999 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-9) [7064afa] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:40,003 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-9) [7064afa] Correlation ID: 7064afa, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:40,090 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterTasksListVDSCommand] (DefaultQuartzScheduler_Worker-5) [2e249f33] FINISH, GlusterTasksListVDSCommand, return: [GlusterAsyncTask[f88a4f39-228a-4452-988c-8d4d5954eec2-REBALANCE-FINISHED]], log id: 7fa59574
2015-02-25 20:09:40,611 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-4) [bb1bebb] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:40,612 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-4) [7dae238e] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:40,617 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-4) [7dae238e] Correlation ID: 7dae238e, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:40,725 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-6) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:40,768 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-6) [7775ee01] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:40,770 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-6) [5800801f] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:40,774 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [5800801f] Correlation ID: 5800801f, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:41,505 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-43) [2d7f42d6] FINISH, GlusterVolumesListVDSCommand, return: {369d3fdc-c8eb-46b7-a33e-0a49f2451ff6=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity at 87dcae7e}, log id: 77476657
2015-02-25 20:09:41,710 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-7) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:41,746 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-7) [78f6e711] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:41,747 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-7) [2e9aeac5] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:41,752 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-7) [2e9aeac5] Correlation ID: 2e9aeac5, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:41,915 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-21) [d9aaa5a] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:41,916 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-21) [573b7df4] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:41,923 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-21) [573b7df4] Correlation ID: 573b7df4, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:42,273 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-5) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:42,724 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-19) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:42,761 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-19) [14d2eb35] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:42,762 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-19) [25a71981] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:42,776 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-19) [25a71981] Correlation ID: 25a71981, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:43,726 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-14) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:43,764 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-14) [181b6b14] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:43,765 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-14) [5b706dd] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:43,769 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-14) [5b706dd] Correlation ID: 5b706dd, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:44,528 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-16) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:44,588 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-16) [7574a545] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:44,589 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-16) [6e8a5650] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:44,596 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-16) [6e8a5650] Correlation ID: 6e8a5650, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:44,717 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-15) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:44,764 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-15) [7b212391] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:44,766 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-15) [7918ce77] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:44,772 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-15) [7918ce77] Correlation ID: 7918ce77, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:44,945 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-3) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:44,948 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged in.
2015-02-25 20:09:45,056 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-5) [76f728e9] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:45,058 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-5) [7c4e592] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:45,064 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [7c4e592] Correlation ID: 7c4e592, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:45,720 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-9) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:45,763 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-9) [2682fb85] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:45,764 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-9) [3986d9f4] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:45,770 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-9) [3986d9f4] Correlation ID: 3986d9f4, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:46,716 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-6) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:46,752 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-6) [23e135f] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:46,754 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-6) [49ee5b] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:46,757 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [49ee5b] Correlation ID: 49ee5b, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:46,878 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-57) START, GlusterVolumesListVDSCommand(HostName = compute3, HostId = 0cb414f1-2cee-4deb-a8fe-540dd6b7aa89), log id: 78af4f6b
2015-02-25 20:09:47,428 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-4) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:47,715 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-7) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:47,759 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-7) [7a4e74c7] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:47,760 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-7) [1d240821] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:47,769 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-7) [1d240821] Correlation ID: 1d240821, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:47,773 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-3) [40892ea5] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:47,774 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-3) [7ef3d452] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:47,777 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [7ef3d452] Correlation ID: 7ef3d452, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:48,724 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-19) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:48,769 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-19) [5e349bf2] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:48,771 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-19) [2d4003b6] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:48,776 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-19) [2d4003b6] Correlation ID: 2d4003b6, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:48,916 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-57) FINISH, GlusterVolumesListVDSCommand, return: {369d3fdc-c8eb-46b7-a33e-0a49f2451ff6=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity at 3bb731c8}, log id: 78af4f6b
2015-02-25 20:09:49,550 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-14) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:49,617 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-14) [396aeb85] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:49,619 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-14) [6b0ba670] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:49,623 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-14) [6b0ba670] Correlation ID: 6b0ba670, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:49,714 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-16) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:49,758 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-16) [b48908b] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:49,760 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-16) [43a3dff0] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:49,766 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-16) [43a3dff0] Correlation ID: 43a3dff0, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:49,838 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-15) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:49,943 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-5) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:50,254 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-4) [6e1af045] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:50,255 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-4) [8f798c0] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:50,259 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-4) [8f798c0] Correlation ID: 8f798c0, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:50,719 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-9) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:50,722 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-9) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged in.
2015-02-25 20:09:50,773 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-9) [44ff1017] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:50,775 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-9) [7c81e24b] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:50,784 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-9) [7c81e24b] Correlation ID: 7c81e24b, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:51,731 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-6) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:51,781 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-6) [7c803792] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:51,783 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-6) [6f82846] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:51,787 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [6f82846] Correlation ID: 6f82846, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:52,454 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-7) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:52,713 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-15) [728ef9ae] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:52,715 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-15) [7d3e0005] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:52,721 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-15) [7d3e0005] Correlation ID: 7d3e0005, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:52,727 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-3) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:52,775 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-3) [335fbf04] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:52,777 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-3) [5731dcc4] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:52,786 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [5731dcc4] Correlation ID: 5731dcc4, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:52,865 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-5) [71835385] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:52,867 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-5) [2a8f0028] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:52,872 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [2a8f0028] Correlation ID: 2a8f0028, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:53,727 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-19) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:53,765 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-19) [15e6d783] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:53,766 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-19) [1a413a7] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:53,770 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-19) [1a413a7] Correlation ID: 1a413a7, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:54,290 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-17) [5c63646a] START, GlusterVolumesListVDSCommand(HostName = compute3, HostId = 0cb414f1-2cee-4deb-a8fe-540dd6b7aa89), log id: 3acba6c0
2015-02-25 20:09:54,529 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-14) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:54,591 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-14) [16811152] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:54,592 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-14) [1b48fff3] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:54,597 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-14) [1b48fff3] Correlation ID: 1b48fff3, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:54,722 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-16) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:54,759 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-16) [1c4008f7] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:54,760 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-16) [7c8505d1] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:54,764 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-16) [7c8505d1] Correlation ID: 7c8505d1, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:54,918 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-4) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:55,244 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-7) [6ea4f2f9] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:55,245 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-7) [493fc6b6] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:55,250 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-7) [493fc6b6] Correlation ID: 493fc6b6, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:55,716 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-9) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:55,754 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-9) [6cfad00f] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:55,755 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-9) [55e9b29a] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:55,765 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-9) [55e9b29a] Correlation ID: 55e9b29a, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:56,061 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-17) [5c63646a] FINISH, GlusterVolumesListVDSCommand, return: {369d3fdc-c8eb-46b7-a33e-0a49f2451ff6=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity at fc63b159}, log id: 3acba6c0
2015-02-25 20:09:56,722 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-6) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:56,731 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged in.
2015-02-25 20:09:56,776 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-6) [277a2a25] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:56,790 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-6) [7a46356] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:56,797 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [7a46356] Correlation ID: 7a46356, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:57,694 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-4) [7a0b539c] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:57,695 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-4) [3b0cc918] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:57,700 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-4) [3b0cc918] Correlation ID: 3b0cc918, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:57,737 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-3) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:57,784 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-3) [773ce99c] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:57,786 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-3) [24ede4ea] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:57,791 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [24ede4ea] Correlation ID: 24ede4ea, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:58,719 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-5) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:58,760 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-5) [397f2631] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:58,762 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-5) [19aa809b] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:58,766 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [19aa809b] Correlation ID: 19aa809b, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:59,538 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-21) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:59,557 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-19) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:59,632 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-21) [19a8bab2] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:59,633 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-21) [7e0db8d4] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:59,638 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-21) [7e0db8d4] Correlation ID: 7e0db8d4, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:59,731 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-14) Running command: LoginUserCommand internal: false.
2015-02-25 20:09:59,767 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-14) [65d8579d] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:09:59,768 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-14) [c50d10f] Running command: LogoutUserCommand internal: false.
2015-02-25 20:09:59,771 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-14) [c50d10f] Correlation ID: c50d10f, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:09:59,913 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-16) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:00,723 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-7) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:00,798 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-7) [580ba025] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:00,800 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-7) [41f4cf71] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:00,803 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-7) [41f4cf71] Correlation ID: 41f4cf71, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:01,488 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-6) [7bbea53d] START, GlusterVolumesListVDSCommand(HostName = compute3, HostId = 0cb414f1-2cee-4deb-a8fe-540dd6b7aa89), log id: 551dfeb5
2015-02-25 20:10:01,721 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-9) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:01,792 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-9) [2ac1792f] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:01,794 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-9) [5afa86ca] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:01,802 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-9) [5afa86ca] Correlation ID: 5afa86ca, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:02,302 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-6) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:02,305 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged in.
2015-02-25 20:10:02,540 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-19) [37b16463] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:02,541 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-19) [755943dd] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:02,547 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-19) [755943dd] Correlation ID: 755943dd, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:02,721 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-4) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:02,798 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-4) [2f67cb67] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:02,799 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-4) [694e3ba3] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:02,802 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-4) [694e3ba3] Correlation ID: 694e3ba3, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:02,811 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-16) [5987b15] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:02,813 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-16) [5b332f5d] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:02,819 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-16) [5b332f5d] Correlation ID: 5b332f5d, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:03,312 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-6) [7bbea53d] FINISH, GlusterVolumesListVDSCommand, return: {369d3fdc-c8eb-46b7-a33e-0a49f2451ff6=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity at 8d1a4dba}, log id: 551dfeb5
2015-02-25 20:10:03,722 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-3) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:03,765 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-3) [61fc0915] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:03,766 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-3) [3e904544] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:03,769 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [3e904544] Correlation ID: 3e904544, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:04,537 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-5) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:04,665 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-5) [251515e8] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:04,666 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-5) [30867954] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:04,671 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [30867954] Correlation ID: 30867954, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:04,756 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-21) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:04,844 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-21) [47240d38] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:04,845 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-21) [5d5d9fe9] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:04,849 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-21) [5d5d9fe9] Correlation ID: 5d5d9fe9, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:04,959 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-14) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:05,075 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-6) [525d2f9f] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:05,076 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-6) [8d8998a] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:05,080 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [8d8998a] Correlation ID: 8d8998a, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:05,724 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-7) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:05,803 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-7) [2a5f9203] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:05,804 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-7) [6c1455d2] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:05,807 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-7) [6c1455d2] Correlation ID: 6c1455d2, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:06,718 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-9) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:06,763 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-9) [14b9bc4e] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:06,764 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-9) [73f406bb] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:06,768 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-9) [73f406bb] Correlation ID: 73f406bb, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:07,706 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-14) [73d4cde4] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:07,708 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-14) [69e4baa0] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:07,719 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-14) [69e4baa0] Correlation ID: 69e4baa0, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:07,736 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-19) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:07,740 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-19) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged in.
2015-02-25 20:10:07,790 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-19) [bc53549] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:07,792 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-19) [68dd2c1a] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:07,796 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-19) [68dd2c1a] Correlation ID: 68dd2c1a, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:08,682 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-9) [1a8485ff] START, GlusterVolumesListVDSCommand(HostName = compute3, HostId = 0cb414f1-2cee-4deb-a8fe-540dd6b7aa89), log id: 1be9c7ed
2015-02-25 20:10:08,730 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-4) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:08,811 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-4) [6c50fb0f] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:08,812 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-4) [29f6378d] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:08,816 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-4) [29f6378d] Correlation ID: 29f6378d, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:09,514 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-16) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:09,604 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-16) [6bde022c] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:09,605 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-16) [4d1b9663] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:09,611 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-16) [4d1b9663] Correlation ID: 4d1b9663, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:09,704 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-3) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:09,705 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-5) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:09,753 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-3) [3cf5bf0d] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:09,755 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-3) [276c87ff] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:09,765 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [276c87ff] Correlation ID: 276c87ff, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:09,937 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-21) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:10,728 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-6) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:10,803 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-6) [54d6386b] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:10,804 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-6) [3e5a561a] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:10,810 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [3e5a561a] Correlation ID: 3e5a561a, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:11,479 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-9) [1a8485ff] FINISH, GlusterVolumesListVDSCommand, return: {369d3fdc-c8eb-46b7-a33e-0a49f2451ff6=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity at 91a5e528}, log id: 1be9c7ed
2015-02-25 20:10:11,724 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-7) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:11,826 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-7) [47c78b89] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:11,828 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-7) [741042b1] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:11,832 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-7) [741042b1] Correlation ID: 741042b1, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:12,282 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-9) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:12,688 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-5) [76d63441] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:12,689 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-5) [6c0dc488] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:12,694 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [6c0dc488] Correlation ID: 6c0dc488, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:12,731 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-19) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:12,767 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-19) [6a9af06f] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:12,769 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-19) [64478e9d] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:12,771 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-19) [64478e9d] Correlation ID: 64478e9d, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:12,812 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-21) [7c8afcdf] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:12,813 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-21) [7b72138a] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:12,816 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-21) [7b72138a] Correlation ID: 7b72138a, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:13,740 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-14) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:13,743 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-14) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged in.
2015-02-25 20:10:13,835 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-14) [a675b42] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:13,836 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-14) [bab9d52] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:13,839 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-14) [bab9d52] Correlation ID: bab9d52, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:14,536 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-4) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:14,603 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-4) [65508532] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:14,605 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-4) [15da2d1e] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:14,619 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-4) [15da2d1e] Correlation ID: 15da2d1e, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:14,738 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-16) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:14,820 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-16) [25bcee2c] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:14,822 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-16) [7a941fe2] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:14,826 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-16) [7a941fe2] Correlation ID: 7a941fe2, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:15,057 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-9) [3385c761] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:15,058 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-9) [4281c053] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:15,062 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-9) [4281c053] Correlation ID: 4281c053, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:15,858 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-3) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:15,863 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-6) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:15,908 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-3) [523db954] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:15,910 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-3) [18eca2db] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:15,914 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [18eca2db] Correlation ID: 18eca2db, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:16,719 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-7) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:16,763 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-7) [488ecfe7] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:16,764 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-7) [ec746f2] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:16,767 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-7) [ec746f2] Correlation ID: ec746f2, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:16,889 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-48) START, GlusterVolumesListVDSCommand(HostName = compute3, HostId = 0cb414f1-2cee-4deb-a8fe-540dd6b7aa89), log id: 21edf6c6
2015-02-25 20:10:17,266 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-19) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:17,716 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-21) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:17,768 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-21) [6f5d1302] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:17,769 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-21) [39a6e723] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:17,777 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-21) [39a6e723] Correlation ID: 39a6e723, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:18,712 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-6) [18aa20a0] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:18,713 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-6) [61e0d3f2] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:18,748 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [61e0d3f2] Correlation ID: 61e0d3f2, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:18,799 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-5) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:18,821 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged in.
2015-02-25 20:10:18,893 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-48) FINISH, GlusterVolumesListVDSCommand, return: {369d3fdc-c8eb-46b7-a33e-0a49f2451ff6=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity at 1cc95225}, log id: 21edf6c6
2015-02-25 20:10:18,929 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-5) [6e8aa339] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:18,931 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-5) [5bbdbbb5] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:18,961 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [5bbdbbb5] Correlation ID: 5bbdbbb5, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:19,314 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (DefaultQuartzScheduler_Worker-14) START, DestroyVDSCommand(HostName = compute11, HostId = ea2e9d98-b780-4816-83f0-be2cbf411223, vmId=93536f77-d1d8-4bb9-a7b9-ba20da66579f, force=false, secondsToWait=0, gracefully=false, reason=), log id: 7cd4a814
2015-02-25 20:10:19,328 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (DefaultQuartzScheduler_Worker-14) FINISH, DestroyVDSCommand, log id: 7cd4a814
2015-02-25 20:10:19,369 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-14) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM punit is down with error. Exit message: Bad volume specification {'index': 0, 'iface': 'virtio', 'type': 'disk', 'format': 'raw', 'bootOrder': '1', 'address': {'slot': '0x07', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'volumeID': '60c73bf0-d190-420b-917c-04aa00e52f10', 'apparentsize': '1073741824', 'imageID': '8ca66096-bd47-460d-9e09-2966e45b471b', 'specParams': {}, 'readonly': 'false', 'domainID': 'e732a82f-bae9-4368-8b98-dedc1c3814de', 'reqsize': '0', 'deviceId': '8ca66096-bd47-460d-9e09-2966e45b471b', 'truesize': '1054048256', 'poolID': '00000002-0002-0002-0002-000000000145', 'device': 'disk', 'shared': 'false', 'propagateErrors': 'off', 'optional': 'false'}.
2015-02-25 20:10:19,371 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-14) Running on vds during rerun failed vm: null
2015-02-25 20:10:19,373 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-14) VM punit (93536f77-d1d8-4bb9-a7b9-ba20da66579f) is running in db and not running in VDS compute11
2015-02-25 20:10:19,374 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-14) add VM punit to HA rerun treatment
2015-02-25 20:10:19,374 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-14) START, FullListVdsCommand(HostName = compute11, HostId = ea2e9d98-b780-4816-83f0-be2cbf411223, vds=Host[compute11,ea2e9d98-b780-4816-83f0-be2cbf411223], vmIds=[93536f77-d1d8-4bb9-a7b9-ba20da66579f]), log id: 696fc81a
2015-02-25 20:10:19,470 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-14) FINISH, FullListVdsCommand, return: [], log id: 696fc81a
2015-02-25 20:10:19,480 ERROR [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-14) Rerun vm 93536f77-d1d8-4bb9-a7b9-ba20da66579f. Called from vds compute11
2015-02-25 20:10:19,493 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-31) Correlation ID: 7c31d88, Job ID: 934b36d4-733a-47bb-be77-8ae9c6ddfce1, Call Stack: null, Custom Event ID: -1, Message: Failed to run VM punit on Host compute11.
2015-02-25 20:10:19,506 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-31) Lock Acquired to object EngineLock [exclusiveLocks= key: 93536f77-d1d8-4bb9-a7b9-ba20da66579f value: VM
, sharedLocks= ]
2015-02-25 20:10:19,542 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-14) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:19,587 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-8-thread-31) START, IsVmDuringInitiatingVDSCommand( vmId = 93536f77-d1d8-4bb9-a7b9-ba20da66579f), log id: ef3f067
2015-02-25 20:10:19,587 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-8-thread-31) FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: ef3f067
2015-02-25 20:10:19,604 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-14) [691917af] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:19,605 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-14) [291cea] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:19,629 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-14) [291cea] Correlation ID: 291cea, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:19,742 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-4) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:19,788 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-4) [21d86bb6] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:19,789 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-4) [6cc3eb03] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:19,795 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-4) [6cc3eb03] Correlation ID: 6cc3eb03, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:19,811 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-31) Running command: RunVmCommand internal: false. Entities affected :  ID: 93536f77-d1d8-4bb9-a7b9-ba20da66579f Type: VMAction group VM_BASIC_OPERATIONS with role type USER
2015-02-25 20:10:19,990 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-9) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:20,031 INFO  [org.ovirt.engine.core.bll.scheduling.policyunits.HaReservationWeightPolicyUnit] (org.ovirt.thread.pool-8-thread-31) Started HA reservation scoring method
2015-02-25 20:10:20,081 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-19) [164d8ea0] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:20,083 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-19) [6cc396aa] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:20,094 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-19) [6cc396aa] Correlation ID: 6cc396aa, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:20,103 INFO  [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-31) START, UpdateVmDynamicDataVDSCommand(HostName = compute7, HostId = 922a8106-6c20-4045-91c5-66f409425081, vmDynamic=org.ovirt.engine.core.common.businessentities.VmDynamic at 7203bc63), log id: 35094f84
2015-02-25 20:10:20,107 INFO  [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-31) FINISH, UpdateVmDynamicDataVDSCommand, log id: 35094f84
2015-02-25 20:10:20,125 INFO  [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-31) START, CreateVmVDSCommand(HostName = compute7, HostId = 922a8106-6c20-4045-91c5-66f409425081, vmId=93536f77-d1d8-4bb9-a7b9-ba20da66579f, vm=VM [punit]), log id: 172d9857
2015-02-25 20:10:20,145 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-31) START, CreateVDSCommand(HostName = compute7, HostId = 922a8106-6c20-4045-91c5-66f409425081, vmId=93536f77-d1d8-4bb9-a7b9-ba20da66579f, vm=VM [punit]), log id: 52830a38
2015-02-25 20:10:20,160 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-31) org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand kvmEnable=true,keyboardLayout=en-us,nice=0,pitReinjection=false,displayNetwork=ovirtmgmt,timeOffset=28800,transparentHugePages=true,vmId=93536f77-d1d8-4bb9-a7b9-ba20da66579f,acpiEnable=true,custom={},spiceSslCipherSuite=DEFAULT,memSize=512,smp=1,emulatedMachine=rhel6.5.0,vmType=kvm,memGuaranteedSize=512,display=vnc,smartcardEnable=false,bootMenuEnable=false,tabletEnable=true,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,smpCoresPerSocket=1,maxVCpus=16,devices=[{specParams={vram=32768, heads=1}, device=cirrus, type=video, deviceId=a08c0ea7-4e51-4376-a59b-afb7766e37a7}, {shared=false, iface=ide, index=2, specParams={path=}, path=, device=cdrom, type=disk, readonly=true, deviceId=ead0e7e0-e423-4684-bf07-9ef046848061}, {shared=false, index=0, volumeID=60c73bf0-d190-420b-917c-04aa00e52f10, propagateErrors=off, format=raw, type=disk, iface=virtio, bootOrder=1, address={bus=0x00, domain=0x0000, slot=0x07, type=pci, function=0x0}, domainID=e732a82f-bae9-4368-8b98-dedc1c3814de, imageID=8ca66096-bd47-460d-9e09-2966e45b471b, specParams={}, optional=false, device=disk, poolID=00000002-0002-0002-0002-000000000145, readonly=false, deviceId=8ca66096-bd47-460d-9e09-2966e45b471b}, {index=0, model=virtio-scsi, address={bus=0x00, domain=0x0000, slot=0x05, type=pci, function=0x0}, specParams={}, device=scsi, type=controller, deviceId=e9015278-de33-4cc6-bfaa-249c595ecdcd}, {address={bus=0x00, domain=0x0000, slot=0x06, type=pci, function=0x0}, specParams={}, device=virtio-serial, type=controller, deviceId=bd809c58-83e1-46ba-b653-9f8aee89009f}],vmName=punit,cpuType=SandyBridge
2015-02-25 20:10:20,715 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-3) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:20,758 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-3) [64dba47b] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:20,759 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-3) [2ef7eee2] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:20,772 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [2ef7eee2] Correlation ID: 2ef7eee2, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:21,587 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-31) FINISH, CreateVDSCommand, log id: 52830a38
2015-02-25 20:10:21,604 INFO  [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-31) FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 172d9857
2015-02-25 20:10:21,605 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-31) Lock freed to object EngineLock [exclusiveLocks= key: 93536f77-d1d8-4bb9-a7b9-ba20da66579f value: VM
, sharedLocks= ]
2015-02-25 20:10:21,609 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-31) Correlation ID: 7c31d88, Job ID: 934b36d4-733a-47bb-be77-8ae9c6ddfce1, Call Stack: null, Custom Event ID: -1, Message: VM punit was started by admin at internal (Host: compute7).
2015-02-25 20:10:21,729 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-21) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:21,780 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-21) [7daafe81] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:21,782 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-21) [6d4083a] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:21,788 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-21) [6d4083a] Correlation ID: 6d4083a, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:22,273 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-6) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:22,720 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-5) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:22,739 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-9) [77b67a14] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:22,740 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-9) [40b4fa02] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:22,745 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-9) [40b4fa02] Correlation ID: 40b4fa02, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:22,767 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-5) [8b3511d] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:22,768 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-5) [44b739e7] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:22,771 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [44b739e7] Correlation ID: 44b739e7, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:23,699 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-14) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:23,742 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-14) [1846c18c] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:23,743 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-14) [8de98a6] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:23,756 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-14) [8de98a6] Correlation ID: 8de98a6, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:24,286 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-54) START, GlusterVolumesListVDSCommand(HostName = compute3, HostId = 0cb414f1-2cee-4deb-a8fe-540dd6b7aa89), log id: 38cf3246
2015-02-25 20:10:24,542 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-4) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:24,545 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-4) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged in.
2015-02-25 20:10:24,605 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-4) [4dca614b] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:24,606 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-4) [2b7835f6] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:24,617 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-4) [2b7835f6] Correlation ID: 2b7835f6, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:24,716 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-19) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:24,772 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-19) [2d0e5581] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:24,773 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-19) [37944227] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:24,783 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-19) [37944227] Correlation ID: 37944227, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:24,948 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-3) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:25,120 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-6) [9b06b67] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:25,121 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-6) [766ee576] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:25,135 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [766ee576] Correlation ID: 766ee576, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:25,733 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-21) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:25,741 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-5) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:25,778 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-5) [3e5b11fa] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:25,793 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-5) [5c2b9a7e] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:25,799 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [5c2b9a7e] Correlation ID: 5c2b9a7e, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:26,656 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-54) FINISH, GlusterVolumesListVDSCommand, return: {369d3fdc-c8eb-46b7-a33e-0a49f2451ff6=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity at ff2cfafd}, log id: 38cf3246
2015-02-25 20:10:26,695 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-14) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:26,733 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-14) [106cfd03] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:26,734 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-14) [5b21c6bb] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:26,743 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-14) [5b21c6bb] Correlation ID: 5b21c6bb, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:26,854 INFO  [org.ovirt.engine.core.bll.scheduling.policyunits.EvenGuestDistributionBalancePolicyUnit] (DefaultQuartzScheduler_Worker-80) There is no host with more than 300 running guests, no balancing is needed
2015-02-25 20:10:27,718 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-4) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:27,762 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-4) [93a47c] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:27,764 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-4) [4e3b3664] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:27,770 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-4) [4e3b3664] Correlation ID: 4e3b3664, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:27,821 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-3) [438eaac6] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:27,822 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-3) [7e638006] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:27,828 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [7e638006] Correlation ID: 7e638006, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:28,607 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-21) [2a09bae6] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:28,609 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-21) [2e41502d] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:28,616 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-21) [2e41502d] Correlation ID: 2e41502d, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:28,741 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-19) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:28,791 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-19) [3f8865a1] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:28,792 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-19) [431ce360] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:28,797 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-19) [431ce360] Correlation ID: 431ce360, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:29,156 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-44) START, FullListVdsCommand(HostName = compute7, HostId = 922a8106-6c20-4045-91c5-66f409425081, vds=Host[compute7,922a8106-6c20-4045-91c5-66f409425081], vmIds=[93536f77-d1d8-4bb9-a7b9-ba20da66579f]), log id: 6c60f8bb
2015-02-25 20:10:29,163 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-44) FINISH, FullListVdsCommand, return: [{displaySecurePort=-1, kvmEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, guestDiskMapping={}, displayIp=43.252.177.16, pitReinjection=false, nice=0, displayNetwork=ovirtmgmt, timeOffset=28800, transparentHugePages=true, vmId=93536f77-d1d8-4bb9-a7b9-ba20da66579f, acpiEnable=true, custom={}, spiceSslCipherSuite=DEFAULT, memSize=512, smp=1, displayPort=-1, emulatedMachine=rhel6.5.0, vmType=kvm, status=WaitForLaunch, memGuaranteedSize=512, display=vnc, pid=0, smartcardEnable=false, bootMenuEnable=false, tabletEnable=true, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, smpCoresPerSocket=1, maxVCpus=16, clientIp=, devices=[Ljava.lang.Object;@5269f493, vmName=punit, cpuType=SandyBridge}], log id: 6c60f8bb
2015-02-25 20:10:29,167 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-44) Received a cirrus Device without an address when processing VM 93536f77-d1d8-4bb9-a7b9-ba20da66579f devices, skipping device: {specParams={vram=32768, heads=1}, device=cirrus, type=video, deviceId=a08c0ea7-4e51-4376-a59b-afb7766e37a7}
2015-02-25 20:10:29,168 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-44) Received a cdrom Device without an address when processing VM 93536f77-d1d8-4bb9-a7b9-ba20da66579f devices, skipping device: {shared=false, iface=ide, index=2, specParams={path=}, path=, device=cdrom, type=disk, readonly=true, deviceId=ead0e7e0-e423-4684-bf07-9ef046848061}
2015-02-25 20:10:29,510 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-6) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:29,568 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-6) [4905744] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:29,569 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-6) [20f15d3d] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:29,575 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [20f15d3d] Correlation ID: 20f15d3d, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:29,713 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-5) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:29,716 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged in.
2015-02-25 20:10:29,753 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-5) [2cae6eff] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:29,754 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-5) [569b6709] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:29,759 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [569b6709] Correlation ID: 569b6709, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:29,976 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-14) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:30,717 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-4) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:30,738 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-3) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:30,810 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-4) [6a84d2d1] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:30,812 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-4) [4c4c3bc2] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:30,817 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-4) [4c4c3bc2] Correlation ID: 4c4c3bc2, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:31,720 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-21) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:31,771 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-21) [81d64c9] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:31,772 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-21) [561c0fb] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:31,777 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-21) [561c0fb] Correlation ID: 561c0fb, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:32,071 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-79) [78233d65] START, GlusterVolumesListVDSCommand(HostName = compute3, HostId = 0cb414f1-2cee-4deb-a8fe-540dd6b7aa89), log id: 686b890f
2015-02-25 20:10:32,292 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-19) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:32,737 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-6) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:32,775 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-6) [135c1d92] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:32,776 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-6) [39ad173] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:32,780 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [39ad173] Correlation ID: 39ad173, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:32,882 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-14) [13b71231] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:32,884 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-14) [50931f07] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:32,889 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-14) [50931f07] Correlation ID: 50931f07, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:33,592 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-3) [5b8c7be0] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:33,593 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-3) [1a37f83c] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:33,604 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [1a37f83c] Correlation ID: 1a37f83c, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:33,714 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-5) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:33,752 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-5) [42621429] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:33,753 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-5) [267890dc] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:33,762 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [267890dc] Correlation ID: 267890dc, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:34,508 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-4) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:34,582 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-4) [5a28fde9] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:34,583 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-4) [2fb7add0] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:34,589 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-4) [2fb7add0] Correlation ID: 2fb7add0, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:34,706 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-21) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:34,774 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-21) [70024c47] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:34,775 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-21) [3386501b] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:34,780 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-21) [3386501b] Correlation ID: 3386501b, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:34,958 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-15) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:34,961 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-15) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged in.
2015-02-25 20:10:35,147 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-19) [644319f] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:35,148 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-19) [1ac05880] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:35,153 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-19) [1ac05880] Correlation ID: 1ac05880, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:35,586 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-79) [78233d65] FINISH, GlusterVolumesListVDSCommand, return: {369d3fdc-c8eb-46b7-a33e-0a49f2451ff6=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity at b7626bfc}, log id: 686b890f
2015-02-25 20:10:35,721 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-14) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:35,723 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-6) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:35,772 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-14) [10dc2d66] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:35,773 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-14) [5319d840] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:35,777 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-14) [5319d840] Correlation ID: 5319d840, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:36,726 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-3) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:36,772 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-3) [1a9bd8a1] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:36,773 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-3) [5bc2577a] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:36,776 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [5bc2577a] Correlation ID: 5bc2577a, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:37,696 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-5) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:37,740 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-5) [5f8c8249] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:37,741 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-5) [16989cc8] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:37,744 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [16989cc8] Correlation ID: 16989cc8, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:37,913 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-15) [36ea9af7] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:37,915 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-15) [2193fbb5] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:37,920 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-15) [2193fbb5] Correlation ID: 2193fbb5, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:38,723 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-6) [29f3eaf2] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:38,724 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-6) [75b21492] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:38,727 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-4) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:38,728 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [75b21492] Correlation ID: 75b21492, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:38,762 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-4) [3f4020fa] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:38,764 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-4) [73d5a6a6] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:38,775 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-4) [73d5a6a6] Correlation ID: 73d5a6a6, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:39,524 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-21) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:39,595 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-21) [67814935] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:39,597 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-21) [44244caa] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:39,602 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-21) [44244caa] Correlation ID: 44244caa, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:39,717 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-19) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:39,761 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-19) [33fd28f8] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:39,762 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-19) [24a4982d] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:39,766 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-19) [24a4982d] Correlation ID: 24a4982d, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:40,263 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterTasksListVDSCommand] (DefaultQuartzScheduler_Worker-65) START, GlusterTasksListVDSCommand(HostName = compute6, HostId = 772232e9-d75c-495e-a9d4-2e6479cb44d8), log id: 2d026dfd
2015-02-25 20:10:40,714 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-14) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:40,716 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-14) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged in.
2015-02-25 20:10:40,754 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-14) [5c44c204] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:40,755 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-14) [1b85ae91] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:40,759 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-14) [1b85ae91] Correlation ID: 1b85ae91, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:40,973 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-31) START, GlusterVolumesListVDSCommand(HostName = compute3, HostId = 0cb414f1-2cee-4deb-a8fe-540dd6b7aa89), log id: 375742b7
2015-02-25 20:10:41,138 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterTasksListVDSCommand] (DefaultQuartzScheduler_Worker-65) FINISH, GlusterTasksListVDSCommand, return: [GlusterAsyncTask[f88a4f39-228a-4452-988c-8d4d5954eec2-REBALANCE-FINISHED]], log id: 2d026dfd
2015-02-25 20:10:41,717 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-3) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:41,753 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-3) [78dab482] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:41,754 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-3) [5fafbfde] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:41,757 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [5fafbfde] Correlation ID: 5fafbfde, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:42,289 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-5) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:42,709 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-31) FINISH, GlusterVolumesListVDSCommand, return: {369d3fdc-c8eb-46b7-a33e-0a49f2451ff6=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity at 68f82d17}, log id: 375742b7
2015-02-25 20:10:42,713 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-15) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:42,750 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-15) [72eb5081] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:42,751 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-15) [64bb756a] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:42,755 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-15) [64bb756a] Correlation ID: 64bb756a, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:43,720 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-9) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:43,765 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-9) [73ad45c7] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:43,767 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-9) [3a73e847] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:43,771 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-9) [3a73e847] Correlation ID: 3a73e847, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:44,524 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-4) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:44,583 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-4) [1446a526] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:44,584 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-4) [c7f90e4] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:44,589 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-4) [c7f90e4] Correlation ID: c7f90e4, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
2015-02-25 20:10:44,718 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (ajp--127.0.0.1-8702-6) Running command: LoginUserCommand internal: false.
2015-02-25 20:10:44,759 INFO  [org.ovirt.engine.core.bll.aaa.LogoutBySessionCommand] (ajp--127.0.0.1-8702-6) [4f8b0888] Running command: LogoutBySessionCommand internal: false.
2015-02-25 20:10:44,761 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (ajp--127.0.0.1-8702-6) [3fceb0f7] Running command: LogoutUserCommand internal: false.
2015-02-25 20:10:44,767 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [3fceb0f7] Correlation ID: 3fceb0f7, Call Stack: null, Custom Event ID: -1, Message: User admin at internal logged out.
-------------- next part --------------
Thread-4574::DEBUG::2015-02-25 20:10:13,701::task::1191::Storage.TaskManager.Task::(prepare) Task=`20e770ec-87d9-47b8-8969-9bc50f8b8c88`::finished: {'truesize': '2616532992', 'apparentsize': '64424509440'}
Thread-1753::DEBUG::2015-02-25 20:10:13,702::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-4574::DEBUG::2015-02-25 20:10:13,702::task::595::Storage.TaskManager.Task::(_updateState) Task=`20e770ec-87d9-47b8-8969-9bc50f8b8c88`::moving from state preparing -> state finished
Thread-1753::DEBUG::2015-02-25 20:10:13,703::task::993::Storage.TaskManager.Task::(_decref) Task=`8040385c-b701-4ddd-89c6-14e30c619999`::ref 0 aborting False
Thread-4574::DEBUG::2015-02-25 20:10:13,703::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-4574::DEBUG::2015-02-25 20:10:13,704::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-4574::DEBUG::2015-02-25 20:10:13,704::task::993::Storage.TaskManager.Task::(_decref) Task=`20e770ec-87d9-47b8-8969-9bc50f8b8c88`::ref 0 aborting False
Thread-590::DEBUG::2015-02-25 20:10:13,936::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1753::DEBUG::2015-02-25 20:10:13,960::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-4574::DEBUG::2015-02-25 20:10:13,970::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-24::DEBUG::2015-02-25 20:10:15,394::fileSD::261::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/glusterSD/10.10.0.14:_ds01/e732a82f-bae9-4368-8b98-dedc1c3814de/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-24::DEBUG::2015-02-25 20:10:15,629::fileSD::261::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n457 bytes (457 B) copied, 0.000905785 s, 505 kB/s\n'; <rc> = 0
Thread-606::DEBUG::2015-02-25 20:10:16,075::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-4437::DEBUG::2015-02-25 20:10:16,683::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-627::DEBUG::2015-02-25 20:10:16,684::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-5186::DEBUG::2015-02-25 20:10:16,687::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-659::DEBUG::2015-02-25 20:10:17,381::task::595::Storage.TaskManager.Task::(_updateState) Task=`f4fe70e2-09ec-4333-8f23-c513668b2d78`::moving from state init -> state preparing
Thread-659::INFO::2015-02-25 20:10:17,383::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='343ec1cb-87d0-4965-9693-8d70b8303dee', volUUID='2873e00b-b02b-4bb4-a293-e7f237572d12', options=None)
Thread-659::INFO::2015-02-25 20:10:17,393::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1586053120', 'apparentsize': '21474836480'}
Thread-659::DEBUG::2015-02-25 20:10:17,394::task::1191::Storage.TaskManager.Task::(prepare) Task=`f4fe70e2-09ec-4333-8f23-c513668b2d78`::finished: {'truesize': '1586053120', 'apparentsize': '21474836480'}
Thread-659::DEBUG::2015-02-25 20:10:17,395::task::595::Storage.TaskManager.Task::(_updateState) Task=`f4fe70e2-09ec-4333-8f23-c513668b2d78`::moving from state preparing -> state finished
Thread-659::DEBUG::2015-02-25 20:10:17,396::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-659::DEBUG::2015-02-25 20:10:17,396::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-659::DEBUG::2015-02-25 20:10:17,397::task::993::Storage.TaskManager.Task::(_decref) Task=`f4fe70e2-09ec-4333-8f23-c513668b2d78`::ref 0 aborting False
Thread-659::DEBUG::2015-02-25 20:10:17,529::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-379::DEBUG::2015-02-25 20:10:17,707::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-9518::ERROR::2015-02-25 20:10:17,941::task::866::Storage.TaskManager.Task::(_setError) Task=`8b8d0a5a-40e2-4ebf-a5d7-b3dbb383ff81`::Unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 873, in _run
    return fn(*args, **kargs)
  File "/usr/share/vdsm/logUtils.py", line 45, in wrapper
    res = f(*args, **kwargs)
  File "/usr/share/vdsm/storage/hsm.py", line 3205, in prepareImage
    allVols = dom.getAllVolumes()
  File "/usr/share/vdsm/storage/fileSD.py", line 425, in getAllVolumes
    volMetaPaths = self.oop.glob.glob(volMetaPattern)
  File "/usr/share/vdsm/storage/outOfProcess.py", line 89, in glob
    return self._iop.glob(pattern)
  File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 500, in glob
    return self._sendCommand("glob", {"pattern": pattern}, self.timeout)
  File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 385, in _sendCommand
    raise Timeout(os.strerror(errno.ETIMEDOUT))
Timeout: Connection timed out
Thread-9518::DEBUG::2015-02-25 20:10:17,942::task::885::Storage.TaskManager.Task::(_run) Task=`8b8d0a5a-40e2-4ebf-a5d7-b3dbb383ff81`::Task._run: 8b8d0a5a-40e2-4ebf-a5d7-b3dbb383ff81 ('e732a82f-bae9-4368-8b98-dedc1c3814de', '00000002-0002-0002-0002-000000000145', '8ca66096-bd47-460d-9e09-2966e45b471b', '60c73bf0-d190-420b-917c-04aa00e52f10') {} failed - stopping task
Thread-9518::DEBUG::2015-02-25 20:10:17,942::task::1217::Storage.TaskManager.Task::(stop) Task=`8b8d0a5a-40e2-4ebf-a5d7-b3dbb383ff81`::stopping in state preparing (force False)
Thread-9518::DEBUG::2015-02-25 20:10:17,942::task::993::Storage.TaskManager.Task::(_decref) Task=`8b8d0a5a-40e2-4ebf-a5d7-b3dbb383ff81`::ref 1 aborting True
Thread-9518::INFO::2015-02-25 20:10:17,943::task::1171::Storage.TaskManager.Task::(prepare) Task=`8b8d0a5a-40e2-4ebf-a5d7-b3dbb383ff81`::aborting: Task is aborted: u'Connection timed out' - code 100
Thread-9518::DEBUG::2015-02-25 20:10:17,943::task::1176::Storage.TaskManager.Task::(prepare) Task=`8b8d0a5a-40e2-4ebf-a5d7-b3dbb383ff81`::Prepare: aborted: Connection timed out
Thread-9518::DEBUG::2015-02-25 20:10:17,943::task::993::Storage.TaskManager.Task::(_decref) Task=`8b8d0a5a-40e2-4ebf-a5d7-b3dbb383ff81`::ref 0 aborting True
Thread-9518::DEBUG::2015-02-25 20:10:17,943::task::928::Storage.TaskManager.Task::(_doAbort) Task=`8b8d0a5a-40e2-4ebf-a5d7-b3dbb383ff81`::Task._doAbort: force False
Thread-9518::DEBUG::2015-02-25 20:10:17,943::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-9518::DEBUG::2015-02-25 20:10:17,944::task::595::Storage.TaskManager.Task::(_updateState) Task=`8b8d0a5a-40e2-4ebf-a5d7-b3dbb383ff81`::moving from state preparing -> state aborting
Thread-9518::DEBUG::2015-02-25 20:10:17,944::task::550::Storage.TaskManager.Task::(__state_aborting) Task=`8b8d0a5a-40e2-4ebf-a5d7-b3dbb383ff81`::_aborting: recover policy none
Thread-9518::DEBUG::2015-02-25 20:10:17,944::task::595::Storage.TaskManager.Task::(_updateState) Task=`8b8d0a5a-40e2-4ebf-a5d7-b3dbb383ff81`::moving from state aborting -> state failed
Thread-9518::DEBUG::2015-02-25 20:10:17,944::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.e732a82f-bae9-4368-8b98-dedc1c3814de': < ResourceRef 'Storage.e732a82f-bae9-4368-8b98-dedc1c3814de', isValid: 'True' obj: 'None'>}
Thread-9518::DEBUG::2015-02-25 20:10:17,944::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-9518::DEBUG::2015-02-25 20:10:17,945::resourceManager::616::Storage.ResourceManager::(releaseResource) Trying to release resource 'Storage.e732a82f-bae9-4368-8b98-dedc1c3814de'
Thread-9518::DEBUG::2015-02-25 20:10:17,945::resourceManager::635::Storage.ResourceManager::(releaseResource) Released resource 'Storage.e732a82f-bae9-4368-8b98-dedc1c3814de' (0 active users)
Thread-9518::DEBUG::2015-02-25 20:10:17,945::resourceManager::641::Storage.ResourceManager::(releaseResource) Resource 'Storage.e732a82f-bae9-4368-8b98-dedc1c3814de' is free, finding out if anyone is waiting for it.
Thread-9518::DEBUG::2015-02-25 20:10:17,945::resourceManager::649::Storage.ResourceManager::(releaseResource) No one is waiting for resource 'Storage.e732a82f-bae9-4368-8b98-dedc1c3814de', Clearing records.
Thread-9518::ERROR::2015-02-25 20:10:17,946::dispatcher::79::Storage.Dispatcher::(wrapper) Connection timed out
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/dispatcher.py", line 71, in wrapper
    result = ctask.prepare(func, *args, **kwargs)
  File "/usr/share/vdsm/storage/task.py", line 103, in wrapper
    return m(self, *a, **kw)
  File "/usr/share/vdsm/storage/task.py", line 1179, in prepare
    raise self.error
Timeout: Connection timed out
Thread-9518::DEBUG::2015-02-25 20:10:17,946::vm::2294::vm.Vm::(_startUnderlyingVm) vmId=`93536f77-d1d8-4bb9-a7b9-ba20da66579f`::_ongoingCreations released
Thread-9518::ERROR::2015-02-25 20:10:17,947::vm::2331::vm.Vm::(_startUnderlyingVm) vmId=`93536f77-d1d8-4bb9-a7b9-ba20da66579f`::The vm start process failed
Traceback (most recent call last):
  File "/usr/share/vdsm/virt/vm.py", line 2271, in _startUnderlyingVm
    self._run()
  File "/usr/share/vdsm/virt/vm.py", line 3266, in _run
    self.preparePaths(devices[DISK_DEVICES])
  File "/usr/share/vdsm/virt/vm.py", line 2353, in preparePaths
    drive['path'] = self.cif.prepareVolumePath(drive, self.id)
  File "/usr/share/vdsm/clientIF.py", line 277, in prepareVolumePath
    raise vm.VolumeError(drive)
VolumeError: Bad volume specification {'index': 0, 'iface': 'virtio', 'type': 'disk', 'format': 'raw', 'bootOrder': '1', 'address': {'slot': '0x07', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'volumeID': '60c73bf0-d190-420b-917c-04aa00e52f10', 'apparentsize': '1073741824', 'imageID': '8ca66096-bd47-460d-9e09-2966e45b471b', 'specParams': {}, 'readonly': 'false', 'domainID': 'e732a82f-bae9-4368-8b98-dedc1c3814de', 'reqsize': '0', 'deviceId': '8ca66096-bd47-460d-9e09-2966e45b471b', 'truesize': '1054048256', 'poolID': '00000002-0002-0002-0002-000000000145', 'device': 'disk', 'shared': 'false', 'propagateErrors': 'off', 'optional': 'false'}
Thread-9518::DEBUG::2015-02-25 20:10:17,948::vm::2786::vm.Vm::(setDownStatus) vmId=`93536f77-d1d8-4bb9-a7b9-ba20da66579f`::Changed state to Down: Bad volume specification {'index': 0, 'iface': 'virtio', 'type': 'disk', 'format': 'raw', 'bootOrder': '1', 'address': {'slot': '0x07', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'volumeID': '60c73bf0-d190-420b-917c-04aa00e52f10', 'apparentsize': '1073741824', 'imageID': '8ca66096-bd47-460d-9e09-2966e45b471b', 'specParams': {}, 'readonly': 'false', 'domainID': 'e732a82f-bae9-4368-8b98-dedc1c3814de', 'reqsize': '0', 'deviceId': '8ca66096-bd47-460d-9e09-2966e45b471b', 'truesize': '1054048256', 'poolID': '00000002-0002-0002-0002-000000000145', 'device': 'disk', 'shared': 'false', 'propagateErrors': 'off', 'optional': 'false'} (code=1)
Thread-1789::DEBUG::2015-02-25 20:10:18,073::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2891::DEBUG::2015-02-25 20:10:18,336::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1472::DEBUG::2015-02-25 20:10:18,666::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1219::DEBUG::2015-02-25 20:10:18,667::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-929::DEBUG::2015-02-25 20:10:18,708::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-66::DEBUG::2015-02-25 20:10:18,825::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1399::DEBUG::2015-02-25 20:10:18,948::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-9472::DEBUG::2015-02-25 20:10:19,097::BindingXMLRPC::1133::vds::(wrapper) client [43.252.177.2]::call vmGetStats with ('93536f77-d1d8-4bb9-a7b9-ba20da66579f',) {}
Thread-9472::DEBUG::2015-02-25 20:10:19,097::BindingXMLRPC::1140::vds::(wrapper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 'statsList': [{'status': 'Down', 'exitMessage': "Bad volume specification {'index': 0, 'iface': 'virtio', 'type': 'disk', 'format': 'raw', 'bootOrder': '1', 'address': {'slot': '0x07', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'volumeID': '60c73bf0-d190-420b-917c-04aa00e52f10', 'apparentsize': '1073741824', 'imageID': '8ca66096-bd47-460d-9e09-2966e45b471b', 'specParams': {}, 'readonly': 'false', 'domainID': 'e732a82f-bae9-4368-8b98-dedc1c3814de', 'reqsize': '0', 'deviceId': '8ca66096-bd47-460d-9e09-2966e45b471b', 'truesize': '1054048256', 'poolID': '00000002-0002-0002-0002-000000000145', 'device': 'disk', 'shared': 'false', 'propagateErrors': 'off', 'optional': 'false'}", 'vmId': '93536f77-d1d8-4bb9-a7b9-ba20da66579f', 'exitReason': 1, 'timeOffset': '28800', 'exitCode': 1}]}
Thread-9472::DEBUG::2015-02-25 20:10:19,120::BindingXMLRPC::1133::vds::(wrapper) client [43.252.177.2]::call vmDestroy with ('93536f77-d1d8-4bb9-a7b9-ba20da66579f',) {}
Thread-9472::INFO::2015-02-25 20:10:19,121::API::332::vds::(destroy) vmContainerLock acquired by vm 93536f77-d1d8-4bb9-a7b9-ba20da66579f
Thread-9472::DEBUG::2015-02-25 20:10:19,121::vm::5026::vm.Vm::(destroy) vmId=`93536f77-d1d8-4bb9-a7b9-ba20da66579f`::destroy Called
Thread-9472::INFO::2015-02-25 20:10:19,121::vm::4952::vm.Vm::(releaseVm) vmId=`93536f77-d1d8-4bb9-a7b9-ba20da66579f`::Release VM resources
Thread-9472::WARNING::2015-02-25 20:10:19,122::vm::1953::vm.Vm::(_set_lastStatus) vmId=`93536f77-d1d8-4bb9-a7b9-ba20da66579f`::trying to set state to Powering down when already Down
Thread-9472::WARNING::2015-02-25 20:10:19,122::utils::129::root::(rmFile) File: /var/lib/libvirt/qemu/channels/93536f77-d1d8-4bb9-a7b9-ba20da66579f.com.redhat.rhevm.vdsm already removed
Thread-9472::WARNING::2015-02-25 20:10:19,122::utils::129::root::(rmFile) File: /var/lib/libvirt/qemu/channels/93536f77-d1d8-4bb9-a7b9-ba20da66579f.org.qemu.guest_agent.0 already removed
Thread-9472::DEBUG::2015-02-25 20:10:19,123::task::595::Storage.TaskManager.Task::(_updateState) Task=`529ec229-3447-4938-a0e8-9eaa873c4606`::moving from state init -> state preparing
Thread-9472::INFO::2015-02-25 20:10:19,123::logUtils::44::dispatcher::(wrapper) Run and protect: inappropriateDevices(thiefId='93536f77-d1d8-4bb9-a7b9-ba20da66579f')
Thread-9472::INFO::2015-02-25 20:10:19,125::logUtils::47::dispatcher::(wrapper) Run and protect: inappropriateDevices, Return response: None
Thread-9472::DEBUG::2015-02-25 20:10:19,125::task::1191::Storage.TaskManager.Task::(prepare) Task=`529ec229-3447-4938-a0e8-9eaa873c4606`::finished: None
Thread-9472::DEBUG::2015-02-25 20:10:19,126::task::595::Storage.TaskManager.Task::(_updateState) Task=`529ec229-3447-4938-a0e8-9eaa873c4606`::moving from state preparing -> state finished
Thread-9472::DEBUG::2015-02-25 20:10:19,126::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-9472::DEBUG::2015-02-25 20:10:19,126::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-9472::DEBUG::2015-02-25 20:10:19,126::task::993::Storage.TaskManager.Task::(_decref) Task=`529ec229-3447-4938-a0e8-9eaa873c4606`::ref 0 aborting False
Thread-9472::DEBUG::2015-02-25 20:10:19,127::vm::5020::vm.Vm::(deleteVm) vmId=`93536f77-d1d8-4bb9-a7b9-ba20da66579f`::Total desktops after destroy of 93536f77-d1d8-4bb9-a7b9-ba20da66579f is 77
Thread-9472::DEBUG::2015-02-25 20:10:19,128::BindingXMLRPC::1140::vds::(wrapper) return vmDestroy with {'status': {'message': 'Machine destroyed', 'code': 0}}
Thread-630::DEBUG::2015-02-25 20:10:19,784::task::595::Storage.TaskManager.Task::(_updateState) Task=`589aab35-0d4d-4ad5-9ef0-99dbc498a523`::moving from state init -> state preparing
Thread-4595::DEBUG::2015-02-25 20:10:19,788::task::595::Storage.TaskManager.Task::(_updateState) Task=`c10fa011-749a-459e-8430-d609c8715878`::moving from state init -> state preparing
Thread-630::INFO::2015-02-25 20:10:19,870::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='adcce117-7473-4571-b7d9-c8bef7faa6d2', volUUID='e2edbf15-ce1f-41e6-b1e6-3b3208114681', options=None)
Thread-4595::INFO::2015-02-25 20:10:19,884::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='0fa16768-ed68-4aaa-9e88-defb0ae4341f', volUUID='a2978843-fce9-421f-b196-77861659d839', options=None)
Thread-185::DEBUG::2015-02-25 20:10:20,081::task::595::Storage.TaskManager.Task::(_updateState) Task=`1431d327-8e09-409c-bc42-ac17d6f3579e`::moving from state init -> state preparing
Thread-1713::DEBUG::2015-02-25 20:10:20,099::task::595::Storage.TaskManager.Task::(_updateState) Task=`15485caf-3df0-4775-9ae0-32cd3262a0f3`::moving from state init -> state preparing
Thread-1084::DEBUG::2015-02-25 20:10:20,099::task::595::Storage.TaskManager.Task::(_updateState) Task=`ba80d4be-88ec-4f60-97ce-8eff5c4a43d5`::moving from state init -> state preparing
Thread-727::DEBUG::2015-02-25 20:10:20,088::task::595::Storage.TaskManager.Task::(_updateState) Task=`5861d8ff-219a-4c6c-bdab-a0e84bd582b2`::moving from state init -> state preparing
Thread-2706::DEBUG::2015-02-25 20:10:20,102::task::595::Storage.TaskManager.Task::(_updateState) Task=`85342ba4-8ba5-4769-a905-a3b1827c4e1a`::moving from state init -> state preparing
Thread-1521::DEBUG::2015-02-25 20:10:20,094::task::595::Storage.TaskManager.Task::(_updateState) Task=`6888e062-5b42-4807-b188-d71924f75c86`::moving from state init -> state preparing
Thread-2456::DEBUG::2015-02-25 20:10:20,095::task::595::Storage.TaskManager.Task::(_updateState) Task=`667a9b99-2222-4b0b-ba75-31265d53d74c`::moving from state init -> state preparing
Thread-3002::DEBUG::2015-02-25 20:10:20,102::task::595::Storage.TaskManager.Task::(_updateState) Task=`1550decf-d95f-4f5e-932c-73b519365837`::moving from state init -> state preparing
Thread-2016::DEBUG::2015-02-25 20:10:20,106::task::595::Storage.TaskManager.Task::(_updateState) Task=`5fb96285-1f25-4bb4-8ccf-5dfe7b8815e8`::moving from state init -> state preparing
Thread-576::DEBUG::2015-02-25 20:10:20,140::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1894::DEBUG::2015-02-25 20:10:20,142::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-185::INFO::2015-02-25 20:10:20,174::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='03a729fb-90d5-4e7b-bc69-ba2fc77759de', volUUID='6a8622cd-3404-43ce-8daa-e74910c58e95', options=None)
Thread-1713::INFO::2015-02-25 20:10:20,196::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='30949685-e0ec-4a70-9a26-994cd61dd0e1', volUUID='b092db9b-1100-44e2-b373-4c98bb0fa839', options=None)
Thread-1084::INFO::2015-02-25 20:10:20,218::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='0e0a0a2b-830e-4703-93c0-263e2bc233bc', volUUID='2503b59b-3959-431c-a58d-4723261932a9', options=None)
Thread-630::INFO::2015-02-25 20:10:20,222::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1445519360', 'apparentsize': '64424509440'}
Thread-727::INFO::2015-02-25 20:10:20,242::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='5df902f9-1d61-445e-ab83-00523ecbbe72', volUUID='897095a5-ff22-41c9-a394-59122d438a19', options=None)
Thread-2706::INFO::2015-02-25 20:10:20,257::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='3d338434-ff53-4b51-ab66-7d72dc691cda', volUUID='08954036-38d7-4a52-a923-881adc08dbe6', options=None)
Thread-1521::INFO::2015-02-25 20:10:20,285::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='058490dd-ffdb-42fb-8fae-dee1f160198f', volUUID='d2099de0-0978-4c89-8dc5-af568ab50db5', options=None)
Thread-4595::INFO::2015-02-25 20:10:20,287::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '2540642304', 'apparentsize': '64424509440'}
Thread-2456::INFO::2015-02-25 20:10:20,295::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='ee2aab3d-37be-44cf-b1e3-420ef96ca719', volUUID='47a1e58f-c5f0-4818-92ad-2b93d869d67e', options=None)
Thread-3002::INFO::2015-02-25 20:10:20,316::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='699422bd-0120-4da1-b6cc-b7e1349af0a9', volUUID='ea51325e-83cf-4abe-be8d-104c47ba9503', options=None)
Thread-2016::INFO::2015-02-25 20:10:20,332::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='fc8337a2-12c3-48b7-b2fc-aedb275aa60a', volUUID='a6cc4716-3989-451c-a1d3-1e84ad1f4ef3', options=None)
Thread-630::DEBUG::2015-02-25 20:10:20,426::task::1191::Storage.TaskManager.Task::(prepare) Task=`589aab35-0d4d-4ad5-9ef0-99dbc498a523`::finished: {'truesize': '1445519360', 'apparentsize': '64424509440'}
Thread-1661::DEBUG::2015-02-25 20:10:20,435::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-4595::DEBUG::2015-02-25 20:10:20,454::task::1191::Storage.TaskManager.Task::(prepare) Task=`c10fa011-749a-459e-8430-d609c8715878`::finished: {'truesize': '2540642304', 'apparentsize': '64424509440'}
Thread-630::DEBUG::2015-02-25 20:10:20,473::task::595::Storage.TaskManager.Task::(_updateState) Task=`589aab35-0d4d-4ad5-9ef0-99dbc498a523`::moving from state preparing -> state finished
Thread-4595::DEBUG::2015-02-25 20:10:20,487::task::595::Storage.TaskManager.Task::(_updateState) Task=`c10fa011-749a-459e-8430-d609c8715878`::moving from state preparing -> state finished
Thread-630::DEBUG::2015-02-25 20:10:20,492::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-4595::DEBUG::2015-02-25 20:10:20,504::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-630::DEBUG::2015-02-25 20:10:20,510::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-4595::DEBUG::2015-02-25 20:10:20,521::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-630::DEBUG::2015-02-25 20:10:20,529::task::993::Storage.TaskManager.Task::(_decref) Task=`589aab35-0d4d-4ad5-9ef0-99dbc498a523`::ref 0 aborting False
Thread-4595::DEBUG::2015-02-25 20:10:20,538::task::993::Storage.TaskManager.Task::(_decref) Task=`c10fa011-749a-459e-8430-d609c8715878`::ref 0 aborting False
Thread-185::INFO::2015-02-25 20:10:20,562::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1060478976', 'apparentsize': '21474836480'}
Thread-185::DEBUG::2015-02-25 20:10:20,571::task::1191::Storage.TaskManager.Task::(prepare) Task=`1431d327-8e09-409c-bc42-ac17d6f3579e`::finished: {'truesize': '1060478976', 'apparentsize': '21474836480'}
Thread-185::DEBUG::2015-02-25 20:10:20,579::task::595::Storage.TaskManager.Task::(_updateState) Task=`1431d327-8e09-409c-bc42-ac17d6f3579e`::moving from state preparing -> state finished
Thread-185::DEBUG::2015-02-25 20:10:20,587::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-185::DEBUG::2015-02-25 20:10:20,594::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1713::INFO::2015-02-25 20:10:20,598::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1628090368', 'apparentsize': '42949672960'}
Thread-185::DEBUG::2015-02-25 20:10:20,603::task::993::Storage.TaskManager.Task::(_decref) Task=`1431d327-8e09-409c-bc42-ac17d6f3579e`::ref 0 aborting False
Thread-1084::INFO::2015-02-25 20:10:20,608::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1940242432', 'apparentsize': '21474836480'}
Thread-1713::DEBUG::2015-02-25 20:10:20,608::task::1191::Storage.TaskManager.Task::(prepare) Task=`15485caf-3df0-4775-9ae0-32cd3262a0f3`::finished: {'truesize': '1628090368', 'apparentsize': '42949672960'}
Thread-1713::DEBUG::2015-02-25 20:10:20,621::task::595::Storage.TaskManager.Task::(_updateState) Task=`15485caf-3df0-4775-9ae0-32cd3262a0f3`::moving from state preparing -> state finished
Thread-1084::DEBUG::2015-02-25 20:10:20,621::task::1191::Storage.TaskManager.Task::(prepare) Task=`ba80d4be-88ec-4f60-97ce-8eff5c4a43d5`::finished: {'truesize': '1940242432', 'apparentsize': '21474836480'}
Thread-727::INFO::2015-02-25 20:10:20,624::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1782235136', 'apparentsize': '21474836480'}
Thread-1713::DEBUG::2015-02-25 20:10:20,630::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1084::DEBUG::2015-02-25 20:10:20,634::task::595::Storage.TaskManager.Task::(_updateState) Task=`ba80d4be-88ec-4f60-97ce-8eff5c4a43d5`::moving from state preparing -> state finished
Thread-2706::INFO::2015-02-25 20:10:20,637::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1787797504', 'apparentsize': '21474836480'}
Thread-1713::DEBUG::2015-02-25 20:10:20,640::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-727::DEBUG::2015-02-25 20:10:20,642::task::1191::Storage.TaskManager.Task::(prepare) Task=`5861d8ff-219a-4c6c-bdab-a0e84bd582b2`::finished: {'truesize': '1782235136', 'apparentsize': '21474836480'}
Thread-1084::DEBUG::2015-02-25 20:10:20,644::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1521::INFO::2015-02-25 20:10:20,653::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '5755490304', 'apparentsize': '21474836480'}
Thread-2706::DEBUG::2015-02-25 20:10:20,655::task::1191::Storage.TaskManager.Task::(prepare) Task=`85342ba4-8ba5-4769-a905-a3b1827c4e1a`::finished: {'truesize': '1787797504', 'apparentsize': '21474836480'}
Thread-1713::DEBUG::2015-02-25 20:10:20,658::task::993::Storage.TaskManager.Task::(_decref) Task=`15485caf-3df0-4775-9ae0-32cd3262a0f3`::ref 0 aborting False
Thread-727::DEBUG::2015-02-25 20:10:20,660::task::595::Storage.TaskManager.Task::(_updateState) Task=`5861d8ff-219a-4c6c-bdab-a0e84bd582b2`::moving from state preparing -> state finished
Thread-1084::DEBUG::2015-02-25 20:10:20,663::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-2456::INFO::2015-02-25 20:10:20,669::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1868374016', 'apparentsize': '21474836480'}
Thread-2706::DEBUG::2015-02-25 20:10:20,673::task::595::Storage.TaskManager.Task::(_updateState) Task=`85342ba4-8ba5-4769-a905-a3b1827c4e1a`::moving from state preparing -> state finished
Thread-1521::DEBUG::2015-02-25 20:10:20,674::task::1191::Storage.TaskManager.Task::(prepare) Task=`6888e062-5b42-4807-b188-d71924f75c86`::finished: {'truesize': '5755490304', 'apparentsize': '21474836480'}
Thread-727::DEBUG::2015-02-25 20:10:20,682::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-3002::INFO::2015-02-25 20:10:20,687::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1431318528', 'apparentsize': '64424509440'}
Thread-1084::DEBUG::2015-02-25 20:10:20,693::task::993::Storage.TaskManager.Task::(_decref) Task=`ba80d4be-88ec-4f60-97ce-8eff5c4a43d5`::ref 0 aborting False
Thread-2706::DEBUG::2015-02-25 20:10:20,700::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-2456::DEBUG::2015-02-25 20:10:20,702::task::1191::Storage.TaskManager.Task::(prepare) Task=`667a9b99-2222-4b0b-ba75-31265d53d74c`::finished: {'truesize': '1868374016', 'apparentsize': '21474836480'}
Thread-1521::DEBUG::2015-02-25 20:10:20,706::task::595::Storage.TaskManager.Task::(_updateState) Task=`6888e062-5b42-4807-b188-d71924f75c86`::moving from state preparing -> state finished
Thread-2016::INFO::2015-02-25 20:10:20,709::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '3833016320', 'apparentsize': '21474836480'}
Thread-727::DEBUG::2015-02-25 20:10:20,709::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-3002::DEBUG::2015-02-25 20:10:20,716::task::1191::Storage.TaskManager.Task::(prepare) Task=`1550decf-d95f-4f5e-932c-73b519365837`::finished: {'truesize': '1431318528', 'apparentsize': '64424509440'}
Thread-2706::DEBUG::2015-02-25 20:10:20,718::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-2456::DEBUG::2015-02-25 20:10:20,721::task::595::Storage.TaskManager.Task::(_updateState) Task=`667a9b99-2222-4b0b-ba75-31265d53d74c`::moving from state preparing -> state finished
Thread-1521::DEBUG::2015-02-25 20:10:20,723::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-2016::DEBUG::2015-02-25 20:10:20,731::task::1191::Storage.TaskManager.Task::(prepare) Task=`5fb96285-1f25-4bb4-8ccf-5dfe7b8815e8`::finished: {'truesize': '3833016320', 'apparentsize': '21474836480'}
Thread-2456::DEBUG::2015-02-25 20:10:20,742::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-727::DEBUG::2015-02-25 20:10:20,734::task::993::Storage.TaskManager.Task::(_decref) Task=`5861d8ff-219a-4c6c-bdab-a0e84bd582b2`::ref 0 aborting False
Thread-3002::DEBUG::2015-02-25 20:10:20,734::task::595::Storage.TaskManager.Task::(_updateState) Task=`1550decf-d95f-4f5e-932c-73b519365837`::moving from state preparing -> state finished
Thread-2706::DEBUG::2015-02-25 20:10:20,741::task::993::Storage.TaskManager.Task::(_decref) Task=`85342ba4-8ba5-4769-a905-a3b1827c4e1a`::ref 0 aborting False
Thread-630::DEBUG::2015-02-25 20:10:20,733::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-4595::DEBUG::2015-02-25 20:10:20,745::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1521::DEBUG::2015-02-25 20:10:20,745::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-386::DEBUG::2015-02-25 20:10:20,747::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2016::DEBUG::2015-02-25 20:10:20,748::task::595::Storage.TaskManager.Task::(_updateState) Task=`5fb96285-1f25-4bb4-8ccf-5dfe7b8815e8`::moving from state preparing -> state finished
Thread-1471::DEBUG::2015-02-25 20:10:20,751::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2456::DEBUG::2015-02-25 20:10:20,752::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-55::DEBUG::2015-02-25 20:10:20,753::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-3002::DEBUG::2015-02-25 20:10:20,758::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1332::DEBUG::2015-02-25 20:10:20,760::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1521::DEBUG::2015-02-25 20:10:20,771::task::993::Storage.TaskManager.Task::(_decref) Task=`6888e062-5b42-4807-b188-d71924f75c86`::ref 0 aborting False
Thread-2016::DEBUG::2015-02-25 20:10:20,773::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-481::DEBUG::2015-02-25 20:10:20,781::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2456::DEBUG::2015-02-25 20:10:20,782::task::993::Storage.TaskManager.Task::(_decref) Task=`667a9b99-2222-4b0b-ba75-31265d53d74c`::ref 0 aborting False
Thread-3002::DEBUG::2015-02-25 20:10:20,786::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-2016::DEBUG::2015-02-25 20:10:20,794::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1843::DEBUG::2015-02-25 20:10:20,796::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-3002::DEBUG::2015-02-25 20:10:20,803::task::993::Storage.TaskManager.Task::(_decref) Task=`1550decf-d95f-4f5e-932c-73b519365837`::ref 0 aborting False
Thread-2016::DEBUG::2015-02-25 20:10:20,806::task::993::Storage.TaskManager.Task::(_decref) Task=`5fb96285-1f25-4bb4-8ccf-5dfe7b8815e8`::ref 0 aborting False
Thread-505::DEBUG::2015-02-25 20:10:20,814::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-185::DEBUG::2015-02-25 20:10:20,835::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1754::DEBUG::2015-02-25 20:10:20,937::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-422::DEBUG::2015-02-25 20:10:20,944::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1713::DEBUG::2015-02-25 20:10:20,959::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1084::DEBUG::2015-02-25 20:10:20,991::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-727::DEBUG::2015-02-25 20:10:21,008::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2706::DEBUG::2015-02-25 20:10:21,017::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2456::DEBUG::2015-02-25 20:10:21,027::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1521::DEBUG::2015-02-25 20:10:21,028::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-3002::DEBUG::2015-02-25 20:10:21,042::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2016::DEBUG::2015-02-25 20:10:21,050::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-25::DEBUG::2015-02-25 20:10:21,052::fileSD::261::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/117.18.79.72:_36Cloud__OStemplates/05be2753-83ed-4e6e-b236-4b342939a5fb/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-25::DEBUG::2015-02-25 20:10:21,306::fileSD::261::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n345 bytes (345 B) copied, 0.00074813 s, 461 kB/s\n'; <rc> = 0
Thread-91::DEBUG::2015-02-25 20:10:22,073::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-540::DEBUG::2015-02-25 20:10:22,091::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-3312::DEBUG::2015-02-25 20:10:22,099::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-9472::DEBUG::2015-02-25 20:10:22,353::task::595::Storage.TaskManager.Task::(_updateState) Task=`8922ca25-ef19-420f-b0e5-d4f1d7aa3303`::moving from state init -> state preparing
Thread-9472::INFO::2015-02-25 20:10:22,353::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-9472::INFO::2015-02-25 20:10:22,354::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'e732a82f-bae9-4368-8b98-dedc1c3814de': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000905785', 'lastCheck': '6.7', 'valid': True}, '05be2753-83ed-4e6e-b236-4b342939a5fb': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.00074813', 'lastCheck': '1.0', 'valid': True}}
Thread-9472::DEBUG::2015-02-25 20:10:22,354::task::1191::Storage.TaskManager.Task::(prepare) Task=`8922ca25-ef19-420f-b0e5-d4f1d7aa3303`::finished: {'e732a82f-bae9-4368-8b98-dedc1c3814de': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000905785', 'lastCheck': '6.7', 'valid': True}, '05be2753-83ed-4e6e-b236-4b342939a5fb': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.00074813', 'lastCheck': '1.0', 'valid': True}}
Thread-9472::DEBUG::2015-02-25 20:10:22,354::task::595::Storage.TaskManager.Task::(_updateState) Task=`8922ca25-ef19-420f-b0e5-d4f1d7aa3303`::moving from state preparing -> state finished
Thread-9472::DEBUG::2015-02-25 20:10:22,355::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-9472::DEBUG::2015-02-25 20:10:22,355::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-9472::DEBUG::2015-02-25 20:10:22,355::task::993::Storage.TaskManager.Task::(_decref) Task=`8922ca25-ef19-420f-b0e5-d4f1d7aa3303`::ref 0 aborting False
Thread-2687::DEBUG::2015-02-25 20:10:22,831::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-65::DEBUG::2015-02-25 20:10:22,835::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1322::DEBUG::2015-02-25 20:10:23,335::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-467::DEBUG::2015-02-25 20:10:23,371::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2517::DEBUG::2015-02-25 20:10:23,412::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2541::DEBUG::2015-02-25 20:10:23,461::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2760::DEBUG::2015-02-25 20:10:23,466::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1259::DEBUG::2015-02-25 20:10:24,402::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-180::DEBUG::2015-02-25 20:10:24,682::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1187::DEBUG::2015-02-25 20:10:24,746::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-57::DEBUG::2015-02-25 20:10:24,770::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-4731::DEBUG::2015-02-25 20:10:24,805::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1059::DEBUG::2015-02-25 20:10:24,805::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-395::DEBUG::2015-02-25 20:10:24,929::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-138::DEBUG::2015-02-25 20:10:24,932::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1417::DEBUG::2015-02-25 20:10:24,960::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-4645::DEBUG::2015-02-25 20:10:24,963::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-238::DEBUG::2015-02-25 20:10:25,213::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1604::DEBUG::2015-02-25 20:10:25,321::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1963::DEBUG::2015-02-25 20:10:25,397::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1438::DEBUG::2015-02-25 20:10:25,417::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-199::DEBUG::2015-02-25 20:10:25,420::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1576::DEBUG::2015-02-25 20:10:25,754::task::595::Storage.TaskManager.Task::(_updateState) Task=`bb912197-7700-4cbf-8433-183742750077`::moving from state init -> state preparing
Thread-2146::DEBUG::2015-02-25 20:10:25,759::task::595::Storage.TaskManager.Task::(_updateState) Task=`a7c906a1-37b7-4af7-af22-d3e3f44df5dc`::moving from state init -> state preparing
Thread-126::DEBUG::2015-02-25 20:10:25,761::task::595::Storage.TaskManager.Task::(_updateState) Task=`c0b42128-397a-44fb-be26-840d17e64acf`::moving from state init -> state preparing
Thread-24::DEBUG::2015-02-25 20:10:25,773::fileSD::261::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/glusterSD/10.10.0.14:_ds01/e732a82f-bae9-4368-8b98-dedc1c3814de/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-1576::INFO::2015-02-25 20:10:25,787::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='0e3c961c-186f-4c5d-8fd2-8c7b10f11965', volUUID='492a8cc8-ae42-4e9a-9dd8-415fb881dcb8', options=None)
Thread-2146::INFO::2015-02-25 20:10:25,792::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='77de8f34-9f4f-4166-ba39-28c7b8d95fe5', volUUID='4fa0b306-7da1-425a-81eb-ffc4e6e7e61a', options=None)
Thread-126::INFO::2015-02-25 20:10:25,796::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='8269ef3a-f0bb-430b-bc44-462ce3d7eb37', volUUID='9427c5a5-951e-41e4-b537-b151d633e53a', options=None)
Thread-24::DEBUG::2015-02-25 20:10:26,066::fileSD::261::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n457 bytes (457 B) copied, 0.000578947 s, 789 kB/s\n'; <rc> = 0
Thread-3013::DEBUG::2015-02-25 20:10:26,100::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1576::INFO::2015-02-25 20:10:26,116::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '2751123456', 'apparentsize': '21474836480'}
Thread-2146::INFO::2015-02-25 20:10:26,128::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1866563584', 'apparentsize': '21474836480'}
Thread-1576::DEBUG::2015-02-25 20:10:26,129::task::1191::Storage.TaskManager.Task::(prepare) Task=`bb912197-7700-4cbf-8433-183742750077`::finished: {'truesize': '2751123456', 'apparentsize': '21474836480'}
Thread-192::DEBUG::2015-02-25 20:10:26,137::task::595::Storage.TaskManager.Task::(_updateState) Task=`7fc2510a-4bed-4efe-befb-8bd989b2c257`::moving from state init -> state preparing
Thread-126::INFO::2015-02-25 20:10:26,139::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1309061120', 'apparentsize': '21474836480'}
Thread-733::DEBUG::2015-02-25 20:10:26,139::task::595::Storage.TaskManager.Task::(_updateState) Task=`e849675c-c538-4f95-969a-ff9170b794ca`::moving from state init -> state preparing
Thread-1576::DEBUG::2015-02-25 20:10:26,141::task::595::Storage.TaskManager.Task::(_updateState) Task=`bb912197-7700-4cbf-8433-183742750077`::moving from state preparing -> state finished
Thread-2146::DEBUG::2015-02-25 20:10:26,141::task::1191::Storage.TaskManager.Task::(prepare) Task=`a7c906a1-37b7-4af7-af22-d3e3f44df5dc`::finished: {'truesize': '1866563584', 'apparentsize': '21474836480'}
Thread-192::INFO::2015-02-25 20:10:26,150::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='abd5ce70-1083-4126-8582-517e4dcae9ee', volUUID='90b8bb3f-64bf-4419-81ec-f1733e13e6c9', options=None)
Thread-126::DEBUG::2015-02-25 20:10:26,154::task::1191::Storage.TaskManager.Task::(prepare) Task=`c0b42128-397a-44fb-be26-840d17e64acf`::finished: {'truesize': '1309061120', 'apparentsize': '21474836480'}
Thread-1576::DEBUG::2015-02-25 20:10:26,156::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-733::INFO::2015-02-25 20:10:26,157::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='5db1fcf5-3c12-4567-996a-afa755026e8b', volUUID='2eb87b6f-8e27-4cbc-9bf3-4738a481f70c', options=None)
Thread-2146::DEBUG::2015-02-25 20:10:26,160::task::595::Storage.TaskManager.Task::(_updateState) Task=`a7c906a1-37b7-4af7-af22-d3e3f44df5dc`::moving from state preparing -> state finished
Thread-126::DEBUG::2015-02-25 20:10:26,167::task::595::Storage.TaskManager.Task::(_updateState) Task=`c0b42128-397a-44fb-be26-840d17e64acf`::moving from state preparing -> state finished
Thread-1576::DEBUG::2015-02-25 20:10:26,169::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-2146::DEBUG::2015-02-25 20:10:26,177::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-126::DEBUG::2015-02-25 20:10:26,181::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1576::DEBUG::2015-02-25 20:10:26,185::task::993::Storage.TaskManager.Task::(_decref) Task=`bb912197-7700-4cbf-8433-183742750077`::ref 0 aborting False
Thread-2146::DEBUG::2015-02-25 20:10:26,185::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-126::DEBUG::2015-02-25 20:10:26,189::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-2146::DEBUG::2015-02-25 20:10:26,200::task::993::Storage.TaskManager.Task::(_decref) Task=`a7c906a1-37b7-4af7-af22-d3e3f44df5dc`::ref 0 aborting False
Thread-126::DEBUG::2015-02-25 20:10:26,203::task::993::Storage.TaskManager.Task::(_decref) Task=`c0b42128-397a-44fb-be26-840d17e64acf`::ref 0 aborting False
Thread-192::INFO::2015-02-25 20:10:26,223::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1061470208', 'apparentsize': '21474836480'}
Thread-192::DEBUG::2015-02-25 20:10:26,233::task::1191::Storage.TaskManager.Task::(prepare) Task=`7fc2510a-4bed-4efe-befb-8bd989b2c257`::finished: {'truesize': '1061470208', 'apparentsize': '21474836480'}
Thread-733::INFO::2015-02-25 20:10:26,233::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '3779055616', 'apparentsize': '42949672960'}
Thread-192::DEBUG::2015-02-25 20:10:26,241::task::595::Storage.TaskManager.Task::(_updateState) Task=`7fc2510a-4bed-4efe-befb-8bd989b2c257`::moving from state preparing -> state finished
Thread-733::DEBUG::2015-02-25 20:10:26,245::task::1191::Storage.TaskManager.Task::(prepare) Task=`e849675c-c538-4f95-969a-ff9170b794ca`::finished: {'truesize': '3779055616', 'apparentsize': '42949672960'}
Thread-192::DEBUG::2015-02-25 20:10:26,249::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-733::DEBUG::2015-02-25 20:10:26,254::task::595::Storage.TaskManager.Task::(_updateState) Task=`e849675c-c538-4f95-969a-ff9170b794ca`::moving from state preparing -> state finished
Thread-192::DEBUG::2015-02-25 20:10:26,256::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-733::DEBUG::2015-02-25 20:10:26,261::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-192::DEBUG::2015-02-25 20:10:26,266::task::993::Storage.TaskManager.Task::(_decref) Task=`7fc2510a-4bed-4efe-befb-8bd989b2c257`::ref 0 aborting False
Thread-733::DEBUG::2015-02-25 20:10:26,269::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-733::DEBUG::2015-02-25 20:10:26,278::task::993::Storage.TaskManager.Task::(_decref) Task=`e849675c-c538-4f95-969a-ff9170b794ca`::ref 0 aborting False
Thread-1576::DEBUG::2015-02-25 20:10:26,354::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-126::DEBUG::2015-02-25 20:10:26,368::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2146::DEBUG::2015-02-25 20:10:26,376::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-192::DEBUG::2015-02-25 20:10:26,432::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-733::DEBUG::2015-02-25 20:10:26,440::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2371::DEBUG::2015-02-25 20:10:26,737::task::595::Storage.TaskManager.Task::(_updateState) Task=`507d0eec-6705-4774-aad6-6ed63b363fca`::moving from state init -> state preparing
Thread-2066::DEBUG::2015-02-25 20:10:26,738::task::595::Storage.TaskManager.Task::(_updateState) Task=`9e526b92-08fc-4b41-9171-b27c55b3aabe`::moving from state init -> state preparing
Thread-2371::INFO::2015-02-25 20:10:26,774::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='c8aac4fe-6775-49bb-9235-3a49078f4214', volUUID='c2f8339c-ea41-4f8e-9d9f-0923bcedb21c', options=None)
Thread-2066::INFO::2015-02-25 20:10:26,783::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='c4a03c79-da16-483c-bc3b-d8efa833f510', volUUID='47a8437b-b460-4f79-ae23-34220f6f2e2e', options=None)
Thread-2371::INFO::2015-02-25 20:10:26,882::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1703649280', 'apparentsize': '21474836480'}
Thread-2066::INFO::2015-02-25 20:10:26,894::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '3571089408', 'apparentsize': '21474836480'}
Thread-2371::DEBUG::2015-02-25 20:10:26,894::task::1191::Storage.TaskManager.Task::(prepare) Task=`507d0eec-6705-4774-aad6-6ed63b363fca`::finished: {'truesize': '1703649280', 'apparentsize': '21474836480'}
Thread-2066::DEBUG::2015-02-25 20:10:26,897::task::1191::Storage.TaskManager.Task::(prepare) Task=`9e526b92-08fc-4b41-9171-b27c55b3aabe`::finished: {'truesize': '3571089408', 'apparentsize': '21474836480'}
Thread-2371::DEBUG::2015-02-25 20:10:26,897::task::595::Storage.TaskManager.Task::(_updateState) Task=`507d0eec-6705-4774-aad6-6ed63b363fca`::moving from state preparing -> state finished
Thread-2066::DEBUG::2015-02-25 20:10:26,898::task::595::Storage.TaskManager.Task::(_updateState) Task=`9e526b92-08fc-4b41-9171-b27c55b3aabe`::moving from state preparing -> state finished
Thread-2371::DEBUG::2015-02-25 20:10:26,899::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-2066::DEBUG::2015-02-25 20:10:26,900::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-2371::DEBUG::2015-02-25 20:10:26,900::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-2066::DEBUG::2015-02-25 20:10:26,901::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-2371::DEBUG::2015-02-25 20:10:26,902::task::993::Storage.TaskManager.Task::(_decref) Task=`507d0eec-6705-4774-aad6-6ed63b363fca`::ref 0 aborting False
Thread-2066::DEBUG::2015-02-25 20:10:26,903::task::993::Storage.TaskManager.Task::(_decref) Task=`9e526b92-08fc-4b41-9171-b27c55b3aabe`::ref 0 aborting False
Thread-2066::DEBUG::2015-02-25 20:10:27,045::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2371::DEBUG::2015-02-25 20:10:27,046::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-56::DEBUG::2015-02-25 20:10:27,084::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-125::DEBUG::2015-02-25 20:10:27,089::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-742::DEBUG::2015-02-25 20:10:28,041::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2150::DEBUG::2015-02-25 20:10:28,381::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2781::DEBUG::2015-02-25 20:10:28,382::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-590::DEBUG::2015-02-25 20:10:29,093::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1753::DEBUG::2015-02-25 20:10:29,096::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-4574::DEBUG::2015-02-25 20:10:29,107::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-606::DEBUG::2015-02-25 20:10:31,162::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-25::DEBUG::2015-02-25 20:10:31,392::fileSD::261::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/117.18.79.72:_36Cloud__OStemplates/05be2753-83ed-4e6e-b236-4b342939a5fb/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-25::DEBUG::2015-02-25 20:10:31,635::fileSD::261::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n345 bytes (345 B) copied, 0.000944452 s, 365 kB/s\n'; <rc> = 0
Thread-627::DEBUG::2015-02-25 20:10:31,856::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-5186::DEBUG::2015-02-25 20:10:31,857::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-4437::DEBUG::2015-02-25 20:10:31,861::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-659::DEBUG::2015-02-25 20:10:32,663::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-379::DEBUG::2015-02-25 20:10:32,817::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1789::DEBUG::2015-02-25 20:10:33,176::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2891::DEBUG::2015-02-25 20:10:33,393::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
VM Channels Listener::DEBUG::2015-02-25 20:10:33,438::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 203.
Thread-1219::DEBUG::2015-02-25 20:10:33,763::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1472::DEBUG::2015-02-25 20:10:33,769::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-929::DEBUG::2015-02-25 20:10:33,812::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1399::DEBUG::2015-02-25 20:10:34,107::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-66::DEBUG::2015-02-25 20:10:34,123::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-576::DEBUG::2015-02-25 20:10:35,405::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1894::DEBUG::2015-02-25 20:10:35,417::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1661::DEBUG::2015-02-25 20:10:35,633::task::595::Storage.TaskManager.Task::(_updateState) Task=`9b04bd40-0c51-433e-a0f0-66d2ad1a7c02`::moving from state init -> state preparing
Thread-1661::INFO::2015-02-25 20:10:35,634::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='ec3802f3-0963-4cb5-b3cb-ebda2d6ee7e1', volUUID='ada9e758-7a65-409e-845b-6c9eb40f84fc', options=None)
Thread-1661::INFO::2015-02-25 20:10:35,662::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '2003734528', 'apparentsize': '21474836480'}
Thread-1661::DEBUG::2015-02-25 20:10:35,663::task::1191::Storage.TaskManager.Task::(prepare) Task=`9b04bd40-0c51-433e-a0f0-66d2ad1a7c02`::finished: {'truesize': '2003734528', 'apparentsize': '21474836480'}
Thread-1661::DEBUG::2015-02-25 20:10:35,666::task::595::Storage.TaskManager.Task::(_updateState) Task=`9b04bd40-0c51-433e-a0f0-66d2ad1a7c02`::moving from state preparing -> state finished
Thread-1661::DEBUG::2015-02-25 20:10:35,667::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1661::DEBUG::2015-02-25 20:10:35,668::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1661::DEBUG::2015-02-25 20:10:35,669::task::993::Storage.TaskManager.Task::(_decref) Task=`9b04bd40-0c51-433e-a0f0-66d2ad1a7c02`::ref 0 aborting False
Thread-386::DEBUG::2015-02-25 20:10:35,796::task::595::Storage.TaskManager.Task::(_updateState) Task=`dd92e901-eb42-47f8-a9b8-361a667f8505`::moving from state init -> state preparing
Thread-386::INFO::2015-02-25 20:10:35,796::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='a1b22e46-219d-447d-ab36-e3711c889bca', volUUID='2739f665-a4d5-498f-9caa-6589c42651c6', options=None)
Thread-1661::DEBUG::2015-02-25 20:10:35,797::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1471::DEBUG::2015-02-25 20:10:35,799::task::595::Storage.TaskManager.Task::(_updateState) Task=`dcbca6f1-ca63-498e-9d4a-20bd5aadcb32`::moving from state init -> state preparing
Thread-1471::INFO::2015-02-25 20:10:35,800::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='00598186-f35f-488f-8ee2-1fba5c4f780a', volUUID='e3d7e429-5333-4536-88cf-4768f463e436', options=None)
Thread-55::DEBUG::2015-02-25 20:10:35,802::task::595::Storage.TaskManager.Task::(_updateState) Task=`e5cf37eb-56aa-4edc-b2de-c796ae4d7ce0`::moving from state init -> state preparing
Thread-55::INFO::2015-02-25 20:10:35,802::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='f75b8ec4-2f9f-4882-97d3-03d776e7aa5e', volUUID='d5000eaf-de30-433f-a04d-ac127e0e3f00', options=None)
Thread-386::INFO::2015-02-25 20:10:35,824::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1385721856', 'apparentsize': '21474836480'}
Thread-386::DEBUG::2015-02-25 20:10:35,828::task::1191::Storage.TaskManager.Task::(prepare) Task=`dd92e901-eb42-47f8-a9b8-361a667f8505`::finished: {'truesize': '1385721856', 'apparentsize': '21474836480'}
Thread-1471::INFO::2015-02-25 20:10:35,830::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '2734686208', 'apparentsize': '21474836480'}
Thread-386::DEBUG::2015-02-25 20:10:35,832::task::595::Storage.TaskManager.Task::(_updateState) Task=`dd92e901-eb42-47f8-a9b8-361a667f8505`::moving from state preparing -> state finished
Thread-55::INFO::2015-02-25 20:10:35,835::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1800978432', 'apparentsize': '21474836480'}
Thread-1471::DEBUG::2015-02-25 20:10:35,837::task::1191::Storage.TaskManager.Task::(prepare) Task=`dcbca6f1-ca63-498e-9d4a-20bd5aadcb32`::finished: {'truesize': '2734686208', 'apparentsize': '21474836480'}
Thread-386::DEBUG::2015-02-25 20:10:35,838::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-55::DEBUG::2015-02-25 20:10:35,842::task::1191::Storage.TaskManager.Task::(prepare) Task=`e5cf37eb-56aa-4edc-b2de-c796ae4d7ce0`::finished: {'truesize': '1800978432', 'apparentsize': '21474836480'}
Thread-1471::DEBUG::2015-02-25 20:10:35,842::task::595::Storage.TaskManager.Task::(_updateState) Task=`dcbca6f1-ca63-498e-9d4a-20bd5aadcb32`::moving from state preparing -> state finished
Thread-386::DEBUG::2015-02-25 20:10:35,843::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-55::DEBUG::2015-02-25 20:10:35,846::task::595::Storage.TaskManager.Task::(_updateState) Task=`e5cf37eb-56aa-4edc-b2de-c796ae4d7ce0`::moving from state preparing -> state finished
Thread-1471::DEBUG::2015-02-25 20:10:35,847::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-386::DEBUG::2015-02-25 20:10:35,849::task::993::Storage.TaskManager.Task::(_decref) Task=`dd92e901-eb42-47f8-a9b8-361a667f8505`::ref 0 aborting False
Thread-55::DEBUG::2015-02-25 20:10:35,850::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-630::DEBUG::2015-02-25 20:10:35,852::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1471::DEBUG::2015-02-25 20:10:35,852::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-55::DEBUG::2015-02-25 20:10:35,855::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-4595::DEBUG::2015-02-25 20:10:35,858::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1471::DEBUG::2015-02-25 20:10:35,860::task::993::Storage.TaskManager.Task::(_decref) Task=`dcbca6f1-ca63-498e-9d4a-20bd5aadcb32`::ref 0 aborting False
Thread-55::DEBUG::2015-02-25 20:10:35,861::task::993::Storage.TaskManager.Task::(_decref) Task=`e5cf37eb-56aa-4edc-b2de-c796ae4d7ce0`::ref 0 aborting False
Thread-55::DEBUG::2015-02-25 20:10:35,974::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-185::DEBUG::2015-02-25 20:10:35,980::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-386::DEBUG::2015-02-25 20:10:35,996::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1471::DEBUG::2015-02-25 20:10:36,173::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-505::DEBUG::2015-02-25 20:10:36,210::task::595::Storage.TaskManager.Task::(_updateState) Task=`019c99ce-31e9-474a-ac97-5f401eef2772`::moving from state init -> state preparing
Thread-481::DEBUG::2015-02-25 20:10:36,222::task::595::Storage.TaskManager.Task::(_updateState) Task=`9f72da41-371a-4c53-ba47-f18b761b4fc9`::moving from state init -> state preparing
Thread-1332::DEBUG::2015-02-25 20:10:36,223::task::595::Storage.TaskManager.Task::(_updateState) Task=`912c7e66-9760-4a69-83d5-9027641c36c5`::moving from state init -> state preparing
Thread-1843::DEBUG::2015-02-25 20:10:36,220::task::595::Storage.TaskManager.Task::(_updateState) Task=`284c065f-8f8c-4df0-83cc-8c652dcb3b63`::moving from state init -> state preparing
Thread-1713::DEBUG::2015-02-25 20:10:36,229::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-505::INFO::2015-02-25 20:10:36,282::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='71ad4afe-feca-4da9-8d91-75647d68a2b1', volUUID='f1675ed0-eb21-4df3-9919-a757785eb917', options=None)
Thread-2456::DEBUG::2015-02-25 20:10:36,283::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-481::INFO::2015-02-25 20:10:36,294::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='c5f103d8-2ff4-4903-b3d6-356b8a482d93', volUUID='984ca697-7982-46fe-aa6c-f3e96e44889b', options=None)
Thread-1084::DEBUG::2015-02-25 20:10:36,295::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-727::DEBUG::2015-02-25 20:10:36,307::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1521::DEBUG::2015-02-25 20:10:36,312::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1332::INFO::2015-02-25 20:10:36,315::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='8665686e-fd6f-4ef2-9f60-04de97b64087', volUUID='1b889093-2b0b-4888-b2cb-97cefe0783e3', options=None)
Thread-3002::DEBUG::2015-02-25 20:10:36,434::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2706::DEBUG::2015-02-25 20:10:36,434::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1754::DEBUG::2015-02-25 20:10:36,441::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1843::INFO::2015-02-25 20:10:36,440::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='fa5869b4-d2fc-48e0-85f1-0b0121b4bd94', volUUID='ec965cfe-91c6-40cc-9a86-328173a4b72f', options=None)
Thread-422::DEBUG::2015-02-25 20:10:36,443::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2016::DEBUG::2015-02-25 20:10:36,448::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-24::DEBUG::2015-02-25 20:10:36,494::fileSD::261::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/glusterSD/10.10.0.14:_ds01/e732a82f-bae9-4368-8b98-dedc1c3814de/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-505::INFO::2015-02-25 20:10:36,967::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1399066624', 'apparentsize': '21474836480'}
Thread-24::DEBUG::2015-02-25 20:10:36,973::fileSD::261::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n457 bytes (457 B) copied, 0.000520198 s, 879 kB/s\n'; <rc> = 0
Thread-481::INFO::2015-02-25 20:10:37,000::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1461882880', 'apparentsize': '21474836480'}
Thread-505::DEBUG::2015-02-25 20:10:37,023::task::1191::Storage.TaskManager.Task::(prepare) Task=`019c99ce-31e9-474a-ac97-5f401eef2772`::finished: {'truesize': '1399066624', 'apparentsize': '21474836480'}
Thread-481::DEBUG::2015-02-25 20:10:37,044::task::1191::Storage.TaskManager.Task::(prepare) Task=`9f72da41-371a-4c53-ba47-f18b761b4fc9`::finished: {'truesize': '1461882880', 'apparentsize': '21474836480'}
Thread-505::DEBUG::2015-02-25 20:10:37,048::task::595::Storage.TaskManager.Task::(_updateState) Task=`019c99ce-31e9-474a-ac97-5f401eef2772`::moving from state preparing -> state finished
Thread-481::DEBUG::2015-02-25 20:10:37,058::task::595::Storage.TaskManager.Task::(_updateState) Task=`9f72da41-371a-4c53-ba47-f18b761b4fc9`::moving from state preparing -> state finished
Thread-1332::INFO::2015-02-25 20:10:37,058::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1858555904', 'apparentsize': '21474836480'}
Thread-505::DEBUG::2015-02-25 20:10:37,062::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-481::DEBUG::2015-02-25 20:10:37,074::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-505::DEBUG::2015-02-25 20:10:37,084::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1332::DEBUG::2015-02-25 20:10:37,086::task::1191::Storage.TaskManager.Task::(prepare) Task=`912c7e66-9760-4a69-83d5-9027641c36c5`::finished: {'truesize': '1858555904', 'apparentsize': '21474836480'}
Thread-481::DEBUG::2015-02-25 20:10:37,090::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1843::INFO::2015-02-25 20:10:37,098::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '2763542528', 'apparentsize': '64424509440'}
Thread-505::DEBUG::2015-02-25 20:10:37,104::task::993::Storage.TaskManager.Task::(_decref) Task=`019c99ce-31e9-474a-ac97-5f401eef2772`::ref 0 aborting False
Thread-1332::DEBUG::2015-02-25 20:10:37,107::task::595::Storage.TaskManager.Task::(_updateState) Task=`912c7e66-9760-4a69-83d5-9027641c36c5`::moving from state preparing -> state finished
Thread-481::DEBUG::2015-02-25 20:10:37,114::task::993::Storage.TaskManager.Task::(_decref) Task=`9f72da41-371a-4c53-ba47-f18b761b4fc9`::ref 0 aborting False
Thread-1843::DEBUG::2015-02-25 20:10:37,123::task::1191::Storage.TaskManager.Task::(prepare) Task=`284c065f-8f8c-4df0-83cc-8c652dcb3b63`::finished: {'truesize': '2763542528', 'apparentsize': '64424509440'}
Thread-1332::DEBUG::2015-02-25 20:10:37,130::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1843::DEBUG::2015-02-25 20:10:37,144::task::595::Storage.TaskManager.Task::(_updateState) Task=`284c065f-8f8c-4df0-83cc-8c652dcb3b63`::moving from state preparing -> state finished
Thread-1332::DEBUG::2015-02-25 20:10:37,149::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1843::DEBUG::2015-02-25 20:10:37,163::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1332::DEBUG::2015-02-25 20:10:37,175::task::993::Storage.TaskManager.Task::(_decref) Task=`912c7e66-9760-4a69-83d5-9027641c36c5`::ref 0 aborting False
Thread-1843::DEBUG::2015-02-25 20:10:37,186::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1843::DEBUG::2015-02-25 20:10:37,230::task::993::Storage.TaskManager.Task::(_decref) Task=`284c065f-8f8c-4df0-83cc-8c652dcb3b63`::ref 0 aborting False
Thread-91::DEBUG::2015-02-25 20:10:37,276::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-540::DEBUG::2015-02-25 20:10:37,296::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-3312::DEBUG::2015-02-25 20:10:37,308::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-505::DEBUG::2015-02-25 20:10:37,384::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-481::DEBUG::2015-02-25 20:10:37,391::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1332::DEBUG::2015-02-25 20:10:37,471::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1843::DEBUG::2015-02-25 20:10:37,522::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-65::DEBUG::2015-02-25 20:10:38,200::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2687::DEBUG::2015-02-25 20:10:38,207::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1322::DEBUG::2015-02-25 20:10:38,509::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-467::DEBUG::2015-02-25 20:10:38,510::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2517::DEBUG::2015-02-25 20:10:38,601::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2541::DEBUG::2015-02-25 20:10:38,607::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2760::DEBUG::2015-02-25 20:10:38,608::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-9472::DEBUG::2015-02-25 20:10:38,990::task::595::Storage.TaskManager.Task::(_updateState) Task=`b4a44586-9084-436a-b871-24e1db00419c`::moving from state init -> state preparing
Thread-9472::INFO::2015-02-25 20:10:38,991::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-9472::INFO::2015-02-25 20:10:38,991::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'e732a82f-bae9-4368-8b98-dedc1c3814de': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000520198', 'lastCheck': '1.8', 'valid': True}, '05be2753-83ed-4e6e-b236-4b342939a5fb': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000944452', 'lastCheck': '7.3', 'valid': True}}
Thread-9472::DEBUG::2015-02-25 20:10:38,991::task::1191::Storage.TaskManager.Task::(prepare) Task=`b4a44586-9084-436a-b871-24e1db00419c`::finished: {'e732a82f-bae9-4368-8b98-dedc1c3814de': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000520198', 'lastCheck': '1.8', 'valid': True}, '05be2753-83ed-4e6e-b236-4b342939a5fb': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000944452', 'lastCheck': '7.3', 'valid': True}}
Thread-9472::DEBUG::2015-02-25 20:10:38,991::task::595::Storage.TaskManager.Task::(_updateState) Task=`b4a44586-9084-436a-b871-24e1db00419c`::moving from state preparing -> state finished
Thread-9472::DEBUG::2015-02-25 20:10:38,991::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-9472::DEBUG::2015-02-25 20:10:38,992::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-9472::DEBUG::2015-02-25 20:10:38,992::task::993::Storage.TaskManager.Task::(_decref) Task=`b4a44586-9084-436a-b871-24e1db00419c`::ref 0 aborting False
Thread-1259::DEBUG::2015-02-25 20:10:39,669::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-180::DEBUG::2015-02-25 20:10:39,738::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1187::DEBUG::2015-02-25 20:10:39,799::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-57::DEBUG::2015-02-25 20:10:39,822::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-395::DEBUG::2015-02-25 20:10:40,224::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-4645::DEBUG::2015-02-25 20:10:40,226::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1417::DEBUG::2015-02-25 20:10:40,228::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1059::DEBUG::2015-02-25 20:10:40,231::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-138::DEBUG::2015-02-25 20:10:40,237::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-4731::DEBUG::2015-02-25 20:10:40,244::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-238::DEBUG::2015-02-25 20:10:40,290::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1604::DEBUG::2015-02-25 20:10:40,382::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-199::DEBUG::2015-02-25 20:10:40,677::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1963::DEBUG::2015-02-25 20:10:40,679::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1438::DEBUG::2015-02-25 20:10:40,680::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-3013::DEBUG::2015-02-25 20:10:41,130::task::595::Storage.TaskManager.Task::(_updateState) Task=`7a890d2b-cab7-432f-80f5-0d42e24b540a`::moving from state init -> state preparing
Thread-3013::INFO::2015-02-25 20:10:41,130::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='a735328d-497c-49ca-9db0-d83095c0ddc0', volUUID='f5e0badc-f5de-4a51-a7e7-ea52054d1d0c', options=None)
Thread-3013::INFO::2015-02-25 20:10:41,156::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1902219264', 'apparentsize': '64424509440'}
Thread-3013::DEBUG::2015-02-25 20:10:41,157::task::1191::Storage.TaskManager.Task::(prepare) Task=`7a890d2b-cab7-432f-80f5-0d42e24b540a`::finished: {'truesize': '1902219264', 'apparentsize': '64424509440'}
Thread-3013::DEBUG::2015-02-25 20:10:41,157::task::595::Storage.TaskManager.Task::(_updateState) Task=`7a890d2b-cab7-432f-80f5-0d42e24b540a`::moving from state preparing -> state finished
Thread-3013::DEBUG::2015-02-25 20:10:41,157::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-3013::DEBUG::2015-02-25 20:10:41,157::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-3013::DEBUG::2015-02-25 20:10:41,157::task::993::Storage.TaskManager.Task::(_decref) Task=`7a890d2b-cab7-432f-80f5-0d42e24b540a`::ref 0 aborting False
Thread-3013::DEBUG::2015-02-25 20:10:41,273::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-126::DEBUG::2015-02-25 20:10:41,510::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2146::DEBUG::2015-02-25 20:10:41,512::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1576::DEBUG::2015-02-25 20:10:41,513::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-192::DEBUG::2015-02-25 20:10:41,599::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-733::DEBUG::2015-02-25 20:10:41,604::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-25::DEBUG::2015-02-25 20:10:41,650::domainMonitor::209::Storage.DomainMonitorThread::(_monitorDomain) Refreshing domain 05be2753-83ed-4e6e-b236-4b342939a5fb
Thread-25::DEBUG::2015-02-25 20:10:41,659::fileSD::152::Storage.StorageDomain::(__init__) Reading domain in path /rhev/data-center/mnt/117.18.79.72:_36Cloud__OStemplates/05be2753-83ed-4e6e-b236-4b342939a5fb
Thread-25::DEBUG::2015-02-25 20:10:41,663::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent dict with FileMetadataRW backend
Thread-25::DEBUG::2015-02-25 20:10:41,665::persistentDict::234::Storage.PersistentDict::(refresh) read lines (FileMetadataRW)=['CLASS=Backup', 'DESCRIPTION=OS_Templates', 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=', 'LOCKRENEWALINTERVALSEC=5', 'POOL_UUID=00000002-0002-0002-0002-000000000145', 'REMOTE_PATH=117.18.79.72:/36Cloud_OStemplates', 'ROLE=Regular', 'SDUUID=05be2753-83ed-4e6e-b236-4b342939a5fb', 'TYPE=NFS', 'VERSION=0', '_SHA_CKSUM=11fb1120ec2275ad55aa9e23a202c2a991d596cd']
Thread-25::DEBUG::2015-02-25 20:10:41,669::fileSD::610::Storage.StorageDomain::(imageGarbageCollector) Removing remnants of deleted images []
Thread-25::INFO::2015-02-25 20:10:41,669::sd::385::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace 05be2753-83ed-4e6e-b236-4b342939a5fb_imageNS already registered
Thread-25::INFO::2015-02-25 20:10:41,669::sd::393::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace 05be2753-83ed-4e6e-b236-4b342939a5fb_volumeNS already registered
Thread-25::DEBUG::2015-02-25 20:10:41,672::fileSD::261::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/117.18.79.72:_36Cloud__OStemplates/05be2753-83ed-4e6e-b236-4b342939a5fb/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-25::DEBUG::2015-02-25 20:10:41,901::fileSD::261::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n345 bytes (345 B) copied, 0.000768833 s, 449 kB/s\n'; <rc> = 0
Thread-2371::DEBUG::2015-02-25 20:10:42,178::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2066::DEBUG::2015-02-25 20:10:42,181::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-56::DEBUG::2015-02-25 20:10:42,442::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-125::DEBUG::2015-02-25 20:10:42,443::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-742::DEBUG::2015-02-25 20:10:43,127::task::595::Storage.TaskManager.Task::(_updateState) Task=`78f4a3c0-5bbb-49f6-998a-5530771d838b`::moving from state init -> state preparing
Thread-742::INFO::2015-02-25 20:10:43,178::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='0fe6c51c-e516-4f2f-8943-832e2fbed2ee', volUUID='99a70d06-05c1-4402-8f38-24fb6e4e7ae3', options=None)
Thread-742::INFO::2015-02-25 20:10:43,278::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1726410752', 'apparentsize': '21474836480'}
Thread-742::DEBUG::2015-02-25 20:10:43,289::task::1191::Storage.TaskManager.Task::(prepare) Task=`78f4a3c0-5bbb-49f6-998a-5530771d838b`::finished: {'truesize': '1726410752', 'apparentsize': '21474836480'}
Thread-742::DEBUG::2015-02-25 20:10:43,298::task::595::Storage.TaskManager.Task::(_updateState) Task=`78f4a3c0-5bbb-49f6-998a-5530771d838b`::moving from state preparing -> state finished
Thread-742::DEBUG::2015-02-25 20:10:43,307::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-742::DEBUG::2015-02-25 20:10:43,315::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-742::DEBUG::2015-02-25 20:10:43,327::task::993::Storage.TaskManager.Task::(_decref) Task=`78f4a3c0-5bbb-49f6-998a-5530771d838b`::ref 0 aborting False
Thread-2781::DEBUG::2015-02-25 20:10:43,422::task::595::Storage.TaskManager.Task::(_updateState) Task=`74a7edf8-abd5-4b40-8c75-42ee152863e5`::moving from state init -> state preparing
Thread-2150::DEBUG::2015-02-25 20:10:43,424::task::595::Storage.TaskManager.Task::(_updateState) Task=`c2182a90-ef38-417c-b16a-33dc821cfe22`::moving from state init -> state preparing
Thread-2781::INFO::2015-02-25 20:10:43,434::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='ca75c558-ac28-4cd4-b1db-acde6ed96cce', volUUID='a8da2535-e69b-412a-ba39-2fd6782070d4', options=None)
Thread-2150::INFO::2015-02-25 20:10:43,437::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='9c75ce80-46b2-40cc-b3f6-2075154fe427', volUUID='aebc65ce-3b5b-4696-8acd-0535541c9989', options=None)
Thread-742::DEBUG::2015-02-25 20:10:43,479::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2781::INFO::2015-02-25 20:10:43,489::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1550782464', 'apparentsize': '21474836480'}
Thread-2150::INFO::2015-02-25 20:10:43,500::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1868447744', 'apparentsize': '21474836480'}
Thread-2781::DEBUG::2015-02-25 20:10:43,501::task::1191::Storage.TaskManager.Task::(prepare) Task=`74a7edf8-abd5-4b40-8c75-42ee152863e5`::finished: {'truesize': '1550782464', 'apparentsize': '21474836480'}
Thread-2150::DEBUG::2015-02-25 20:10:43,514::task::1191::Storage.TaskManager.Task::(prepare) Task=`c2182a90-ef38-417c-b16a-33dc821cfe22`::finished: {'truesize': '1868447744', 'apparentsize': '21474836480'}
Thread-2781::DEBUG::2015-02-25 20:10:43,514::task::595::Storage.TaskManager.Task::(_updateState) Task=`74a7edf8-abd5-4b40-8c75-42ee152863e5`::moving from state preparing -> state finished
Thread-2150::DEBUG::2015-02-25 20:10:43,524::task::595::Storage.TaskManager.Task::(_updateState) Task=`c2182a90-ef38-417c-b16a-33dc821cfe22`::moving from state preparing -> state finished
Thread-2781::DEBUG::2015-02-25 20:10:43,526::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-2150::DEBUG::2015-02-25 20:10:43,532::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-2781::DEBUG::2015-02-25 20:10:43,536::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-2150::DEBUG::2015-02-25 20:10:43,542::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-2781::DEBUG::2015-02-25 20:10:43,548::task::993::Storage.TaskManager.Task::(_decref) Task=`74a7edf8-abd5-4b40-8c75-42ee152863e5`::ref 0 aborting False
Thread-2150::DEBUG::2015-02-25 20:10:43,556::task::993::Storage.TaskManager.Task::(_decref) Task=`c2182a90-ef38-417c-b16a-33dc821cfe22`::ref 0 aborting False
Thread-2781::DEBUG::2015-02-25 20:10:43,704::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-2150::DEBUG::2015-02-25 20:10:43,705::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-590::DEBUG::2015-02-25 20:10:44,262::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1753::DEBUG::2015-02-25 20:10:44,266::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-4574::DEBUG::2015-02-25 20:10:44,270::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-606::DEBUG::2015-02-25 20:10:46,264::task::595::Storage.TaskManager.Task::(_updateState) Task=`67cd6cd3-f664-4bc1-a3da-e1a592e5f16c`::moving from state init -> state preparing
Thread-606::INFO::2015-02-25 20:10:46,264::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='ca0c3ef0-6e76-4123-82b9-34cefff22def', volUUID='babbb3af-0603-4dd5-a58f-2cb2daf9a5de', options=None)
Thread-606::INFO::2015-02-25 20:10:46,289::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '2159808512', 'apparentsize': '21474836480'}
Thread-606::DEBUG::2015-02-25 20:10:46,289::task::1191::Storage.TaskManager.Task::(prepare) Task=`67cd6cd3-f664-4bc1-a3da-e1a592e5f16c`::finished: {'truesize': '2159808512', 'apparentsize': '21474836480'}
Thread-606::DEBUG::2015-02-25 20:10:46,289::task::595::Storage.TaskManager.Task::(_updateState) Task=`67cd6cd3-f664-4bc1-a3da-e1a592e5f16c`::moving from state preparing -> state finished
Thread-606::DEBUG::2015-02-25 20:10:46,289::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-606::DEBUG::2015-02-25 20:10:46,289::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-606::DEBUG::2015-02-25 20:10:46,290::task::993::Storage.TaskManager.Task::(_decref) Task=`67cd6cd3-f664-4bc1-a3da-e1a592e5f16c`::ref 0 aborting False
Thread-606::DEBUG::2015-02-25 20:10:46,407::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-5186::DEBUG::2015-02-25 20:10:46,954::task::595::Storage.TaskManager.Task::(_updateState) Task=`e1ec4e4a-5705-488d-a6e9-3ace320aea09`::moving from state init -> state preparing
Thread-5186::INFO::2015-02-25 20:10:46,954::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='542a4756-2d6f-41ff-a7b3-fa9ce178065e', volUUID='f54511d3-b95c-4065-a332-d4e65442c288', options=None)
Thread-627::DEBUG::2015-02-25 20:10:46,956::task::595::Storage.TaskManager.Task::(_updateState) Task=`44cb5dcf-dc96-48aa-9186-f7ad7e5476c1`::moving from state init -> state preparing
Thread-627::INFO::2015-02-25 20:10:46,957::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='7aab4d26-3edd-47a2-9e44-ffcbb9a92d8e', volUUID='7a422925-b4a5-47f5-9fe4-8134bf647586', options=None)
Thread-4437::DEBUG::2015-02-25 20:10:46,959::task::595::Storage.TaskManager.Task::(_updateState) Task=`06601999-b701-4fc1-9676-96ab8303675f`::moving from state init -> state preparing
Thread-4437::INFO::2015-02-25 20:10:46,960::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='0e333bcf-ca48-4fac-955b-6d62ed08b637', volUUID='ccfe7a62-79e0-4b7a-8aef-cbb1f275a774', options=None)
Thread-5186::INFO::2015-02-25 20:10:46,971::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1233408000', 'apparentsize': '21474836480'}
Thread-5186::DEBUG::2015-02-25 20:10:46,971::task::1191::Storage.TaskManager.Task::(prepare) Task=`e1ec4e4a-5705-488d-a6e9-3ace320aea09`::finished: {'truesize': '1233408000', 'apparentsize': '21474836480'}
Thread-5186::DEBUG::2015-02-25 20:10:46,971::task::595::Storage.TaskManager.Task::(_updateState) Task=`e1ec4e4a-5705-488d-a6e9-3ace320aea09`::moving from state preparing -> state finished
Thread-5186::DEBUG::2015-02-25 20:10:46,972::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-5186::DEBUG::2015-02-25 20:10:46,972::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-5186::DEBUG::2015-02-25 20:10:46,972::task::993::Storage.TaskManager.Task::(_decref) Task=`e1ec4e4a-5705-488d-a6e9-3ace320aea09`::ref 0 aborting False
Thread-627::INFO::2015-02-25 20:10:46,989::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1670332416', 'apparentsize': '21474836480'}
Thread-627::DEBUG::2015-02-25 20:10:46,989::task::1191::Storage.TaskManager.Task::(prepare) Task=`44cb5dcf-dc96-48aa-9186-f7ad7e5476c1`::finished: {'truesize': '1670332416', 'apparentsize': '21474836480'}
Thread-627::DEBUG::2015-02-25 20:10:46,989::task::595::Storage.TaskManager.Task::(_updateState) Task=`44cb5dcf-dc96-48aa-9186-f7ad7e5476c1`::moving from state preparing -> state finished
Thread-627::DEBUG::2015-02-25 20:10:46,989::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-627::DEBUG::2015-02-25 20:10:46,989::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-627::DEBUG::2015-02-25 20:10:46,990::task::993::Storage.TaskManager.Task::(_decref) Task=`44cb5dcf-dc96-48aa-9186-f7ad7e5476c1`::ref 0 aborting False
Thread-4437::INFO::2015-02-25 20:10:46,994::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '2159915008', 'apparentsize': '21474836480'}
Thread-4437::DEBUG::2015-02-25 20:10:46,994::task::1191::Storage.TaskManager.Task::(prepare) Task=`06601999-b701-4fc1-9676-96ab8303675f`::finished: {'truesize': '2159915008', 'apparentsize': '21474836480'}
Thread-4437::DEBUG::2015-02-25 20:10:46,994::task::595::Storage.TaskManager.Task::(_updateState) Task=`06601999-b701-4fc1-9676-96ab8303675f`::moving from state preparing -> state finished
Thread-4437::DEBUG::2015-02-25 20:10:46,994::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-4437::DEBUG::2015-02-25 20:10:46,995::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-4437::DEBUG::2015-02-25 20:10:46,995::task::993::Storage.TaskManager.Task::(_decref) Task=`06601999-b701-4fc1-9676-96ab8303675f`::ref 0 aborting False
Thread-5186::DEBUG::2015-02-25 20:10:47,120::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-627::DEBUG::2015-02-25 20:10:47,126::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-4437::DEBUG::2015-02-25 20:10:47,141::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-24::DEBUG::2015-02-25 20:10:47,233::fileSD::261::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/glusterSD/10.10.0.14:_ds01/e732a82f-bae9-4368-8b98-dedc1c3814de/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-24::DEBUG::2015-02-25 20:10:47,461::fileSD::261::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n457 bytes (457 B) copied, 0.000454804 s, 1.0 MB/s\n'; <rc> = 0
Thread-659::DEBUG::2015-02-25 20:10:47,711::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-379::DEBUG::2015-02-25 20:10:47,955::task::595::Storage.TaskManager.Task::(_updateState) Task=`2a7c88e8-8c18-4737-894b-c82d20f7c111`::moving from state init -> state preparing
Thread-379::INFO::2015-02-25 20:10:47,990::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='9ee10339-358c-4b24-9b54-cd13d8bb047f', volUUID='b38ff11f-5efe-42db-a96e-8c69f2e75b5c', options=None)
Thread-1789::DEBUG::2015-02-25 20:10:48,382::task::595::Storage.TaskManager.Task::(_updateState) Task=`52a1cf85-b356-488a-8bb0-8503c72232a0`::moving from state init -> state preparing
Thread-379::INFO::2015-02-25 20:10:48,462::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1718005760', 'apparentsize': '21474836480'}
Thread-1789::INFO::2015-02-25 20:10:48,485::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='0a3bc2c2-2218-43b5-bb22-c9c46b7c1a4d', volUUID='3e15f376-80e6-4d4e-8956-769dcd4fa69a', options=None)
Thread-379::DEBUG::2015-02-25 20:10:48,573::task::1191::Storage.TaskManager.Task::(prepare) Task=`2a7c88e8-8c18-4737-894b-c82d20f7c111`::finished: {'truesize': '1718005760', 'apparentsize': '21474836480'}
Thread-2891::DEBUG::2015-02-25 20:10:48,621::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-379::DEBUG::2015-02-25 20:10:48,641::task::595::Storage.TaskManager.Task::(_updateState) Task=`2a7c88e8-8c18-4737-894b-c82d20f7c111`::moving from state preparing -> state finished
Thread-379::DEBUG::2015-02-25 20:10:48,732::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-379::DEBUG::2015-02-25 20:10:48,795::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1789::INFO::2015-02-25 20:10:48,853::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1789825024', 'apparentsize': '21474836480'}
Thread-379::DEBUG::2015-02-25 20:10:48,866::task::993::Storage.TaskManager.Task::(_decref) Task=`2a7c88e8-8c18-4737-894b-c82d20f7c111`::ref 0 aborting False
Thread-1789::DEBUG::2015-02-25 20:10:48,924::task::1191::Storage.TaskManager.Task::(prepare) Task=`52a1cf85-b356-488a-8bb0-8503c72232a0`::finished: {'truesize': '1789825024', 'apparentsize': '21474836480'}
Thread-1789::DEBUG::2015-02-25 20:10:48,974::task::595::Storage.TaskManager.Task::(_updateState) Task=`52a1cf85-b356-488a-8bb0-8503c72232a0`::moving from state preparing -> state finished
Thread-1789::DEBUG::2015-02-25 20:10:49,015::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1789::DEBUG::2015-02-25 20:10:49,042::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1472::DEBUG::2015-02-25 20:10:49,054::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-929::DEBUG::2015-02-25 20:10:49,056::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1219::DEBUG::2015-02-25 20:10:49,057::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1789::DEBUG::2015-02-25 20:10:49,061::task::993::Storage.TaskManager.Task::(_decref) Task=`52a1cf85-b356-488a-8bb0-8503c72232a0`::ref 0 aborting False
Thread-379::DEBUG::2015-02-25 20:10:49,118::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1789::DEBUG::2015-02-25 20:10:49,203::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-66::DEBUG::2015-02-25 20:10:49,304::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present
Thread-1399::DEBUG::2015-02-25 20:10:49,311::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present