Dan Kenigsberg has submitted this change and it was merged.
Change subject: logging: More standard logging format
......................................................................
logging: More standard logging format
Use nicer and more standard logging format, similar to engine log
format. Having similar logging formats in the oVirt project should make
it easier to debug and support.
Changes compared to engine log:
- (thread-name) is displayed before the [logger-name] so it is always
aligned.
- Add (module:lineno) at the end of the message.
Here is example log during vdsm startup:
2016-09-23 02:11:43,319 INFO (MainThread) [vds] (PID: 19841) I am the actual
vdsm 4.18.999-604.gitf69ba3a.el7 voodoo6.tlv.redhat.com (3.10.0-489.el7.x86_64)
(vdsm:145)
2016-09-23 02:11:43,319 INFO (MainThread) [vds] VDSM will run with cpu
affinity: frozenset([1]) (vdsm:251)
2016-09-23 02:11:43,385 INFO (MainThread) [storage.check] Starting check
service (check:91)
2016-09-23 02:11:43,389 INFO (MainThread) [storage.Dispatcher] Starting
StorageDispatcher... (dispatcher:47)
2016-09-23 02:11:43,389 INFO (check/loop) [storage.asyncevent] Starting
<EventLoop running=True closed=False at 0x50437200> (asyncevent:122)
2016-09-23 02:11:43,480 INFO (MainThread) [dispatcher] Run and protect:
registerDomainStateChangeCallback(callbackFunc=<functools.partial object at
0x3877a48>) (logUtils:49)
2016-09-23 02:11:43,480 INFO (MainThread) [dispatcher] Run and protect:
registerDomainStateChangeCallback, Return response: None (logUtils:52)
2016-09-23 02:11:43,481 INFO (MainThread) [MOM] Preparing MOM interface
(momIF:49)
2016-09-23 02:11:43,481 INFO (MainThread) [MOM] Using named unix socket
/var/run/vdsm/mom-vdsm.sock (momIF:58)
2016-09-23 02:11:43,482 INFO (MainThread) [root] Unregistering all secrets
(secret:91)
2016-09-23 02:11:43,488 INFO (MainThread) [vds] Setting channels' timeout to
30 seconds. (vmchannels:223)
2016-09-23 02:11:43,492 INFO (MainThread) [vds.MultiProtocolAcceptor]
Listening at :::54321 (protocoldetector:178)
2016-09-23 02:11:44,543 INFO (clientIFinit) [vds] recovery [1:1/1]:
recovered domain 45b59cae-f2a0-4d83-8da8-b7c0a21fbe14 from libvirt
(recovery:178)
2016-09-23 02:11:44,543 INFO (clientIFinit) [vds] recovery: waiting for 1
domains to go up (clientIF:545)
2016-09-23 02:11:44,543 INFO (Thread-11) [virt.vm]
vmId=`45b59cae-f2a0-4d83-8da8-b7c0a21fbe14`::VM wrapper has started (vm:1751)
2016-09-23 02:11:44,544 INFO (Thread-11) [dispatcher] Run and protect:
getVolumeSize(sdUUID=u'5f35b5c0-17d7-4475-9125-e97f1cdb06f9',
spUUID=u'f9374c0e-ae24-4bc1-a596-f61d5f05bc5f',
imgUUID=u'3bdc1ff7-22f9-4263-8955-7e3bfa540edc',
volUUID=u'7e159928-0e2f-423a-a02d-3faddbf55585', options=None) (logUtils:49)
2016-09-23 02:11:44,544 ERROR (Thread-11) [storage.StorageDomainCache]
looking for unfetched domain 5f35b5c0-17d7-4475-9125-e97f1cdb06f9 (sdc:151)
2016-09-23 02:11:44,544 ERROR (Thread-11) [storage.StorageDomainCache]
looking for domain 5f35b5c0-17d7-4475-9125-e97f1cdb06f9 (sdc:168)
2016-09-23 02:11:44,673 INFO (Thread-11) [storage.LVM] Refreshing lvs:
vg=5f35b5c0-17d7-4475-9125-e97f1cdb06f9 lvs=['metadata'] (lvm:1226)
2016-09-23 02:11:44,947 INFO (Thread-11) [storage.LVM] Refreshing lvs:
vg=5f35b5c0-17d7-4475-9125-e97f1cdb06f9 lvs=['ids'] (lvm:1226)
2016-09-23 02:11:45,074 INFO (Thread-11) [storage.LVM] Refreshing lvs:
vg=5f35b5c0-17d7-4475-9125-e97f1cdb06f9 lvs=['leases'] (lvm:1226)
2016-09-23 02:11:45,210 INFO (Thread-11) [storage.LVM] Refreshing lvs:
vg=5f35b5c0-17d7-4475-9125-e97f1cdb06f9 lvs=['metadata', 'leases', 'ids',
'inbox', 'outbox', 'master'] (lvm:1226)
2016-09-23 02:11:45,219 INFO (hsm/init) [storage.LVM] Refreshing lvs:
vg=bb85ee2f-d674-489f-9377-3eb1f176e8fb lvs=['inbox', 'outbox', 'metadata',
'ids', 'leases', 'master'] (lvm:677)
2016-09-23 02:11:45,386 INFO (Thread-11) [dispatcher] Run and protect:
getVolumeSize, Return response: {'truesize': '1073741824', 'apparentsize':
'1073741824'} (logUtils:52)
2016-09-23 02:11:45,387 INFO (Thread-11) [dispatcher] Run and protect:
getVolumeSize(sdUUID=u'5f35b5c0-17d7-4475-9125-e97f1cdb06f9',
spUUID=u'f9374c0e-ae24-4bc1-a596-f61d5f05bc5f',
imgUUID=u'65e74f9f-a41b-4636-8e72-db3dd7d73055',
volUUID=u'3a9f341b-4149-4794-88d6-4fd12ff84307', options=None) (logUtils:49)
2016-09-23 02:11:45,387 INFO (Thread-11) [dispatcher] Run and protect:
getVolumeSize, Return response: {'truesize': '7650410496', 'apparentsize':
'7650410496'} (logUtils:52)
2016-09-23 02:11:45,387 INFO (Thread-11) [dispatcher] Run and protect:
getVolumeSize(sdUUID=u'5f35b5c0-17d7-4475-9125-e97f1cdb06f9',
spUUID=u'f9374c0e-ae24-4bc1-a596-f61d5f05bc5f',
imgUUID=u'69107a7c-acd6-44b0-a481-e7ec13486847',
volUUID=u'88816475-3ea1-4d1f-ac93-7767cf9a2d2c', options=None) (logUtils:49)
2016-09-23 02:11:45,388 INFO (Thread-11) [dispatcher] Run and protect:
getVolumeSize, Return response: {'truesize': '1073741824', 'apparentsize':
'1073741824'} (logUtils:52)
2016-09-23 02:11:45,410 INFO (Thread-11) [virt.vm]
vmId=`45b59cae-f2a0-4d83-8da8-b7c0a21fbe14`::Starting connection
(guestagent:234)
2016-09-23 02:11:45,418 INFO (Thread-11) [virt.vm]
vmId=`45b59cae-f2a0-4d83-8da8-b7c0a21fbe14`::CPU running: domain initialization
(vm:4653)
2016-09-23 02:11:45,465 WARNING (Thread-11) [vds] Not ready yet, ignoring event
u'|virt|VM_status|45b59cae-f2a0-4d83-8da8-b7c0a21fbe14'
args={u'45b59cae-f2a0-4d83-8da8-b7c0a21fbe14': {'status': 'Up', 'displayInfo':
[{'tlsPort': u'5900', 'ipAddress': '10.35.0.110', 'type': u'spice', 'port':
'-1'}], 'hash': '-6596881514735067770', 'displayIp': '10.35.0.110',
'displayPort': '-1', 'displaySecurePort': u'5900', 'timeOffset': u'0',
'pauseCode': 'NOERR', 'vcpuQuota': '-1', 'cpuUser': '0.00', 'monitorResponse':
'0', 'elapsedTime': '199082', 'displayType': 'qxl', 'cpuSys': '0.00',
'clientIp': '', 'vcpuPeriod': 100000L}} (clientIF:157)
2016-09-23 02:11:45,475 INFO (BindingXMLRPC) [vds] XMLRPC server running
(bindingxmlrpc:63)
2016-09-23 02:11:45,476 INFO (MainThread) [health] Starting health monitor
(interval=60) (health:64)
2016-09-23 02:11:45,525 INFO (hsm/init) [storage.LVM] Refreshing lvs:
vg=5f35b5c0-17d7-4475-9125-e97f1cdb06f9 lvs=['ids', 'master', 'inbox',
'metadata', 'outbox', 'leases'] (lvm:677)
2016-09-23 02:11:45,544 INFO (clientIFinit) [dispatcher] Run and protect:
getConnectedStoragePoolsList(options=None) (logUtils:49)
2016-09-23 02:11:45,544 INFO (clientIFinit) [dispatcher] Run and protect:
getConnectedStoragePoolsList, Return response: {'poollist': []} (logUtils:52)
2016-09-23 02:11:45,544 INFO (clientIFinit) [vds] recovery: waiting for
storage pool to go up (clientIF:551)
2016-09-23 02:11:45,572 INFO (Reactor thread)
[ProtocolDetector.AcceptorImpl] Accepting connection from
::ffff:10.35.0.102:50379 (protocoldetector:71)
2016-09-23 02:11:45,635 INFO (Reactor thread) [ProtocolDetector.Detector]
Detected protocol stomp from ::ffff:10.35.0.102:50379 (protocoldetector:120)
2016-09-23 02:11:45,636 INFO (Reactor thread) [Broker.StompAdapter]
Subscribe command received (stompreactor:128)
Change-Id: I640c3c83db3b5818a08b4984d5358b1e27bf0ef3
Signed-off-by: Nir Soffer <nsof...@redhat.com>
Reviewed-on: https://gerrit.ovirt.org/64113
Continuous-Integration: Jenkins CI
Reviewed-by: Michal Skrivanek <michal.skriva...@redhat.com>
Reviewed-by: Francesco Romani <from...@redhat.com>
Reviewed-by: Piotr Kliczewski <piotr.kliczew...@gmail.com>
Reviewed-by: Edward Haas <edwa...@redhat.com>
Reviewed-by: Dan Kenigsberg <dan...@redhat.com>
---
M static/etc/vdsm/logger.conf.in
M tests/run_tests_local.sh.in
2 files changed, 2 insertions(+), 2 deletions(-)
Approvals:
Piotr Kliczewski: Looks good to me, but someone else must approve
Nir Soffer: Verified
Jenkins CI: Passed CI tests
Dan Kenigsberg: Looks good to me, approved
Francesco Romani: Looks good to me, but someone else must approve
Michal Skrivanek: Looks good to me, but someone else must approve
Edward Haas: Looks good to me, but someone else must approve
--
To view, visit https://gerrit.ovirt.org/64113
To unsubscribe, visit https://gerrit.ovirt.org/settings
Gerrit-MessageType: merged
Gerrit-Change-Id: I640c3c83db3b5818a08b4984d5358b1e27bf0ef3
Gerrit-PatchSet: 5
Gerrit-Project: vdsm
Gerrit-Branch: master
Gerrit-Owner: Nir Soffer <nsof...@redhat.com>
Gerrit-Reviewer: Adam Litke <ali...@redhat.com>
Gerrit-Reviewer: Allon Mureinik <amure...@redhat.com>
Gerrit-Reviewer: Dan Kenigsberg <dan...@redhat.com>
Gerrit-Reviewer: Edward Haas <edwa...@redhat.com>
Gerrit-Reviewer: Francesco Romani <from...@redhat.com>
Gerrit-Reviewer: Jenkins CI
Gerrit-Reviewer: Michal Skrivanek <michal.skriva...@redhat.com>
Gerrit-Reviewer: Milan Zamazal <mzama...@redhat.com>
Gerrit-Reviewer: Nir Soffer <nsof...@redhat.com>
Gerrit-Reviewer: Peter Portante <peter.porta...@redhat.com>
Gerrit-Reviewer: Piotr Kliczewski <piotr.kliczew...@gmail.com>
Gerrit-Reviewer: Yaniv Bronhaim <ybron...@redhat.com>
Gerrit-Reviewer: gerrit-hooks <automat...@ovirt.org>
_______________________________________________
vdsm-patches mailing list -- vdsm-patches@lists.fedorahosted.org
To unsubscribe send an email to vdsm-patches-le...@lists.fedorahosted.org
