Adding more logs when reading/writing meta file #1410
Conversation
There was a problem hiding this comment.
I am concerned with the amount of logs this will generate. Is it temporary to find the bug ? Then it can be in a private branch. If you do want this traffic, it feels like belonging to debug (warnings are ok, but all marked as info does not feel like a generic info)
| @@ -256,32 +257,42 @@ def load(volpath): | |||
| """ | |||
| Load and return dictionary from the sidecar | |||
| """ | |||
| logging.info("Load dictionary from sidecar for vol path %s", volpath) | |||
There was a problem hiding this comment.
it feels like a debug, not info. Can you elaborate why do we want it on every log all the time ?
There was a problem hiding this comment.
Mark, the reason I put it as info is the failure cannot hit every time, that is why I want to merge it to master so that every CI run will able to log the enough information that I need. I have more chance to reproduce this issue with needed log.
There was a problem hiding this comment.
so this is for a bug hunting ? Then there should be an issue to roll it back when the bug is found.
I do not think we should print that much information which really has no value outside of catching this bug.
esx_service/utils/kvESX.py
Outdated
| return None | ||
|
|
||
| try: | ||
| return json.loads(kv_str) | ||
| except ValueError: | ||
| # Adding this log for DEBUG | ||
| logging.warning("kv_str from meta file is %s ", kv_str) | ||
| logging.exception("Failed to decode meta-data for %s", volpath) | ||
| logging.warning("load:Dump kv_str from meta file") |
There was a problem hiding this comment.
Do we really need 3 lines in log for that ? Can it be compressed into 1 ? Or 2 (warning and then exception)
esx_service/utils/kvESX.py
Outdated
| @@ -298,7 +310,15 @@ def save(volpath, kv_dict): | |||
| vol_name = vmdk_utils.get_volname_from_vmdk_path(volpath) | |||
| while True: | |||
| try: | |||
| if os.stat(meta_file).st_size > 0: | |||
There was a problem hiding this comment.
I think this block of logging is redundant.
Agreed that this logs are temp and would be removed once we hit the root cause of the issue about the volume metadata being unavailable(either corrupted or empty); do you mind wrapping this lines into a function and call it twice. The only reason being this change is being merged into master.
| @@ -1474,7 +1474,7 @@ def set_vol_opts(name, tenant_name, options): | |||
|
|
|||
| vmdk_path = vmdk_utils.get_vmdk_path(path, vol_name) | |||
|
|
|||
| logging.debug("set_vol_opts: path=%s vmdk_path=%s", path, vmdk_path) | |||
| logging.info("set_vol_opts: path=%s vmdk_path=%s", path, vmdk_path) | |||
There was a problem hiding this comment.
Essentially this log (and the related ones) are meant to be debug itself.
Do you mind filing the issue to revert this change later ?(after we narrow down to reason ... either due to test issue or product issue)
|
Contingent to CI pass and no merge conflicts (not expecting any though) |
lipingxue
force-pushed
the
runci/add_log_in_metadata_rw
branch
from
ab014c3
to
23a992e
Compare
|
CI failure: https://ci.vmware.run/vmware/docker-volume-vsphere/548 @lipingxue tests from test-esx are failing. |
lipingxue
force-pushed
the
runci/add_log_in_metadata_rw
branch
from
23a992e
to
463e775
Compare
pdhamdhere
dismissed
msterin’s stale review
Temp changes. Issue #1419 is filed to revert these changes.
This reverts commit 5205f0c.
* Add log to dump the kv_str reading from meta file. * Add more log when reading/writing meta data file. * Add warning log in load/save meta file if the meta file is empty.
This PR added more logs when reading/writing meta file to triage #1371 . Please review it.