PageRenderTime 32ms CodeModel.GetById 16ms RepoModel.GetById 0ms app.codeStats 0ms

/test/logger/test_logdevice.rb

https://gitlab.com/MichelZuniga/ruby
Ruby | 420 lines | 377 code | 38 blank | 5 comment | 19 complexity | afb99acb6fcf59844d624cd17fe29c73 MD5 | raw file
  1. # coding: US-ASCII
  2. require 'test/unit'
  3. require 'logger'
  4. require 'tempfile'
  5. require 'tmpdir'
  6. require_relative '../ruby/envutil'
  7. class TestLogDevice < Test::Unit::TestCase
  8. class LogExcnRaiser
  9. def write(*arg)
  10. raise 'disk is full'
  11. end
  12. def close
  13. end
  14. def stat
  15. Object.new
  16. end
  17. end
  18. def setup
  19. @tempfile = Tempfile.new("logger")
  20. @tempfile.close
  21. @filename = @tempfile.path
  22. File.unlink(@filename)
  23. end
  24. def teardown
  25. @tempfile.close(true)
  26. end
  27. def d(log, opt = {})
  28. Logger::LogDevice.new(log, opt)
  29. end
  30. def test_initialize
  31. logdev = d(STDERR)
  32. assert_equal(STDERR, logdev.dev)
  33. assert_nil(logdev.filename)
  34. assert_raises(TypeError) do
  35. d(nil)
  36. end
  37. #
  38. logdev = d(@filename)
  39. begin
  40. assert(File.exist?(@filename))
  41. assert(logdev.dev.sync)
  42. assert_equal(@filename, logdev.filename)
  43. logdev.write('hello')
  44. ensure
  45. logdev.close
  46. end
  47. # create logfile whitch is already exist.
  48. logdev = d(@filename)
  49. begin
  50. logdev.write('world')
  51. logfile = File.read(@filename)
  52. assert_equal(2, logfile.split(/\n/).size)
  53. assert_match(/^helloworld$/, logfile)
  54. ensure
  55. logdev.close
  56. end
  57. end
  58. def test_write
  59. r, w = IO.pipe
  60. logdev = d(w)
  61. logdev.write("msg2\n\n")
  62. IO.select([r], nil, nil, 0.1)
  63. w.close
  64. msg = r.read
  65. r.close
  66. assert_equal("msg2\n\n", msg)
  67. #
  68. logdev = d(LogExcnRaiser.new)
  69. class << (stderr = '')
  70. alias write <<
  71. end
  72. $stderr, stderr = stderr, $stderr
  73. begin
  74. assert_nothing_raised do
  75. logdev.write('hello')
  76. end
  77. ensure
  78. logdev.close
  79. $stderr, stderr = stderr, $stderr
  80. end
  81. assert_equal "log writing failed. disk is full\n", stderr
  82. end
  83. def test_close
  84. r, w = IO.pipe
  85. logdev = d(w)
  86. logdev.write("msg2\n\n")
  87. IO.select([r], nil, nil, 0.1)
  88. assert(!w.closed?)
  89. logdev.close
  90. assert(w.closed?)
  91. r.close
  92. end
  93. def test_shifting_size
  94. tmpfile = Tempfile.new([File.basename(__FILE__, '.*'), '_1.log'])
  95. logfile = tmpfile.path
  96. logfile0 = logfile + '.0'
  97. logfile1 = logfile + '.1'
  98. logfile2 = logfile + '.2'
  99. logfile3 = logfile + '.3'
  100. tmpfile.close(true)
  101. File.unlink(logfile) if File.exist?(logfile)
  102. File.unlink(logfile0) if File.exist?(logfile0)
  103. File.unlink(logfile1) if File.exist?(logfile1)
  104. File.unlink(logfile2) if File.exist?(logfile2)
  105. logger = Logger.new(logfile, 4, 100)
  106. logger.error("0" * 15)
  107. assert(File.exist?(logfile))
  108. assert(!File.exist?(logfile0))
  109. logger.error("0" * 15)
  110. assert(File.exist?(logfile0))
  111. assert(!File.exist?(logfile1))
  112. logger.error("0" * 15)
  113. assert(File.exist?(logfile1))
  114. assert(!File.exist?(logfile2))
  115. logger.error("0" * 15)
  116. assert(File.exist?(logfile2))
  117. assert(!File.exist?(logfile3))
  118. logger.error("0" * 15)
  119. assert(!File.exist?(logfile3))
  120. logger.error("0" * 15)
  121. assert(!File.exist?(logfile3))
  122. logger.close
  123. File.unlink(logfile)
  124. File.unlink(logfile0)
  125. File.unlink(logfile1)
  126. File.unlink(logfile2)
  127. tmpfile = Tempfile.new([File.basename(__FILE__, '.*'), '_2.log'])
  128. logfile = tmpfile.path
  129. logfile0 = logfile + '.0'
  130. logfile1 = logfile + '.1'
  131. logfile2 = logfile + '.2'
  132. logfile3 = logfile + '.3'
  133. tmpfile.close(true)
  134. logger = Logger.new(logfile, 4, 150)
  135. logger.error("0" * 15)
  136. assert(File.exist?(logfile))
  137. assert(!File.exist?(logfile0))
  138. logger.error("0" * 15)
  139. assert(!File.exist?(logfile0))
  140. logger.error("0" * 15)
  141. assert(File.exist?(logfile0))
  142. assert(!File.exist?(logfile1))
  143. logger.error("0" * 15)
  144. assert(!File.exist?(logfile1))
  145. logger.error("0" * 15)
  146. assert(File.exist?(logfile1))
  147. assert(!File.exist?(logfile2))
  148. logger.error("0" * 15)
  149. assert(!File.exist?(logfile2))
  150. logger.error("0" * 15)
  151. assert(File.exist?(logfile2))
  152. assert(!File.exist?(logfile3))
  153. logger.error("0" * 15)
  154. assert(!File.exist?(logfile3))
  155. logger.error("0" * 15)
  156. assert(!File.exist?(logfile3))
  157. logger.error("0" * 15)
  158. assert(!File.exist?(logfile3))
  159. logger.close
  160. File.unlink(logfile)
  161. File.unlink(logfile0)
  162. File.unlink(logfile1)
  163. File.unlink(logfile2)
  164. end
  165. def test_shifting_age_variants
  166. logger = Logger.new(@filename, 'daily')
  167. logger.info('daily')
  168. logger.close
  169. logger = Logger.new(@filename, 'weekly')
  170. logger.info('weekly')
  171. logger.close
  172. logger = Logger.new(@filename, 'monthly')
  173. logger.info('monthly')
  174. logger.close
  175. end
  176. def test_shifting_age
  177. # shift_age other than 'daily', 'weekly', and 'monthly' means 'everytime'
  178. yyyymmdd = Time.now.strftime("%Y%m%d")
  179. filename1 = @filename + ".#{yyyymmdd}"
  180. filename2 = @filename + ".#{yyyymmdd}.1"
  181. filename3 = @filename + ".#{yyyymmdd}.2"
  182. begin
  183. logger = Logger.new(@filename, 'now')
  184. assert(File.exist?(@filename))
  185. assert(!File.exist?(filename1))
  186. assert(!File.exist?(filename2))
  187. assert(!File.exist?(filename3))
  188. logger.info("0" * 15)
  189. assert(File.exist?(@filename))
  190. assert(File.exist?(filename1))
  191. assert(!File.exist?(filename2))
  192. assert(!File.exist?(filename3))
  193. logger.warn("0" * 15)
  194. assert(File.exist?(@filename))
  195. assert(File.exist?(filename1))
  196. assert(File.exist?(filename2))
  197. assert(!File.exist?(filename3))
  198. logger.error("0" * 15)
  199. assert(File.exist?(@filename))
  200. assert(File.exist?(filename1))
  201. assert(File.exist?(filename2))
  202. assert(File.exist?(filename3))
  203. ensure
  204. logger.close if logger
  205. [filename1, filename2, filename3].each do |filename|
  206. File.unlink(filename) if File.exist?(filename)
  207. end
  208. end
  209. end
  210. def test_shifting_size_in_multiprocess
  211. tmpfile = Tempfile.new([File.basename(__FILE__, '.*'), '_1.log'])
  212. logfile = tmpfile.path
  213. logfile0 = logfile + '.0'
  214. logfile1 = logfile + '.1'
  215. logfile2 = logfile + '.2'
  216. tmpfile.close(true)
  217. File.unlink(logfile) if File.exist?(logfile)
  218. File.unlink(logfile0) if File.exist?(logfile0)
  219. File.unlink(logfile1) if File.exist?(logfile1)
  220. File.unlink(logfile2) if File.exist?(logfile2)
  221. begin
  222. stderr = run_children(2, [logfile], <<-'END')
  223. logger = Logger.new(ARGV[0], 4, 10)
  224. 10.times do
  225. logger.info '0' * 15
  226. end
  227. END
  228. assert_no_match(/log shifting failed/, stderr)
  229. assert_no_match(/log writing failed/, stderr)
  230. assert_no_match(/log rotation inter-process lock failed/, stderr)
  231. ensure
  232. File.unlink(logfile) if File.exist?(logfile)
  233. File.unlink(logfile0) if File.exist?(logfile0)
  234. File.unlink(logfile1) if File.exist?(logfile1)
  235. File.unlink(logfile2) if File.exist?(logfile2)
  236. end
  237. end
  238. def test_shifting_age_in_multiprocess
  239. yyyymmdd = Time.now.strftime("%Y%m%d")
  240. begin
  241. stderr = run_children(2, [@filename], <<-'END')
  242. logger = Logger.new(ARGV[0], 'now')
  243. 10.times do
  244. logger.info '0' * 15
  245. end
  246. END
  247. assert_no_match(/log shifting failed/, stderr)
  248. assert_no_match(/log writing failed/, stderr)
  249. assert_no_match(/log rotation inter-process lock failed/, stderr)
  250. ensure
  251. Dir.glob("#{@filename}.#{yyyymmdd}{,.[1-9]*}") do |filename|
  252. File.unlink(filename) if File.exist?(filename)
  253. end
  254. end
  255. end
  256. def test_open_logfile_in_multiprocess
  257. tmpfile = Tempfile.new([File.basename(__FILE__, '.*'), '_1.log'])
  258. logfile = tmpfile.path
  259. tmpfile.close(true)
  260. begin
  261. 20.times do
  262. run_children(2, [logfile], <<-'END')
  263. logfile = ARGV[0]
  264. logdev = Logger::LogDevice.new(logfile)
  265. logdev.send(:open_logfile, logfile)
  266. END
  267. assert_equal(1, File.readlines(logfile).grep(/# Logfile created on/).size)
  268. File.unlink(logfile)
  269. end
  270. ensure
  271. File.unlink(logfile) if File.exist?(logfile)
  272. end
  273. end
  274. def test_shifting_size_not_rotate_too_much
  275. logdev0 = d(@filename)
  276. logdev0.__send__(:add_log_header, @tempfile)
  277. header_size = @tempfile.size
  278. message = "*" * 99 + "\n"
  279. shift_size = header_size + message.size * 3 - 1
  280. opt = {shift_age: 1, shift_size: shift_size}
  281. Dir.mktmpdir do |tmpdir|
  282. begin
  283. log = File.join(tmpdir, "log")
  284. logdev1 = d(log, opt)
  285. logdev2 = d(log, opt)
  286. assert_file.identical?(log, logdev1.dev)
  287. assert_file.identical?(log, logdev2.dev)
  288. 3.times{logdev1.write(message)}
  289. assert_file.identical?(log, logdev1.dev)
  290. assert_file.identical?(log, logdev2.dev)
  291. logdev1.write(message)
  292. assert_file.identical?(log, logdev1.dev)
  293. assert_file.identical?(log + ".0", logdev2.dev)
  294. logdev2.write(message)
  295. assert_file.identical?(log, logdev1.dev)
  296. assert_file.identical?(log, logdev2.dev)
  297. logdev1.write(message)
  298. assert_file.identical?(log, logdev1.dev)
  299. assert_file.identical?(log, logdev2.dev)
  300. ensure
  301. logdev1.close if logdev1
  302. logdev2.close if logdev2
  303. end
  304. end
  305. ensure
  306. logdev0.close
  307. end unless /mswin|mingw/ =~ RUBY_PLATFORM
  308. def test_shifting_midnight
  309. Dir.mktmpdir do |tmpdir|
  310. assert_in_out_err([*%W"--disable=gems -rlogger -C#{tmpdir} -"], <<-'end;')
  311. begin
  312. module FakeTime
  313. attr_accessor :now
  314. end
  315. class << Time
  316. prepend FakeTime
  317. end
  318. log = "log"
  319. File.open(log, "w") {}
  320. File.utime(*[Time.mktime(2014, 1, 1, 23, 59, 59)]*2, log)
  321. Time.now = Time.mktime(2014, 1, 2, 23, 59, 59, 999000)
  322. dev = Logger::LogDevice.new(log, shift_age: 'daily')
  323. dev.write("#{Time.now} hello-1\n")
  324. Time.now = Time.mktime(2014, 1, 3, 1, 1, 1)
  325. dev.write("#{Time.now} hello-2\n")
  326. ensure
  327. dev.close
  328. end
  329. end;
  330. bug = '[GH-539]'
  331. log = File.join(tmpdir, "log")
  332. cont = File.read(log)
  333. assert_match(/hello-2/, cont)
  334. assert_not_match(/hello-1/, cont)
  335. assert_file.for(bug).exist?(log+".20140102")
  336. assert_match(/hello-1/, File.read(log+".20140102"), bug)
  337. end
  338. end
  339. def test_shifting_dst_change
  340. Dir.mktmpdir do |tmpdir|
  341. assert_in_out_err([{"TZ"=>"Europe/London"}, *%W"--disable=gems -rlogger -C#{tmpdir} -"], <<-'end;')
  342. begin
  343. module FakeTime
  344. attr_accessor :now
  345. end
  346. class << Time
  347. prepend FakeTime
  348. end
  349. log = "log"
  350. File.open(log, "w") {}
  351. Time.now = Time.mktime(2014, 3, 30, 0, 1, 1)
  352. File.utime(Time.now, Time.now, log)
  353. dev = Logger::LogDevice.new(log, shift_age: 'daily')
  354. dev.write("#{Time.now} hello-1\n")
  355. File.utime(*[Time.mktime(2014, 3, 30, 0, 2, 3)]*2, log)
  356. Time.now = Time.mktime(2014, 3, 31, 0, 1, 1)
  357. File.utime(Time.now, Time.now, log)
  358. dev.write("#{Time.now} hello-2\n")
  359. ensure
  360. dev.close
  361. end
  362. end;
  363. log = File.join(tmpdir, "log")
  364. cont = File.read(log)
  365. assert_match(/hello-2/, cont)
  366. assert_not_match(/hello-1/, cont)
  367. assert_file.exist?(log+".20140330")
  368. end
  369. end if /linux|darwin|freebsd/ =~ RUBY_PLATFORM # borrow from test/ruby/test_time_tz.rb
  370. private
  371. def run_children(n, args, src)
  372. r, w = IO.pipe
  373. [w, *(1..n).map do
  374. f = IO.popen([EnvUtil.rubybin, *%w[--disable=gems -rlogger -], *args], "w", err: w)
  375. f.puts(src)
  376. f
  377. end].each(&:close)
  378. stderr = r.read
  379. r.close
  380. stderr
  381. end
  382. end