When mozharness uploads files to S3, we currently don't get any logging from the taskcluster client. This would be helpful for determining when retries are triggered, and for what reasons. I've tried a bit to see if I could hook up the log object in taskcluster-client to the LogMixin in mozharness, but they seem to be incompatible. If that sounds wrong and it should be easy, let me know! Currently I am thinking of just setting DEBUG_TASKCLUSTER_CLIENT=1 in the environment, though I don't know if that will be too noisy and/or too jarring if it doesn't include the usual mozharness log timestamp header.

This just enables logging for taskcluster-client to stdout, which should help if we hit any errors trying to upload artifacts. We can tie it into mozharness' logger if/when we support that in the future. The tc-client version is upgraded to 0.0.14, which has the fixes for not logging the credentials, and not logging duplicate lines.

Comment on attachment 8574988 [details] [diff] [review] logging Review of attachment 8574988 [details] [diff] [review]: ----------------------------------------------------------------- so we are about to land this: https://bugzilla.mozilla.org/attachment.cgi?id=8571877&action=edit which if you search for the log.py changes, we are adding a root logger that should pick up all the python logging in the script and give it mozharness logging style. I wonder how your patch is going to work with it. Will it conflict? Will mgerva's patch aid this one and give you mh time stamps? I'm leaning on the side of testing these patches together before landing this one since the other one is in flight.

I had to make a few minor tweaks to the logger for this to work, but the TC client now ties in to mozharness logging, which is what I wanted :) 1) Pull in new taskcluster-client.py, so we aren't logging the credentials 2) Set the taskcluster logging to DEBUG, since most of the messages in tc-client are debug 3) Remove the .setLevel() calls on the logger handlers. These essentially put a hard limit on what the lower level loggers can be set to. 4) (cleanup) - Removed logger_name parameter from new_logger(), since it's no longer used as far as I can tell.

Comment on attachment 8576182 [details] [diff] [review] logging Review of attachment 8576182 [details] [diff] [review]: ----------------------------------------------------------------- I think we are good to try this in the wild :) ::: mozharness/base/log.py @@ -308,5 @@ > > def add_console_handler(self, log_level=None, log_format=None, > date_format=None): > console_handler = logging.StreamHandler() > - console_handler.setLevel(self.get_logger_level(log_level)) so by removing this, what will the streamhandler level be set to? I know you set it in the TC case, but I'm assuming there will be a default for everything else. I'm wondering if we are going to get more or less output from running commands? I guess there is no harm in trying it out. ::: mozharness/mozilla/building/buildbase.py @@ +1280,5 @@ > self.activate_virtualenv() > > + # Enable Taskcluster debug logging, so at least we get some debug > + # messages while we are testing uploads. > + logging.getLogger('taskcluster').setLevel(logging.DEBUG) neat. Though, since you care about debug logging on the client side of things in mh, maybe taskcluster should be logging info lines instead of debug for the parts you care about?

(In reply to Jordan Lund (:jlund) from comment #4) > > def add_console_handler(self, log_level=None, log_format=None, > > date_format=None): > > console_handler = logging.StreamHandler() > > - console_handler.setLevel(self.get_logger_level(log_level)) > > so by removing this, what will the streamhandler level be set to? I know you > set it in the TC case, but I'm assuming there will be a default for > everything else. I'm wondering if we are going to get more or less output > from running commands? I guess there is no harm in trying it out. The streamhandler (Handler object) level will be unset, which means it processes all messages that come to it. However, we still have the setLevel on the root logger (Logger object): self.logger = ROOT_LOGGER self.logger.setLevel(self.get_logger_level()) So the Logger object prunes all messages lower than our default level (INFO), and passes them on to the Handler objects, which now take everything. I think the idea is you could have different handlers with different log levels, so for example maybe you have DEBUG messages being printed to the screen, but you want a separate file handler that keeps only the ERROR messages so as to not fill up a disk with debug-spew. For us we don't seem to need the separate levels on the handlers, and it prevents us from setting a lower threshold lower down the logger hierarchy. This post may help a bit: http://stackoverflow.com/questions/17668633/what-is-the-point-of-setlevel-in-a-python-logging-handler I don't think this will change the amount of messages in our logs, except for the new taskcluster-client messages. If it does I'm clearly misunderstanding something! > > ::: mozharness/mozilla/building/buildbase.py > @@ +1280,5 @@ > > self.activate_virtualenv() > > > > + # Enable Taskcluster debug logging, so at least we get some debug > > + # messages while we are testing uploads. > > + logging.getLogger('taskcluster').setLevel(logging.DEBUG) > > neat. Though, since you care about debug logging on the client side of > things in mh, maybe taskcluster should be logging info lines instead of > debug for the parts you care about? I think we'll want to switch from DEBUG to just INFO (so, delete this line and use the default) after we're confident that uploads are working consistently. Right now we just want as much info as possible in case something goes wrong so we can debug it.

Comment on attachment 8576182 [details] [diff] [review] logging https://hg.mozilla.org/build/mozharness/rev/27b7e35e1995

mozharness production tag moved to: https://hg.mozilla.org/build/mozharness/rev/d35bfd399151