Description of problem: We should reduce the amount of logging per upload, to avoid logs filling too fast. However, we should also provide an option to enable them for debug, in case needed. Version-Release number of selected component (if applicable): ovirt-imageio-daemon-1.4.2-0.el7ev.noarch
Target release should be placed once a package build is known to fix a issue. Since this bug is not modified, the target version has been reset. Please use target milestone to plan a fix for a oVirt release.
We cleaned up logging, reducing amount of logs to 25% compared with 1.4.2. To view the START and FINISH [web] logs, you can enable DEBUG level in /etc/ovirt-imageio-daemon/logger.conf: [logger_root] level=DEBUG handlers=logfile propagate=0 Note that this will log about 4X times more data, so you need to increase the size of the log files: [handler_logfile] class=logging.handlers.RotatingFileHandler args=('/var/log/ovirt-imageio-daemon/daemon.log', 'a', 83886080, 10) level=DEBUG formatter=long Fixed in these patches: commit c7abe2cc423528c0a5a2f9ba7daf6406507671a0 Author: Nir Soffer <nsoffer> Date: Sat Aug 11 20:36:23 2018 +0300 logging: Show client address in [tickets] info logs Move tickets logs to the Tickets application, so we can log the client address. Currently this is always [local], but this make the log more consistent and with Images logs. Here is an example log: 2018-08-11 20:45:57,567 INFO (Thread-1) [tickets] [local] ADD ticket={u'ops': [u'read', u'write'], u'size': 18446744073709551616L, u'timeout': 300, u'uuid': u'ed5af028-4b7a-4cdf-aeaa-96b96689166d', u'url': u'file:///var/run/vdsm/storage/foo'} This change also improves the log for adding ticket to show the client request instead of the parsed ticket, which is intended for debugging. Change-Id: I239633da1a4811ab19bbc5d6ee2596b91c08d245 Bug-Url: https://bugzilla.redhat.com/1614202 Signed-off-by: Nir Soffer <nsoffer> commit 893822b0dd380c28e81492c9598f114f9234ecb1 Author: Nir Soffer <nsoffer> Date: Sat Aug 11 20:16:42 2018 +0300 logging: Include client address in application logs Now that [web] logs are only available in debug level, the client address is not available in the logs. Add the client address to the application logs. Here is an example application log: 2018-08-11 20:18:58,935 INFO (Thread-124) [images] [127.0.0.1] WRITE size=4 offset=0 flush=True ticket=62611b0a-18a6-49ee-9139-7e4b61b6879b Change-Id: I6f1f420a1f31d439b3822a0d8b6a9d22a2d57d1e Bug-Url: https://bugzilla.redhat.com/1614202 Signed-off-by: Nir Soffer <nsoffer> commit 2a850b46f36d20447991524b607933ae90ec6316 Author: Nir Soffer <nsoffer> Date: Fri Aug 10 03:47:10 2018 +0300 logging: Remove path=/path/to/image from images logs We can have 5000 requests for same transfer, so it does not make sense to log the image path for every request. We log the path for every ticket when adding a ticket, and there is no need to repeat this info again. Because oVirt image paths are very long, this reduces the amount of data for single 6G virt-v2v import by half: version size ------------------- with path 677K no path 331K Change-Id: I2c81084bce78e546f7d03d5d8eb9ccdd45926288 Bug-Url: https://bugzilla.redhat.com/1614202 Signed-off-by: Nir Soffer <nsoffer> commit caab48d18e0f3ecd08efb743b593599f642c5ad3 Author: Nir Soffer <nsoffer> Date: Fri Aug 10 03:45:07 2018 +0300 logging: Add OPTIONS log Now that we don't have START and FINISH logs in the default log level, we need application level log for OPTIONS request. Here is an example of the new log: 2018-08-10 04:04:54,543 INFO (Thread-3) [images] OPTIONS ticket=b3a62556-8dd9-4692-8397-d0247952c5dd Change-Id: Ia09887fad70d8b559c2bc81289e4ebc980ccb9a8 Bug-Url: https://bugzilla.redhat.com/1614202 Signed-off-by: Nir Soffer <nsoffer> commit 7225e7287f7ec976cedbb125fdd97b49a8fca1e8 Author: Nir Soffer <nsoffer> Date: Fri Aug 10 02:02:45 2018 +0300 logging: Change [web] logs to debug level We have 3 logs for every request: 2018-08-10 03:02:34,740 INFO (Thread-4) [web] START [local] PATCH /images/8a38a6ce-fd5d-48d6-9c9c-0b27fd8a9f91 2018-08-10 03:02:34,741 INFO (Thread-4) [images] ZERO size=33554432 offset=201326592 flush=False path=/path/to/image ticket=8a38a6ce-fd5d-48d6-9c9c-0b27fd8a9f91 2018-08-10 03:02:35,158 INFO (Thread-4) [web] FINISH [local] PATCH /images/8a38a6ce-fd5d-48d6-9c9c-0b27fd8a9f91 [200] 0 [request=0.418138, operation=0.417035, write=0.415888] The START log is pretty useless normally, but can be handy when we get stuck on unresponsive storage. The FINISH log is important for understanding how time was spent during the request. This was very valuable for improving concurrency. However both logs are not useful for production, and they are responsible for 66% of the logs we generate during virt-v2v import. Here are logs for virt-v2v import of 6G sparse Fedora 27 image: version lines size ---------------------------------- with web logs 7100 1.40M no web logs 2336 0.66M Change [web] logs to debug level, so now we have one log per request. Change-Id: Ib83fb1fe98a592e245b047f88b4ec9abe40c4554 Bug-Url: https://bugzilla.redhat.com/1614202 Signed-off-by: Nir Soffer <nsoffer>
Moving to urgent, since without these changes it is very likely to loose virt-v2v import logs because of rotation. Without logs, we will not be able to debug issues in the field.
We're releasing today 4.2.6 RC2 including v1.4.3 which is referencing this bug. can you please check this bug status?
(In reply to Sandro Bonazzola from comment #6) Bug should be fixed in 1.4.3, but not tested by QE yet.
We have a downstream build, moving to ON_QA
Verified on: ovirt-imageio-daemon-1.4.4-0.el7ev.noarch RHV 4.2.6-4