test_logger.py 19 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442
  1. import logging
  2. import sys
  3. import pytest
  4. from flexmock import flexmock
  5. from borgmatic import logger as module
  6. @pytest.mark.parametrize('bool_val', (True, 'yes', 'on', '1', 'true', 'True', 1))
  7. def test_to_bool_parses_true_values(bool_val):
  8. assert module.to_bool(bool_val)
  9. @pytest.mark.parametrize('bool_val', (False, 'no', 'off', '0', 'false', 'False', 0))
  10. def test_to_bool_parses_false_values(bool_val):
  11. assert not module.to_bool(bool_val)
  12. def test_to_bool_passes_none_through():
  13. assert module.to_bool(None) is None
  14. def test_interactive_console_false_when_not_isatty(capsys):
  15. with capsys.disabled():
  16. flexmock(module.sys.stderr).should_receive('isatty').and_return(False)
  17. assert module.interactive_console() is False
  18. def test_interactive_console_false_when_TERM_is_dumb(capsys):
  19. with capsys.disabled():
  20. flexmock(module.sys.stderr).should_receive('isatty').and_return(True)
  21. flexmock(module.os.environ).should_receive('get').with_args('TERM').and_return('dumb')
  22. assert module.interactive_console() is False
  23. def test_interactive_console_true_when_isatty_and_TERM_is_not_dumb(capsys):
  24. with capsys.disabled():
  25. flexmock(module.sys.stderr).should_receive('isatty').and_return(True)
  26. flexmock(module.os.environ).should_receive('get').with_args('TERM').and_return('smart')
  27. assert module.interactive_console() is True
  28. def test_should_do_markup_respects_no_color_value():
  29. assert module.should_do_markup(no_color=True, configs={}) is False
  30. def test_should_do_markup_respects_config_value():
  31. assert (
  32. module.should_do_markup(no_color=False, configs={'foo.yaml': {'output': {'color': False}}})
  33. is False
  34. )
  35. def test_should_do_markup_prefers_any_false_config_value():
  36. assert (
  37. module.should_do_markup(
  38. no_color=False,
  39. configs={
  40. 'foo.yaml': {'output': {'color': True}},
  41. 'bar.yaml': {'output': {'color': False}},
  42. },
  43. )
  44. is False
  45. )
  46. def test_should_do_markup_respects_PY_COLORS_environment_variable():
  47. flexmock(module.os.environ).should_receive('get').with_args('PY_COLORS', None).and_return(
  48. 'True'
  49. )
  50. flexmock(module.os.environ).should_receive('get').with_args('NO_COLOR', None).and_return(None)
  51. flexmock(module).should_receive('to_bool').and_return(True)
  52. assert module.should_do_markup(no_color=False, configs={}) is True
  53. def test_should_do_markup_prefers_no_color_value_to_config_value():
  54. assert (
  55. module.should_do_markup(no_color=True, configs={'foo.yaml': {'output': {'color': True}}})
  56. is False
  57. )
  58. def test_should_do_markup_prefers_config_value_to_environment_variables():
  59. flexmock(module.os.environ).should_receive('get').and_return('True')
  60. flexmock(module).should_receive('to_bool').and_return(True)
  61. assert (
  62. module.should_do_markup(no_color=False, configs={'foo.yaml': {'output': {'color': False}}})
  63. is False
  64. )
  65. def test_should_do_markup_prefers_no_color_value_to_environment_variables():
  66. flexmock(module.os.environ).should_receive('get').and_return('True')
  67. flexmock(module).should_receive('to_bool').and_return(True)
  68. assert module.should_do_markup(no_color=True, configs={}) is False
  69. def test_should_do_markup_respects_interactive_console_value():
  70. flexmock(module.os.environ).should_receive('get').and_return(None)
  71. flexmock(module).should_receive('interactive_console').and_return(True)
  72. assert module.should_do_markup(no_color=False, configs={}) is True
  73. def test_should_do_markup_prefers_PY_COLORS_to_interactive_console_value():
  74. flexmock(module.os.environ).should_receive('get').with_args('PY_COLORS', None).and_return(
  75. 'True'
  76. )
  77. flexmock(module.os.environ).should_receive('get').with_args('NO_COLOR', None).and_return(None)
  78. flexmock(module).should_receive('to_bool').and_return(True)
  79. flexmock(module).should_receive('interactive_console').never()
  80. assert module.should_do_markup(no_color=False, configs={}) is True
  81. def test_should_do_markup_prefers_NO_COLOR_to_interactive_console_value():
  82. flexmock(module.os.environ).should_receive('get').with_args('PY_COLORS', None).and_return(None)
  83. flexmock(module.os.environ).should_receive('get').with_args('NO_COLOR', None).and_return('True')
  84. assert module.should_do_markup(no_color=False, configs={}) is False
  85. def test_should_do_markup_respects_NO_COLOR_environment_variable():
  86. flexmock(module.os.environ).should_receive('get').with_args('NO_COLOR', None).and_return('True')
  87. flexmock(module.os.environ).should_receive('get').with_args('PY_COLORS', None).and_return(None)
  88. assert module.should_do_markup(no_color=False, configs={}) is False
  89. def test_should_do_markup_ignores_empty_NO_COLOR_environment_variable():
  90. flexmock(module.os.environ).should_receive('get').with_args('NO_COLOR', None).and_return('')
  91. flexmock(module.os.environ).should_receive('get').with_args('PY_COLORS', None).and_return(None)
  92. flexmock(module).should_receive('interactive_console').and_return(True)
  93. assert module.should_do_markup(no_color=False, configs={}) is True
  94. def test_should_do_markup_prefers_NO_COLOR_to_PY_COLORS():
  95. flexmock(module.os.environ).should_receive('get').with_args('PY_COLORS', None).and_return(
  96. 'True'
  97. )
  98. flexmock(module.os.environ).should_receive('get').with_args('NO_COLOR', None).and_return(
  99. 'SomeValue'
  100. )
  101. assert module.should_do_markup(no_color=False, configs={}) is False
  102. def test_multi_stream_handler_logs_to_handler_for_log_level():
  103. error_handler = flexmock()
  104. error_handler.should_receive('emit').once()
  105. info_handler = flexmock()
  106. multi_handler = module.Multi_stream_handler(
  107. {module.logging.ERROR: error_handler, module.logging.INFO: info_handler}
  108. )
  109. multi_handler.emit(flexmock(levelno=module.logging.ERROR))
  110. def test_console_color_formatter_format_includes_log_message():
  111. flexmock(module).should_receive('add_custom_log_levels')
  112. flexmock(module.logging).ANSWER = module.ANSWER
  113. plain_message = 'uh oh'
  114. record = flexmock(levelno=logging.CRITICAL, msg=plain_message)
  115. colored_message = module.Console_color_formatter().format(record)
  116. assert colored_message != plain_message
  117. assert plain_message in colored_message
  118. def test_color_text_does_not_raise():
  119. module.color_text(module.colorama.Fore.RED, 'hi')
  120. def test_color_text_without_color_does_not_raise():
  121. module.color_text(None, 'hi')
  122. def test_add_logging_level_adds_level_name_and_sets_global_attributes_and_methods():
  123. logger = flexmock()
  124. flexmock(module.logging).should_receive('getLoggerClass').and_return(logger)
  125. flexmock(module.logging).should_receive('addLevelName').with_args(99, 'PLAID')
  126. builtins = flexmock(sys.modules['builtins'])
  127. builtins.should_call('setattr')
  128. builtins.should_receive('setattr').with_args(module.logging, 'PLAID', 99).once()
  129. builtins.should_receive('setattr').with_args(logger, 'plaid', object).once()
  130. builtins.should_receive('setattr').with_args(logging, 'plaid', object).once()
  131. module.add_logging_level('PLAID', 99)
  132. def test_add_logging_level_skips_global_setting_if_already_set():
  133. logger = flexmock()
  134. flexmock(module.logging).should_receive('getLoggerClass').and_return(logger)
  135. flexmock(module.logging).PLAID = 99
  136. flexmock(logger).plaid = flexmock()
  137. flexmock(logging).plaid = flexmock()
  138. flexmock(module.logging).should_receive('addLevelName').never()
  139. builtins = flexmock(sys.modules['builtins'])
  140. builtins.should_call('setattr')
  141. builtins.should_receive('setattr').with_args(module.logging, 'PLAID', 99).never()
  142. builtins.should_receive('setattr').with_args(logger, 'plaid', object).never()
  143. builtins.should_receive('setattr').with_args(logging, 'plaid', object).never()
  144. module.add_logging_level('PLAID', 99)
  145. def test_configure_logging_with_syslog_log_level_probes_for_log_socket_on_linux():
  146. flexmock(module).should_receive('add_custom_log_levels')
  147. flexmock(module.logging).ANSWER = module.ANSWER
  148. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  149. multi_stream_handler.should_receive('setFormatter').once()
  150. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  151. flexmock(module).should_receive('Console_color_formatter')
  152. flexmock(module).should_receive('interactive_console').and_return(False)
  153. flexmock(module.logging).should_receive('basicConfig').with_args(
  154. level=logging.DEBUG, handlers=list
  155. )
  156. flexmock(module.os.path).should_receive('exists').with_args('/dev/log').and_return(True)
  157. syslog_handler = logging.handlers.SysLogHandler()
  158. flexmock(module.logging.handlers).should_receive('SysLogHandler').with_args(
  159. address='/dev/log'
  160. ).and_return(syslog_handler).once()
  161. module.configure_logging(logging.INFO, syslog_log_level=logging.DEBUG)
  162. def test_configure_logging_with_syslog_log_level_probes_for_log_socket_on_macos():
  163. flexmock(module).should_receive('add_custom_log_levels')
  164. flexmock(module.logging).ANSWER = module.ANSWER
  165. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  166. multi_stream_handler.should_receive('setFormatter').once()
  167. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  168. flexmock(module).should_receive('Console_color_formatter')
  169. flexmock(module).should_receive('interactive_console').and_return(False)
  170. flexmock(module.logging).should_receive('basicConfig').with_args(
  171. level=logging.DEBUG, handlers=list
  172. )
  173. flexmock(module.os.path).should_receive('exists').with_args('/dev/log').and_return(False)
  174. flexmock(module.os.path).should_receive('exists').with_args('/var/run/syslog').and_return(True)
  175. syslog_handler = logging.handlers.SysLogHandler()
  176. flexmock(module.logging.handlers).should_receive('SysLogHandler').with_args(
  177. address='/var/run/syslog'
  178. ).and_return(syslog_handler).once()
  179. module.configure_logging(logging.INFO, syslog_log_level=logging.DEBUG)
  180. def test_configure_logging_with_syslog_log_level_probes_for_log_socket_on_freebsd():
  181. flexmock(module).should_receive('add_custom_log_levels')
  182. flexmock(module.logging).ANSWER = module.ANSWER
  183. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  184. multi_stream_handler.should_receive('setFormatter').once()
  185. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  186. flexmock(module).should_receive('Console_color_formatter')
  187. flexmock(module).should_receive('interactive_console').and_return(False)
  188. flexmock(module.logging).should_receive('basicConfig').with_args(
  189. level=logging.DEBUG, handlers=list
  190. )
  191. flexmock(module.os.path).should_receive('exists').with_args('/dev/log').and_return(False)
  192. flexmock(module.os.path).should_receive('exists').with_args('/var/run/syslog').and_return(False)
  193. flexmock(module.os.path).should_receive('exists').with_args('/var/run/log').and_return(True)
  194. syslog_handler = logging.handlers.SysLogHandler()
  195. flexmock(module.logging.handlers).should_receive('SysLogHandler').with_args(
  196. address='/var/run/log'
  197. ).and_return(syslog_handler).once()
  198. module.configure_logging(logging.INFO, syslog_log_level=logging.DEBUG)
  199. def test_configure_logging_without_syslog_log_level_skips_syslog():
  200. flexmock(module).should_receive('add_custom_log_levels')
  201. flexmock(module.logging).ANSWER = module.ANSWER
  202. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  203. multi_stream_handler.should_receive('setFormatter').once()
  204. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  205. flexmock(module).should_receive('Console_color_formatter')
  206. flexmock(module.logging).should_receive('basicConfig').with_args(
  207. level=logging.INFO, handlers=list
  208. )
  209. flexmock(module.os.path).should_receive('exists').never()
  210. flexmock(module.logging.handlers).should_receive('SysLogHandler').never()
  211. module.configure_logging(console_log_level=logging.INFO)
  212. def test_configure_logging_skips_syslog_if_not_found():
  213. flexmock(module).should_receive('add_custom_log_levels')
  214. flexmock(module.logging).ANSWER = module.ANSWER
  215. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  216. multi_stream_handler.should_receive('setFormatter').once()
  217. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  218. flexmock(module).should_receive('Console_color_formatter')
  219. flexmock(module.logging).should_receive('basicConfig').with_args(
  220. level=logging.INFO, handlers=list
  221. )
  222. flexmock(module.os.path).should_receive('exists').and_return(False)
  223. flexmock(module.logging.handlers).should_receive('SysLogHandler').never()
  224. module.configure_logging(console_log_level=logging.INFO, syslog_log_level=logging.DEBUG)
  225. def test_configure_logging_skips_log_file_if_log_file_logging_is_disabled():
  226. flexmock(module).should_receive('add_custom_log_levels')
  227. flexmock(module.logging).DISABLED = module.DISABLED
  228. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  229. multi_stream_handler.should_receive('setFormatter').once()
  230. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  231. flexmock(module.logging).should_receive('basicConfig').with_args(
  232. level=logging.INFO, handlers=list
  233. )
  234. flexmock(module.os.path).should_receive('exists').never()
  235. flexmock(module.logging.handlers).should_receive('SysLogHandler').never()
  236. flexmock(module.logging.handlers).should_receive('WatchedFileHandler').never()
  237. module.configure_logging(
  238. console_log_level=logging.INFO, log_file_log_level=logging.DISABLED, log_file='/tmp/logfile'
  239. )
  240. def test_configure_logging_to_log_file_instead_of_syslog():
  241. flexmock(module).should_receive('add_custom_log_levels')
  242. flexmock(module.logging).ANSWER = module.ANSWER
  243. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  244. multi_stream_handler.should_receive('setFormatter').once()
  245. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  246. flexmock(module.logging).should_receive('basicConfig').with_args(
  247. level=logging.DEBUG, handlers=list
  248. )
  249. flexmock(module.os.path).should_receive('exists').never()
  250. flexmock(module.logging.handlers).should_receive('SysLogHandler').never()
  251. file_handler = logging.handlers.WatchedFileHandler('/tmp/logfile')
  252. flexmock(module.logging.handlers).should_receive('WatchedFileHandler').with_args(
  253. '/tmp/logfile'
  254. ).and_return(file_handler).once()
  255. module.configure_logging(
  256. console_log_level=logging.INFO,
  257. syslog_log_level=logging.DISABLED,
  258. log_file_log_level=logging.DEBUG,
  259. log_file='/tmp/logfile',
  260. )
  261. def test_configure_logging_to_both_log_file_and_syslog():
  262. flexmock(module).should_receive('add_custom_log_levels')
  263. flexmock(module.logging).ANSWER = module.ANSWER
  264. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  265. multi_stream_handler.should_receive('setFormatter').once()
  266. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  267. flexmock(module.logging).should_receive('basicConfig').with_args(
  268. level=logging.DEBUG, handlers=list
  269. )
  270. flexmock(module.os.path).should_receive('exists').with_args('/dev/log').and_return(True)
  271. syslog_handler = logging.handlers.SysLogHandler()
  272. flexmock(module.logging.handlers).should_receive('SysLogHandler').with_args(
  273. address='/dev/log'
  274. ).and_return(syslog_handler).once()
  275. file_handler = logging.handlers.WatchedFileHandler('/tmp/logfile')
  276. flexmock(module.logging.handlers).should_receive('WatchedFileHandler').with_args(
  277. '/tmp/logfile'
  278. ).and_return(file_handler).once()
  279. module.configure_logging(
  280. console_log_level=logging.INFO,
  281. syslog_log_level=logging.DEBUG,
  282. log_file_log_level=logging.DEBUG,
  283. log_file='/tmp/logfile',
  284. )
  285. def test_configure_logging_to_log_file_formats_with_custom_log_format():
  286. flexmock(module).should_receive('add_custom_log_levels')
  287. flexmock(module.logging).ANSWER = module.ANSWER
  288. flexmock(module.logging).should_receive('Formatter').with_args(
  289. '{message}', style='{' # noqa: FS003
  290. ).once()
  291. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  292. multi_stream_handler.should_receive('setFormatter').once()
  293. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  294. flexmock(module).should_receive('interactive_console').and_return(False)
  295. flexmock(module.logging).should_receive('basicConfig').with_args(
  296. level=logging.DEBUG, handlers=list
  297. )
  298. flexmock(module.os.path).should_receive('exists').with_args('/dev/log').and_return(True)
  299. flexmock(module.logging.handlers).should_receive('SysLogHandler').never()
  300. file_handler = logging.handlers.WatchedFileHandler('/tmp/logfile')
  301. flexmock(module.logging.handlers).should_receive('WatchedFileHandler').with_args(
  302. '/tmp/logfile'
  303. ).and_return(file_handler).once()
  304. module.configure_logging(
  305. console_log_level=logging.INFO,
  306. log_file_log_level=logging.DEBUG,
  307. log_file='/tmp/logfile',
  308. log_file_format='{message}', # noqa: FS003
  309. )
  310. def test_configure_logging_skips_log_file_if_argument_is_none():
  311. flexmock(module).should_receive('add_custom_log_levels')
  312. flexmock(module.logging).ANSWER = module.ANSWER
  313. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  314. multi_stream_handler.should_receive('setFormatter').once()
  315. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  316. flexmock(module.logging).should_receive('basicConfig').with_args(
  317. level=logging.INFO, handlers=list
  318. )
  319. flexmock(module.os.path).should_receive('exists').and_return(False)
  320. flexmock(module.logging.handlers).should_receive('WatchedFileHandler').never()
  321. module.configure_logging(console_log_level=logging.INFO, log_file=None)
  322. def test_configure_logging_skips_console_color_formatter_if_color_disabled():
  323. flexmock(module).should_receive('add_custom_log_levels')
  324. flexmock(module.logging).ANSWER = module.ANSWER
  325. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  326. multi_stream_handler.should_receive('setFormatter').never()
  327. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  328. flexmock(module.logging).should_receive('basicConfig').with_args(
  329. level=logging.INFO, handlers=list
  330. )
  331. flexmock(module.os.path).should_receive('exists').and_return(False)
  332. flexmock(module.logging.handlers).should_receive('WatchedFileHandler').never()
  333. module.configure_logging(console_log_level=logging.INFO, log_file=None, color_enabled=False)