test_logger.py 19 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435
  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').and_return(False)
  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. flexmock(module).should_receive('interactive_console').and_return(False)
  85. assert module.should_do_markup(no_color=False, configs={}) is False
  86. def test_should_do_markup_respects_NO_COLOR_environment_variable():
  87. flexmock(module.os.environ).should_receive('get').with_args('NO_COLOR', None).and_return('True')
  88. flexmock(module.os.environ).should_receive('get').with_args('PY_COLORS', None).and_return(None)
  89. assert module.should_do_markup(no_color=False, configs={}) is False
  90. def test_should_do_markup_prefers_NO_COLOR_to_PY_COLORS():
  91. flexmock(module.os.environ).should_receive('get').with_args('PY_COLORS', None).and_return(
  92. 'True'
  93. )
  94. flexmock(module.os.environ).should_receive('get').with_args('NO_COLOR', None).and_return(
  95. 'SomeValue'
  96. )
  97. assert module.should_do_markup(no_color=False, configs={}) is False
  98. def test_multi_stream_handler_logs_to_handler_for_log_level():
  99. error_handler = flexmock()
  100. error_handler.should_receive('emit').once()
  101. info_handler = flexmock()
  102. multi_handler = module.Multi_stream_handler(
  103. {module.logging.ERROR: error_handler, module.logging.INFO: info_handler}
  104. )
  105. multi_handler.emit(flexmock(levelno=module.logging.ERROR))
  106. def test_console_color_formatter_format_includes_log_message():
  107. flexmock(module).should_receive('add_custom_log_levels')
  108. flexmock(module.logging).ANSWER = module.ANSWER
  109. plain_message = 'uh oh'
  110. record = flexmock(levelno=logging.CRITICAL, msg=plain_message)
  111. colored_message = module.Console_color_formatter().format(record)
  112. assert colored_message != plain_message
  113. assert plain_message in colored_message
  114. def test_color_text_does_not_raise():
  115. module.color_text(module.colorama.Fore.RED, 'hi')
  116. def test_color_text_without_color_does_not_raise():
  117. module.color_text(None, 'hi')
  118. def test_add_logging_level_adds_level_name_and_sets_global_attributes_and_methods():
  119. logger = flexmock()
  120. flexmock(module.logging).should_receive('getLoggerClass').and_return(logger)
  121. flexmock(module.logging).should_receive('addLevelName').with_args(99, 'PLAID')
  122. builtins = flexmock(sys.modules['builtins'])
  123. builtins.should_call('setattr')
  124. builtins.should_receive('setattr').with_args(module.logging, 'PLAID', 99).once()
  125. builtins.should_receive('setattr').with_args(logger, 'plaid', object).once()
  126. builtins.should_receive('setattr').with_args(logging, 'plaid', object).once()
  127. module.add_logging_level('PLAID', 99)
  128. def test_add_logging_level_skips_global_setting_if_already_set():
  129. logger = flexmock()
  130. flexmock(module.logging).should_receive('getLoggerClass').and_return(logger)
  131. flexmock(module.logging).PLAID = 99
  132. flexmock(logger).plaid = flexmock()
  133. flexmock(logging).plaid = flexmock()
  134. flexmock(module.logging).should_receive('addLevelName').never()
  135. builtins = flexmock(sys.modules['builtins'])
  136. builtins.should_call('setattr')
  137. builtins.should_receive('setattr').with_args(module.logging, 'PLAID', 99).never()
  138. builtins.should_receive('setattr').with_args(logger, 'plaid', object).never()
  139. builtins.should_receive('setattr').with_args(logging, 'plaid', object).never()
  140. module.add_logging_level('PLAID', 99)
  141. def test_configure_logging_with_syslog_log_level_probes_for_log_socket_on_linux():
  142. flexmock(module).should_receive('add_custom_log_levels')
  143. flexmock(module.logging).ANSWER = module.ANSWER
  144. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  145. multi_stream_handler.should_receive('setFormatter').once()
  146. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  147. flexmock(module).should_receive('Console_color_formatter')
  148. flexmock(module).should_receive('interactive_console').and_return(False)
  149. flexmock(module.logging).should_receive('basicConfig').with_args(
  150. level=logging.DEBUG, handlers=list
  151. )
  152. flexmock(module.os.path).should_receive('exists').with_args('/dev/log').and_return(True)
  153. syslog_handler = logging.handlers.SysLogHandler()
  154. flexmock(module.logging.handlers).should_receive('SysLogHandler').with_args(
  155. address='/dev/log'
  156. ).and_return(syslog_handler).once()
  157. module.configure_logging(logging.INFO, syslog_log_level=logging.DEBUG)
  158. def test_configure_logging_with_syslog_log_level_probes_for_log_socket_on_macos():
  159. flexmock(module).should_receive('add_custom_log_levels')
  160. flexmock(module.logging).ANSWER = module.ANSWER
  161. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  162. multi_stream_handler.should_receive('setFormatter').once()
  163. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  164. flexmock(module).should_receive('Console_color_formatter')
  165. flexmock(module).should_receive('interactive_console').and_return(False)
  166. flexmock(module.logging).should_receive('basicConfig').with_args(
  167. level=logging.DEBUG, handlers=list
  168. )
  169. flexmock(module.os.path).should_receive('exists').with_args('/dev/log').and_return(False)
  170. flexmock(module.os.path).should_receive('exists').with_args('/var/run/syslog').and_return(True)
  171. syslog_handler = logging.handlers.SysLogHandler()
  172. flexmock(module.logging.handlers).should_receive('SysLogHandler').with_args(
  173. address='/var/run/syslog'
  174. ).and_return(syslog_handler).once()
  175. module.configure_logging(logging.INFO, syslog_log_level=logging.DEBUG)
  176. def test_configure_logging_with_syslog_log_level_probes_for_log_socket_on_freebsd():
  177. flexmock(module).should_receive('add_custom_log_levels')
  178. flexmock(module.logging).ANSWER = module.ANSWER
  179. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  180. multi_stream_handler.should_receive('setFormatter').once()
  181. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  182. flexmock(module).should_receive('Console_color_formatter')
  183. flexmock(module).should_receive('interactive_console').and_return(False)
  184. flexmock(module.logging).should_receive('basicConfig').with_args(
  185. level=logging.DEBUG, handlers=list
  186. )
  187. flexmock(module.os.path).should_receive('exists').with_args('/dev/log').and_return(False)
  188. flexmock(module.os.path).should_receive('exists').with_args('/var/run/syslog').and_return(False)
  189. flexmock(module.os.path).should_receive('exists').with_args('/var/run/log').and_return(True)
  190. syslog_handler = logging.handlers.SysLogHandler()
  191. flexmock(module.logging.handlers).should_receive('SysLogHandler').with_args(
  192. address='/var/run/log'
  193. ).and_return(syslog_handler).once()
  194. module.configure_logging(logging.INFO, syslog_log_level=logging.DEBUG)
  195. def test_configure_logging_without_syslog_log_level_skips_syslog():
  196. flexmock(module).should_receive('add_custom_log_levels')
  197. flexmock(module.logging).ANSWER = module.ANSWER
  198. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  199. multi_stream_handler.should_receive('setFormatter').once()
  200. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  201. flexmock(module).should_receive('Console_color_formatter')
  202. flexmock(module.logging).should_receive('basicConfig').with_args(
  203. level=logging.INFO, handlers=list
  204. )
  205. flexmock(module.os.path).should_receive('exists').never()
  206. flexmock(module.logging.handlers).should_receive('SysLogHandler').never()
  207. module.configure_logging(console_log_level=logging.INFO)
  208. def test_configure_logging_skips_syslog_if_not_found():
  209. flexmock(module).should_receive('add_custom_log_levels')
  210. flexmock(module.logging).ANSWER = module.ANSWER
  211. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  212. multi_stream_handler.should_receive('setFormatter').once()
  213. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  214. flexmock(module).should_receive('Console_color_formatter')
  215. flexmock(module.logging).should_receive('basicConfig').with_args(
  216. level=logging.INFO, handlers=list
  217. )
  218. flexmock(module.os.path).should_receive('exists').and_return(False)
  219. flexmock(module.logging.handlers).should_receive('SysLogHandler').never()
  220. module.configure_logging(console_log_level=logging.INFO, syslog_log_level=logging.DEBUG)
  221. def test_configure_logging_skips_log_file_if_log_file_logging_is_disabled():
  222. flexmock(module).should_receive('add_custom_log_levels')
  223. flexmock(module.logging).DISABLED = module.DISABLED
  224. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  225. multi_stream_handler.should_receive('setFormatter').once()
  226. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  227. flexmock(module.logging).should_receive('basicConfig').with_args(
  228. level=logging.INFO, handlers=list
  229. )
  230. flexmock(module.os.path).should_receive('exists').never()
  231. flexmock(module.logging.handlers).should_receive('SysLogHandler').never()
  232. flexmock(module.logging.handlers).should_receive('WatchedFileHandler').never()
  233. module.configure_logging(
  234. console_log_level=logging.INFO, log_file_log_level=logging.DISABLED, log_file='/tmp/logfile'
  235. )
  236. def test_configure_logging_to_log_file_instead_of_syslog():
  237. flexmock(module).should_receive('add_custom_log_levels')
  238. flexmock(module.logging).ANSWER = module.ANSWER
  239. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  240. multi_stream_handler.should_receive('setFormatter').once()
  241. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  242. flexmock(module.logging).should_receive('basicConfig').with_args(
  243. level=logging.DEBUG, handlers=list
  244. )
  245. flexmock(module.os.path).should_receive('exists').never()
  246. flexmock(module.logging.handlers).should_receive('SysLogHandler').never()
  247. file_handler = logging.handlers.WatchedFileHandler('/tmp/logfile')
  248. flexmock(module.logging.handlers).should_receive('WatchedFileHandler').with_args(
  249. '/tmp/logfile'
  250. ).and_return(file_handler).once()
  251. module.configure_logging(
  252. console_log_level=logging.INFO,
  253. syslog_log_level=logging.DISABLED,
  254. log_file_log_level=logging.DEBUG,
  255. log_file='/tmp/logfile',
  256. )
  257. def test_configure_logging_to_both_log_file_and_syslog():
  258. flexmock(module).should_receive('add_custom_log_levels')
  259. flexmock(module.logging).ANSWER = module.ANSWER
  260. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  261. multi_stream_handler.should_receive('setFormatter').once()
  262. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  263. flexmock(module.logging).should_receive('basicConfig').with_args(
  264. level=logging.DEBUG, handlers=list
  265. )
  266. flexmock(module.os.path).should_receive('exists').with_args('/dev/log').and_return(True)
  267. syslog_handler = logging.handlers.SysLogHandler()
  268. flexmock(module.logging.handlers).should_receive('SysLogHandler').with_args(
  269. address='/dev/log'
  270. ).and_return(syslog_handler).once()
  271. file_handler = logging.handlers.WatchedFileHandler('/tmp/logfile')
  272. flexmock(module.logging.handlers).should_receive('WatchedFileHandler').with_args(
  273. '/tmp/logfile'
  274. ).and_return(file_handler).once()
  275. module.configure_logging(
  276. console_log_level=logging.INFO,
  277. syslog_log_level=logging.DEBUG,
  278. log_file_log_level=logging.DEBUG,
  279. log_file='/tmp/logfile',
  280. )
  281. def test_configure_logging_to_log_file_formats_with_custom_log_format():
  282. flexmock(module).should_receive('add_custom_log_levels')
  283. flexmock(module.logging).ANSWER = module.ANSWER
  284. flexmock(module.logging).should_receive('Formatter').with_args(
  285. '{message}', style='{' # noqa: FS003
  286. ).once()
  287. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  288. multi_stream_handler.should_receive('setFormatter').once()
  289. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  290. flexmock(module).should_receive('interactive_console').and_return(False)
  291. flexmock(module.logging).should_receive('basicConfig').with_args(
  292. level=logging.DEBUG, handlers=list
  293. )
  294. flexmock(module.os.path).should_receive('exists').with_args('/dev/log').and_return(True)
  295. flexmock(module.logging.handlers).should_receive('SysLogHandler').never()
  296. file_handler = logging.handlers.WatchedFileHandler('/tmp/logfile')
  297. flexmock(module.logging.handlers).should_receive('WatchedFileHandler').with_args(
  298. '/tmp/logfile'
  299. ).and_return(file_handler).once()
  300. module.configure_logging(
  301. console_log_level=logging.INFO,
  302. log_file_log_level=logging.DEBUG,
  303. log_file='/tmp/logfile',
  304. log_file_format='{message}', # noqa: FS003
  305. )
  306. def test_configure_logging_skips_log_file_if_argument_is_none():
  307. flexmock(module).should_receive('add_custom_log_levels')
  308. flexmock(module.logging).ANSWER = module.ANSWER
  309. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  310. multi_stream_handler.should_receive('setFormatter').once()
  311. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  312. flexmock(module.logging).should_receive('basicConfig').with_args(
  313. level=logging.INFO, handlers=list
  314. )
  315. flexmock(module.os.path).should_receive('exists').and_return(False)
  316. flexmock(module.logging.handlers).should_receive('WatchedFileHandler').never()
  317. module.configure_logging(console_log_level=logging.INFO, log_file=None)
  318. def test_configure_logging_skips_console_color_formatter_if_color_disabled():
  319. flexmock(module).should_receive('add_custom_log_levels')
  320. flexmock(module.logging).ANSWER = module.ANSWER
  321. multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
  322. multi_stream_handler.should_receive('setFormatter').never()
  323. flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
  324. flexmock(module.logging).should_receive('basicConfig').with_args(
  325. level=logging.INFO, handlers=list
  326. )
  327. flexmock(module.os.path).should_receive('exists').and_return(False)
  328. flexmock(module.logging.handlers).should_receive('WatchedFileHandler').never()
  329. module.configure_logging(console_log_level=logging.INFO, log_file=None, color_enabled=False)