webkitpy: Add time output to the start of logging messages.

webkitpy: Add time output to the start of logging messages.

To understand how it is between log messages we should print a human
(and machine) parsable version of the current time.

This is needed to figure out what is going on in
https://crbug.com/734467 but will be generally useful.

Before;
--------------------
webkitpy.common.system.log_utils: [DEBUG] Debug logging enabled.
root: [DEBUG] results_json_value_overrides: {}
root: [WARNING] Output directory exists '/fast/testdir2'
webkitpy.common.system.filesystem: [INFO] Removing contents of /fast/testdir2
webkitpy.layout_tests.merge_results: [DEBUG] Merging following paths:
webkitpy.layout_tests.merge_results: [DEBUG] ['/fast/chrome/src/blah', '/fast/chrome/src/blah']
--------------------

After;
--------------------
2017-06-23 10:39:32,803 - webkitpy.common.system.log_utils: [DEBUG] Debug logging enabled.
2017-06-23 10:39:32,803 - root: [DEBUG] results_json_value_overrides: {}
2017-06-23 10:39:32,804 - root: [WARNING] Output directory exists '/fast/testdir2'
2017-06-23 10:39:32,804 - webkitpy.common.system.filesystem: [INFO] Removing contents of /fast/testdir2
2017-06-23 10:39:32,805 - webkitpy.layout_tests.merge_results: [DEBUG] Merging following paths:
2017-06-23 10:39:32,805 - webkitpy.layout_tests.merge_results: [DEBUG] ['/fast/chrome/src/blah', '/fast/chrome/src/blah']
---------------------

R=qyearsley@chromium.org, jeffcarp@chromium.org, mcgreevy@chromium.org, dpranke@chromium.org
BUG=735297
Review-Url: https://codereview.chromium.org/2948043002
Cr-Commit-Position: refs/heads/master@{#482141}
Committed: https://chromium.googlesource.com/chromium/src/+/02a30eaf8b14d5f9d80f85470c0794ae584b12ff

[mithro, 2017-06-21 05:08:23]

The CQ bit was checked by tansell@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2017-06-21 05:08:42]

Dry run: CQ is trying da patch.

Follow status at:
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[mithro, 2017-06-21 05:08:42]

PTAL.

[commit-bot: I haz the power, 2017-06-21 06:26:32]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-06-21 06:26:33]

Dry run: This issue passed the CQ dry run.

[qyearsley, 2017-06-21 16:42:26]

Nice, supporting adding time output to logging messages seems helpful :-)

https://codereview.chromium.org/2948043002/diff/20001/third_party/WebKit/Tool...
File third_party/WebKit/Tools/Scripts/webkitpy/common/system/log_utils.py
(right):

https://codereview.chromium.org/2948043002/diff/20001/third_party/WebKit/Tool...
third_party/WebKit/Tools/Scripts/webkitpy/common/system/log_utils.py:67:
handlers=None, no_time=False):
It might be a bit clearer to rename this to avoid the double negative; what do
you think?

https://codereview.chromium.org/2948043002/diff/20001/third_party/WebKit/Tool...
third_party/WebKit/Tools/Scripts/webkitpy/common/system/log_utils.py:88: stream
parameter is not used.
Remember to include the time argument here.

[mithro, 2017-06-22 05:33:50]

The CQ bit was checked by tansell@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2017-06-22 05:34:00]

Dry run: CQ is trying da patch.

Follow status at:
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-06-22 06:52:48]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-06-22 06:52:48]

Dry run: This issue passed the CQ dry run.

[mithro, 2017-06-23 00:37:57]

https://codereview.chromium.org/2948043002/diff/20001/third_party/WebKit/Tool...
File third_party/WebKit/Tools/Scripts/webkitpy/common/system/log_utils.py
(right):

https://codereview.chromium.org/2948043002/diff/20001/third_party/WebKit/Tool...
third_party/WebKit/Tools/Scripts/webkitpy/common/system/log_utils.py:67:
handlers=None, no_time=False):
On 2017/06/21 16:42:26, qyearsley wrote:
> It might be a bit clearer to rename this to avoid the double negative; what do
> you think?

Done.

https://codereview.chromium.org/2948043002/diff/20001/third_party/WebKit/Tool...
third_party/WebKit/Tools/Scripts/webkitpy/common/system/log_utils.py:88: stream
parameter is not used.
On 2017/06/21 16:42:26, qyearsley wrote:
> Remember to include the time argument here.

Done.

[mithro, 2017-06-23 00:40:34]

Description was changed from

==========
webkitpy: Add time output to the start of logging messages.

To understand how it is between log messages we should print a human
(and machine) parsable version of the current time.

This is needed to figure out what is going on in
https://crbug.com/734467 but will be generally useful.

R=qyearsley@chromium.org, jeffcarp@chromium.org, mcgreevy@chromium.org,
dpranke@chromium.org
BUG=735297
==========

to

==========
webkitpy: Add time output to the start of logging messages.

To understand how it is between log messages we should print a human
(and machine) parsable version of the current time.

This is needed to figure out what is going on in
https://crbug.com/734467 but will be generally useful.

Before;
--------------------
webkitpy.common.system.log_utils: [DEBUG] Debug logging enabled.
root: [DEBUG] results_json_value_overrides: {}
root: [WARNING] Output directory exists '/fast/testdir2'
webkitpy.common.system.filesystem: [INFO] Removing contents of /fast/testdir2
webkitpy.layout_tests.merge_results: [DEBUG] Merging following paths:
webkitpy.layout_tests.merge_results: [DEBUG] ['/fast/chrome/src/blah',
'/fast/chrome/src/blah']
--------------------

