Bug 1614202

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.

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>

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.

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