Bogus "Duplicate keyval label" messages showing up in inventory logs
Reported by
jrbarnette@chromium.org,
Nov 29 2017
|
||
Issue description
In recent lab inventory run logs, there are messages like this:
2017-11-27 06:29:59 | WARNING | Duplicate keyval label 'board_freq_mem:swanky_2.6GHz_4GB' (current map OrderedDict([('pool', 'bvt'), ('graphics', 'gl'), ('ec', 'cros'), ('storage', 'mmc'), ('board', 'swanky'), ('power', 'battery'), ('gpu_family', 'baytrail'), ('board_freq_mem', 'swanky_3.1GHz_2GB')]))
The same kinds of message also show up in the stable version
assignment log files and e-mail.
The messages offer no real diagnostic value, and don't
represent a problem worth solving; they're merely worthless
gunk. They should be removed, to make log output more
readable.
,
Nov 30 2017
> I think the email should contain only the output of the scripts, not the logs. ... The "assign_stable_images" script doesn't use logging; it only prints to stdout. Because of that, any code that uses logging will end up writing to stdout (or stderr?), and captured in the e-mail. Mostly, we need it to do that: If something goes wrong, it needs to show up in the e-mail, or we won't ever notice. > And the logs can contain this at debug level. That's what log levels are for. This doesn't belong in the lab inventory logs at any level. The lab inventory script logs at debug level. There are various reasons for this, but one simple one is that if something actually goes wrong, we want those messages in the log file. However, so long as nothing has actually gone wrong, we (well, I, at least) also want the inventory logs to be clean and readable. The current messages are inconsistent with the goal of "no messy log messages unless something really is wrong."
,
Nov 30 2017
I think it should be the job of the inventory script to disable undesired logging, not to remove logging for the sake of the inventory script's unique requirements. Also, when you say this is bogus, does that mean it's valid to have two borad_freq_mem labels? If so, I will need to reevaluate labellib. If not, this is a data integrity issue which should be warned about.
,
Nov 30 2017
> I think it should be the job of the inventory script > to disable undesired logging, [ ... ] That's not feasible. We don't currently distinguish most of the different sources of log messages, so most of them can't be turned off. Even if we were able to do that, it isn't a maintainable solution to say that the inventory script (or any other part of the system) should enumerate the acceptable sources of log messages. > not to remove logging for the sake of the inventory script's > unique requirements. I'm not proposing we make a change merely for the sake of the inventory script. I'm claiming that the message in question has no utility for any purpose, and that consequently, it makes the most sense to delete the message rather than look for more complicated alternatives.
,
Nov 30 2017
> Also, when you say this is bogus, does that mean it's valid to have two
> borad_freq_mem labels?
TTBOMK, for all of the duplicated keys (including board_freq_mem):
A) The intended semantic is such that the labels probably shouldn't
have two different settings, but
B) In practice, the labels are unused, so it doesn't matter.
So, we could suppress the current crop of messages by cleaning
up the database. But, spending time on these messages is a
waste of time: The message doesn't describe an actual error,
so spending time to clean up the database is a waste of effort
that we could save by silencing the message.
> If so, I will need to reevaluate labellib. If not, this is a data integrity issue which should be warned about.
The assumption that "key names are unique within a DUT" isn't true.
Most especially, 'pool' labels aren't required to be unique in all
cases. Uniqueness is expected for some keys, and absolutely
required for other keys (especially "board"), but there's no
universal rule; every key is different.
As for data integrity: If uniqueness actually matters, then
merely logging a warning is still the wrong thing to do. It
doesn't prevent problems from occurring, it doesn't mitigate
problem symptoms, it doesn't guarantee that we'll notice
problems when they occur, and if a problem actually occurs and
we notice it, the message may or may not be useful to debugging.
And of course, if uniqueness doesn't matter, then the message
is just noise.
,
Nov 30 2017
> The assumption that "key names are unique within a DUT" isn't true. Most especially, 'pool' labels aren't required to be unique in all cases. Uniqueness is expected for some keys, and absolutely required for other keys (especially "board"), but there's no universal rule; every key is different. Okay, that's all I need.
,
Dec 2 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/third_party/autotest/+/56db253558c13e2dfc0faf092ed407cceb54689d commit 56db253558c13e2dfc0faf092ed407cceb54689d Author: Richard Barnette <jrbarnette@chromium.org> Date: Sat Dec 02 04:32:42 2017 [autotest] Drop messages regarding duplicate keyval labels. In the util.labellib.LabelsMapping constructor, a warning message would be printed if a DUT's key/value labels included a key with more than one value. The message provides minimal value, the condition warned of isn't necessarily a problem, and the message was showing up in places where it didn't belong. So, drop logging the message. BUG= chromium:789724 TEST=run unit tests Change-Id: I0bac9b4c12131af148a5e3e1260c9c3f49dc1b98 Reviewed-on: https://chromium-review.googlesource.com/798710 Commit-Ready: ChromeOS CL Exonerator Bot <chromiumos-cl-exonerator@appspot.gserviceaccount.com> Tested-by: Richard Barnette <jrbarnette@chromium.org> Reviewed-by: Richard Barnette <jrbarnette@google.com> [modify] https://crrev.com/56db253558c13e2dfc0faf092ed407cceb54689d/utils/labellib.py [modify] https://crrev.com/56db253558c13e2dfc0faf092ed407cceb54689d/utils/labellib_unittest.py
,
Jan 9 2018
|
||
►
Sign in to add a comment |
||
Comment 1 by pprabhu@chromium.org
, Nov 29 2017