After;
--------------------
2017-06-23 10:39:32,803 - webkitpy.common.system.log_utils: [DEBUG] Debug
logging enabled.
2017-06-23 10:39:32,803 - root: [DEBUG] results_json_value_overrides: {}
2017-06-23 10:39:32,804 - root: [WARNING] Output directory exists
'/fast/testdir2'
2017-06-23 10:39:32,804 - webkitpy.common.system.filesystem: [INFO] Removing
contents of /fast/testdir2
2017-06-23 10:39:32,805 - webkitpy.layout_tests.merge_results: [DEBUG] Merging
following paths:
2017-06-23 10:39:32,805 - webkitpy.layout_tests.merge_results: [DEBUG]
['/fast/chrome/src/blah', '/fast/chrome/src/blah']
---------------------

R=qyearsley@chromium.org, jeffcarp@chromium.org, mcgreevy@chromium.org,
dpranke@chromium.org
BUG=735297
==========

[mithro, 2017-06-23 00:40:55]

I updated the commit message with some example log output.

[qyearsley, 2017-06-23 17:20:09]

On 2017/06/23 00:40:55, mithro wrote:
> I updated the commit message with some example log output.

LGTM

[mithro, 2017-06-24 03:49:14]

The CQ bit was checked by tansell@chromium.org

[commit-bot: I haz the power, 2017-06-24 03:49:17]

CQ is trying da patch.

Follow status at:
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-06-24 07:18:34]

CQ is committing da patch.

Bot data: {"patchset_id": 40001, "attempt_start_ts": 1498276154241720,
"parent_rev": "2c89a25cf7851a3830f884b8d368d3eceacfc018", "commit_rev":
"02a30eaf8b14d5f9d80f85470c0794ae584b12ff"}

[commit-bot: I haz the power, 2017-06-24 07:18:45]

Description was changed from

==========
webkitpy: Add time output to the start of logging messages.

To understand how it is between log messages we should print a human
(and machine) parsable version of the current time.

This is needed to figure out what is going on in
https://crbug.com/734467 but will be generally useful.

Before;
--------------------
webkitpy.common.system.log_utils: [DEBUG] Debug logging enabled.
root: [DEBUG] results_json_value_overrides: {}
root: [WARNING] Output directory exists '/fast/testdir2'
webkitpy.common.system.filesystem: [INFO] Removing contents of /fast/testdir2
webkitpy.layout_tests.merge_results: [DEBUG] Merging following paths:
webkitpy.layout_tests.merge_results: [DEBUG] ['/fast/chrome/src/blah',
'/fast/chrome/src/blah']
--------------------

After;
--------------------
2017-06-23 10:39:32,803 - webkitpy.common.system.log_utils: [DEBUG] Debug
logging enabled.
2017-06-23 10:39:32,803 - root: [DEBUG] results_json_value_overrides: {}
2017-06-23 10:39:32,804 - root: [WARNING] Output directory exists
'/fast/testdir2'
2017-06-23 10:39:32,804 - webkitpy.common.system.filesystem: [INFO] Removing
contents of /fast/testdir2
2017-06-23 10:39:32,805 - webkitpy.layout_tests.merge_results: [DEBUG] Merging
following paths:
2017-06-23 10:39:32,805 - webkitpy.layout_tests.merge_results: [DEBUG]
['/fast/chrome/src/blah', '/fast/chrome/src/blah']
---------------------

R=qyearsley@chromium.org, jeffcarp@chromium.org, mcgreevy@chromium.org,
dpranke@chromium.org
BUG=735297
==========

to

==========
webkitpy: Add time output to the start of logging messages.

To understand how it is between log messages we should print a human
(and machine) parsable version of the current time.

This is needed to figure out what is going on in
https://crbug.com/734467 but will be generally useful.

Before;
--------------------
webkitpy.common.system.log_utils: [DEBUG] Debug logging enabled.
root: [DEBUG] results_json_value_overrides: {}
root: [WARNING] Output directory exists '/fast/testdir2'
webkitpy.common.system.filesystem: [INFO] Removing contents of /fast/testdir2
webkitpy.layout_tests.merge_results: [DEBUG] Merging following paths:
webkitpy.layout_tests.merge_results: [DEBUG] ['/fast/chrome/src/blah',
'/fast/chrome/src/blah']
--------------------

After;
--------------------
2017-06-23 10:39:32,803 - webkitpy.common.system.log_utils: [DEBUG] Debug
logging enabled.
2017-06-23 10:39:32,803 - root: [DEBUG] results_json_value_overrides: {}
2017-06-23 10:39:32,804 - root: [WARNING] Output directory exists
'/fast/testdir2'
2017-06-23 10:39:32,804 - webkitpy.common.system.filesystem: [INFO] Removing
contents of /fast/testdir2
2017-06-23 10:39:32,805 - webkitpy.layout_tests.merge_results: [DEBUG] Merging
following paths:
2017-06-23 10:39:32,805 - webkitpy.layout_tests.merge_results: [DEBUG]
['/fast/chrome/src/blah', '/fast/chrome/src/blah']
---------------------

R=qyearsley@chromium.org, jeffcarp@chromium.org, mcgreevy@chromium.org,
dpranke@chromium.org
BUG=735297

Review-Url: https://codereview.chromium.org/2948043002
Cr-Commit-Position: refs/heads/master@{#482141}
Committed:
https://chromium.googlesource.com/chromium/src/+/02a30eaf8b14d5f9d80f85470c07...
==========

[commit-bot: I haz the power, 2017-06-24 07:18:46]

Committed patchset #3 (id:40001) as
https://chromium.googlesource.com/chromium/src/+/02a30eaf8b14d5f9d80f85470c07...