Python 记录器格式损坏:I0716 而不是 INFO

Question

由于某种原因，python记录器格式有时有点坏了。我不确定出了什么问题，看起来像编码问题：

I0716 23:27:10.491452 4409853376 tpu_context.py:209] _TPUContext: eval_on_tpu True
W0716 23:27:10.491577 4409853376 tpu_context.py:211] eval_on_tpu ignored because use_tpu is False.
W0716 23:27:10.619174 4409853376 deprecation_wrapper.py:119] From bert-ner.py:423: The name tf.python_io.TFRecordWriter is deprecated. Please use tf.io.TFRecordWriter instead.
W0716 23:27:10.621710 4409853376 deprecation_wrapper.py:119] From bert-ner.py:428: The name tf.logging.info is deprecated. Please use tf.compat.v1.logging.info instead.

它应该看起来像：

INFO ...
INFO ...
WARN ...
WARN ...

脚本的执行方式如下：

subprocess.call('python3 bert-ner.py ...', shell=True)

如何解决这个问题？

Answer 1

Python API

如果只想自定义tensorflow日志记录格式，请替换absl中的格式化程序并tensorflow记录器：

import logging
from absl import logging as absl_logging
import tensorflow as tf

fmt = '[%(levelname)s %(asctime)s %(filename)s:%(lineno)s] %(message)s'
formatter = logging.Formatter(fmt)
absl_logging.get_absl_handler().setFormatter(formatter)
absl_logging.set_verbosity('debug')  # for example
for h in tf.get_logger().handlers:
h.setFormatter(formatter)
tf.compat.v1.logging.set_verbosity(logging.DEBUG)  # for example

# test configuration
if __name__ == '__main__':
# test custom logger if you have one - should also emit in the same format
logging.getLogger(__name__).debug('tf imported')
# this issues a DeprecationWarning in tensorflow>=1.13, emitting a warning log message
s = tf.Session()

脚本发出：

WARNING: Logging before flag parsing goes to stderr.
[DEBUG 2019-07-18 14:03:15,662 eggs.py:20] tf imported
[WARNING 2019-07-18 14:03:15,662 deprecation_wrapper.py:119] From eggs.py:22: The name tf.Session is deprecated. Please use tf.compat.v1.Session instead.
2019-07-18 14:03:15.671392: I tensorflow/core/platform/cpu_feature_guard.cc:142] Your CPU supports instructions that this TensorFlow binary was not compiled to use: AVX2 FMA
2019-07-18 14:03:15.674517: I tensorflow/core/platform/profile_utils/cpu_utils.cc:94] CPU Frequency: 1992000000 Hz
...

C++接口

从 Python 部件发出的日志记录现在具有不同的统一输出。但是，正如您在上面的输出中看到的那样，从C++部件发出的日志不受其影响。不幸的是，截至目前(2019 年 7 月 18 日)，C++代码中的日志格式不可配置，请参阅 implLogMessage::GenerateLogMessage()：

void LogMessage::GenerateLogMessage() {
...
strftime(time_buffer, time_buffer_size, "%Y-%m-%d %H:%M:%S",
localtime(&now_seconds));
// TODO(jeff,sanjay): Replace this with something that logs through the env.
fprintf(stderr, "%s.%06d: %c %s:%d] %sn", time_buffer, micros_remainder,
"IWEF"[severity_], fname_, line_, str().c_str());
}

这意味着除了关闭库C++部分的日志发出之外，您无能为力：

import logging
import os
from absl import logging as absl_logging
import tensorflow as tf
os.environ['TF_CPP_MIN_LOG_LEVEL'] = '3'
...

记录对齐

如果您像我一样不喜欢日志行未正确对齐，请对字符串稍作修改fmt：

fmt = '[%(levelname)8s %(asctime)s %(filename)s:%(lineno)s] %(message)s'

现在输出看起来更具可读性：

[   DEBUG 2019-07-18 14:31:20,097 eggs.py:36] tf imported
[ WARNING 2019-07-18 14:31:20,097 deprecation_wrapper.py:119] From eggs.py:38: The name tf.Session is deprecated. Please use tf.compat.v1.Session instead.

使用微秒和线程 ID

默认abseil处理程序追加到日期的微秒，还包括当前线程的 ID。您也可以这样做 - 线程 ID 由logging模块提供，而微秒必须首先计算(我为此使用了自定义Filter)。重新访问了上面的示例脚本：

import logging
import os
import time
from absl import logging as absl_logging
import tensorflow as tf
os.environ['TF_CPP_MIN_LOG_LEVEL'] = '3'
fmt = '[%(levelname)8s %(asctime)s.%(microsecs)06d %(thread)d %(filename)s:%(lineno)s] %(message)s'
date_fmt = '%Y-%m-%d %H:%M:%S'
formatter = logging.Formatter(fmt, date_fmt)

class FilterMicroseconds(logging.Filter):
def filter(self, record):
local_time = time.localtime(record.created)
record.microsecs = int(record.created % 1.0 * 1e6)
return True
filter_microsecs = FilterMicroseconds()

absl_logging.get_absl_handler().setFormatter(formatter)
absl_logging.get_absl_handler().addFilter(filter_microsecs)
absl_logging.set_verbosity('debug')  # for example
for h in tf.get_logger().handlers:
h.setFormatter(formatter)
h.addFilter(filter_microsecs)
tf.compat.v1.logging.set_verbosity(logging.DEBUG)  # for example

# test configuration
if __name__ == '__main__':
# test custom logger if you have one - should also emit in the same format
logging.getLogger(__name__).debug('tf imported')
# this issues a DeprecationWarning in tensorflow>=1.13, emitting a warning log message
s = tf.Session()

输出：

WARNING: Logging before flag parsing goes to stderr.
[   DEBUG 2019-07-18 14:39:04.522035 140546459115328 eggs.py:36] tf imported
[ WARNING 2019-07-18 14:39:04.522186 140546459115328 deprecation_wrapper.py:119] From eggs.py:38: The name tf.Session is deprecated. Please use tf.compat.v1.Session instead.