test_logfile.py 20 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614
  1. # Copyright (c) Twisted Matrix Laboratories.
  2. # See LICENSE for details.
  3. from __future__ import division, absolute_import
  4. import contextlib
  5. import errno
  6. import os
  7. import pickle
  8. import stat
  9. import time
  10. from twisted.trial import unittest
  11. from twisted.python import logfile, runtime
  12. class LogFileTests(unittest.TestCase):
  13. """
  14. Test the rotating log file.
  15. """
  16. def setUp(self):
  17. self.dir = self.mktemp()
  18. os.makedirs(self.dir)
  19. self.name = "test.log"
  20. self.path = os.path.join(self.dir, self.name)
  21. def tearDown(self):
  22. """
  23. Restore back write rights on created paths: if tests modified the
  24. rights, that will allow the paths to be removed easily afterwards.
  25. """
  26. os.chmod(self.dir, 0o777)
  27. if os.path.exists(self.path):
  28. os.chmod(self.path, 0o777)
  29. def test_abstractShouldRotate(self):
  30. """
  31. L{BaseLogFile.shouldRotate} is abstract and must be implemented by
  32. subclass.
  33. """
  34. log = logfile.BaseLogFile(self.name, self.dir)
  35. self.addCleanup(log.close)
  36. self.assertRaises(NotImplementedError, log.shouldRotate)
  37. def test_writing(self):
  38. """
  39. Log files can be written to, flushed and closed. Closing a log file
  40. also flushes it.
  41. """
  42. with contextlib.closing(logfile.LogFile(self.name, self.dir)) as log:
  43. log.write("123")
  44. log.write("456")
  45. log.flush()
  46. log.write("7890")
  47. with open(self.path) as f:
  48. self.assertEqual(f.read(), "1234567890")
  49. def test_rotation(self):
  50. """
  51. Rotating log files autorotate after a period of time, and can also be
  52. manually rotated.
  53. """
  54. # this logfile should rotate every 10 bytes
  55. with contextlib.closing(
  56. logfile.LogFile(self.name, self.dir, rotateLength=10)) as log:
  57. # test automatic rotation
  58. log.write("123")
  59. log.write("4567890")
  60. log.write("1" * 11)
  61. self.assertTrue(os.path.exists("{0}.1".format(self.path)))
  62. self.assertFalse(os.path.exists("{0}.2".format(self.path)))
  63. log.write('')
  64. self.assertTrue(os.path.exists("{0}.1".format(self.path)))
  65. self.assertTrue(os.path.exists("{0}.2".format(self.path)))
  66. self.assertFalse(os.path.exists("{0}.3".format(self.path)))
  67. log.write("3")
  68. self.assertFalse(os.path.exists("{0}.3".format(self.path)))
  69. # test manual rotation
  70. log.rotate()
  71. self.assertTrue(os.path.exists("{0}.3".format(self.path)))
  72. self.assertFalse(os.path.exists("{0}.4".format(self.path)))
  73. self.assertEqual(log.listLogs(), [1, 2, 3])
  74. def test_append(self):
  75. """
  76. Log files can be written to, closed. Their size is the number of
  77. bytes written to them. Everything that was written to them can
  78. be read, even if the writing happened on separate occasions,
  79. and even if the log file was closed in between.
  80. """
  81. with contextlib.closing(logfile.LogFile(self.name, self.dir)) as log:
  82. log.write("0123456789")
  83. log = logfile.LogFile(self.name, self.dir)
  84. self.addCleanup(log.close)
  85. self.assertEqual(log.size, 10)
  86. self.assertEqual(log._file.tell(), log.size)
  87. log.write("abc")
  88. self.assertEqual(log.size, 13)
  89. self.assertEqual(log._file.tell(), log.size)
  90. f = log._file
  91. f.seek(0, 0)
  92. self.assertEqual(f.read(), "0123456789abc")
  93. def test_logReader(self):
  94. """
  95. Various tests for log readers.
  96. First of all, log readers can get logs by number and read what
  97. was written to those log files. Getting nonexistent log files
  98. raises C{ValueError}. Using anything other than an integer
  99. index raises C{TypeError}. As logs get older, their log
  100. numbers increase.
  101. """
  102. log = logfile.LogFile(self.name, self.dir)
  103. self.addCleanup(log.close)
  104. log.write("abc\n")
  105. log.write("def\n")
  106. log.rotate()
  107. log.write("ghi\n")
  108. log.flush()
  109. # check reading logs
  110. self.assertEqual(log.listLogs(), [1])
  111. with contextlib.closing(log.getCurrentLog()) as reader:
  112. reader._file.seek(0)
  113. self.assertEqual(reader.readLines(), ["ghi\n"])
  114. self.assertEqual(reader.readLines(), [])
  115. with contextlib.closing(log.getLog(1)) as reader:
  116. self.assertEqual(reader.readLines(), ["abc\n", "def\n"])
  117. self.assertEqual(reader.readLines(), [])
  118. # check getting illegal log readers
  119. self.assertRaises(ValueError, log.getLog, 2)
  120. self.assertRaises(TypeError, log.getLog, "1")
  121. # check that log numbers are higher for older logs
  122. log.rotate()
  123. self.assertEqual(log.listLogs(), [1, 2])
  124. with contextlib.closing(log.getLog(1)) as reader:
  125. reader._file.seek(0)
  126. self.assertEqual(reader.readLines(), ["ghi\n"])
  127. self.assertEqual(reader.readLines(), [])
  128. with contextlib.closing(log.getLog(2)) as reader:
  129. self.assertEqual(reader.readLines(), ["abc\n", "def\n"])
  130. self.assertEqual(reader.readLines(), [])
  131. def test_LogReaderReadsZeroLine(self):
  132. """
  133. L{LogReader.readLines} supports reading no line.
  134. """
  135. # We don't need any content, just a file path that can be opened.
  136. with open(self.path, "w"):
  137. pass
  138. reader = logfile.LogReader(self.path)
  139. self.addCleanup(reader.close)
  140. self.assertEqual([], reader.readLines(0))
  141. def test_modePreservation(self):
  142. """
  143. Check rotated files have same permissions as original.
  144. """
  145. open(self.path, "w").close()
  146. os.chmod(self.path, 0o707)
  147. mode = os.stat(self.path)[stat.ST_MODE]
  148. log = logfile.LogFile(self.name, self.dir)
  149. self.addCleanup(log.close)
  150. log.write("abc")
  151. log.rotate()
  152. self.assertEqual(mode, os.stat(self.path)[stat.ST_MODE])
  153. def test_noPermission(self):
  154. """
  155. Check it keeps working when permission on dir changes.
  156. """
  157. log = logfile.LogFile(self.name, self.dir)
  158. self.addCleanup(log.close)
  159. log.write("abc")
  160. # change permissions so rotation would fail
  161. os.chmod(self.dir, 0o555)
  162. # if this succeeds, chmod doesn't restrict us, so we can't
  163. # do the test
  164. try:
  165. f = open(os.path.join(self.dir,"xxx"), "w")
  166. except (OSError, IOError):
  167. pass
  168. else:
  169. f.close()
  170. return
  171. log.rotate() # this should not fail
  172. log.write("def")
  173. log.flush()
  174. f = log._file
  175. self.assertEqual(f.tell(), 6)
  176. f.seek(0, 0)
  177. self.assertEqual(f.read(), "abcdef")
  178. def test_maxNumberOfLog(self):
  179. """
  180. Test it respect the limit on the number of files when maxRotatedFiles
  181. is not None.
  182. """
  183. log = logfile.LogFile(self.name, self.dir, rotateLength=10,
  184. maxRotatedFiles=3)
  185. self.addCleanup(log.close)
  186. log.write("1" * 11)
  187. log.write("2" * 11)
  188. self.assertTrue(os.path.exists("{0}.1".format(self.path)))
  189. log.write("3" * 11)
  190. self.assertTrue(os.path.exists("{0}.2".format(self.path)))
  191. log.write("4" * 11)
  192. self.assertTrue(os.path.exists("{0}.3".format(self.path)))
  193. with open("{0}.3".format(self.path)) as fp:
  194. self.assertEqual(fp.read(), "1" * 11)
  195. log.write("5" * 11)
  196. with open("{0}.3".format(self.path)) as fp:
  197. self.assertEqual(fp.read(), "2" * 11)
  198. self.assertFalse(os.path.exists("{0}.4".format(self.path)))
  199. def test_fromFullPath(self):
  200. """
  201. Test the fromFullPath method.
  202. """
  203. log1 = logfile.LogFile(self.name, self.dir, 10, defaultMode=0o777)
  204. self.addCleanup(log1.close)
  205. log2 = logfile.LogFile.fromFullPath(self.path, 10, defaultMode=0o777)
  206. self.addCleanup(log2.close)
  207. self.assertEqual(log1.name, log2.name)
  208. self.assertEqual(os.path.abspath(log1.path), log2.path)
  209. self.assertEqual(log1.rotateLength, log2.rotateLength)
  210. self.assertEqual(log1.defaultMode, log2.defaultMode)
  211. def test_defaultPermissions(self):
  212. """
  213. Test the default permission of the log file: if the file exist, it
  214. should keep the permission.
  215. """
  216. with open(self.path, "wb"):
  217. os.chmod(self.path, 0o707)
  218. currentMode = stat.S_IMODE(os.stat(self.path)[stat.ST_MODE])
  219. log1 = logfile.LogFile(self.name, self.dir)
  220. self.assertEqual(stat.S_IMODE(os.stat(self.path)[stat.ST_MODE]),
  221. currentMode)
  222. self.addCleanup(log1.close)
  223. def test_specifiedPermissions(self):
  224. """
  225. Test specifying the permissions used on the log file.
  226. """
  227. log1 = logfile.LogFile(self.name, self.dir, defaultMode=0o066)
  228. self.addCleanup(log1.close)
  229. mode = stat.S_IMODE(os.stat(self.path)[stat.ST_MODE])
  230. if runtime.platform.isWindows():
  231. # The only thing we can get here is global read-only
  232. self.assertEqual(mode, 0o444)
  233. else:
  234. self.assertEqual(mode, 0o066)
  235. def test_reopen(self):
  236. """
  237. L{logfile.LogFile.reopen} allows to rename the currently used file and
  238. make L{logfile.LogFile} create a new file.
  239. """
  240. with contextlib.closing(logfile.LogFile(self.name, self.dir)) as log1:
  241. log1.write("hello1")
  242. savePath = os.path.join(self.dir, "save.log")
  243. os.rename(self.path, savePath)
  244. log1.reopen()
  245. log1.write("hello2")
  246. with open(self.path) as f:
  247. self.assertEqual(f.read(), "hello2")
  248. with open(savePath) as f:
  249. self.assertEqual(f.read(), "hello1")
  250. if runtime.platform.isWindows():
  251. test_reopen.skip = "Can't test reopen on Windows"
  252. def test_nonExistentDir(self):
  253. """
  254. Specifying an invalid directory to L{LogFile} raises C{IOError}.
  255. """
  256. e = self.assertRaises(
  257. IOError, logfile.LogFile, self.name, 'this_dir_does_not_exist')
  258. self.assertEqual(e.errno, errno.ENOENT)
  259. def test_persistence(self):
  260. """
  261. L{LogFile} objects can be pickled and unpickled, which preserves all
  262. the various attributes of the log file.
  263. """
  264. rotateLength = 12345
  265. defaultMode = 0o642
  266. maxRotatedFiles = 42
  267. with contextlib.closing(
  268. logfile.LogFile(self.name, self.dir,
  269. rotateLength, defaultMode,
  270. maxRotatedFiles)) as log:
  271. log.write("123")
  272. copy = pickle.loads(pickle.dumps(log))
  273. self.addCleanup(copy.close)
  274. # Check that the unpickled log is the same as the original one.
  275. self.assertEqual(self.name, copy.name)
  276. self.assertEqual(self.dir, copy.directory)
  277. self.assertEqual(self.path, copy.path)
  278. self.assertEqual(rotateLength, copy.rotateLength)
  279. self.assertEqual(defaultMode, copy.defaultMode)
  280. self.assertEqual(maxRotatedFiles, copy.maxRotatedFiles)
  281. self.assertEqual(log.size, copy.size)
  282. def test_cantChangeFileMode(self):
  283. """
  284. Opening a L{LogFile} which can be read and write but whose mode can't
  285. be changed doesn't trigger an error.
  286. """
  287. if runtime.platform.isWindows():
  288. name, directory = "NUL", ""
  289. expectedPath = "NUL"
  290. else:
  291. name, directory = "null", "/dev"
  292. expectedPath = "/dev/null"
  293. log = logfile.LogFile(name, directory, defaultMode=0o555)
  294. self.addCleanup(log.close)
  295. self.assertEqual(log.path, expectedPath)
  296. self.assertEqual(log.defaultMode, 0o555)
  297. def test_listLogsWithBadlyNamedFiles(self):
  298. """
  299. L{LogFile.listLogs} doesn't choke if it encounters a file with an
  300. unexpected name.
  301. """
  302. log = logfile.LogFile(self.name, self.dir)
  303. self.addCleanup(log.close)
  304. with open("{0}.1".format(log.path), "w") as fp:
  305. fp.write("123")
  306. with open("{0}.bad-file".format(log.path), "w") as fp:
  307. fp.write("123")
  308. self.assertEqual([1], log.listLogs())
  309. def test_listLogsIgnoresZeroSuffixedFiles(self):
  310. """
  311. L{LogFile.listLogs} ignores log files which rotated suffix is 0.
  312. """
  313. log = logfile.LogFile(self.name, self.dir)
  314. self.addCleanup(log.close)
  315. for i in range(0, 3):
  316. with open("{0}.{1}".format(log.path, i), "w") as fp:
  317. fp.write("123")
  318. self.assertEqual([1, 2], log.listLogs())
  319. class RiggedDailyLogFile(logfile.DailyLogFile):
  320. _clock = 0.0
  321. def _openFile(self):
  322. logfile.DailyLogFile._openFile(self)
  323. # rig the date to match _clock, not mtime
  324. self.lastDate = self.toDate()
  325. def toDate(self, *args):
  326. if args:
  327. return time.gmtime(*args)[:3]
  328. return time.gmtime(self._clock)[:3]
  329. class DailyLogFileTests(unittest.TestCase):
  330. """
  331. Test rotating log file.
  332. """
  333. def setUp(self):
  334. self.dir = self.mktemp()
  335. os.makedirs(self.dir)
  336. self.name = "testdaily.log"
  337. self.path = os.path.join(self.dir, self.name)
  338. def test_writing(self):
  339. """
  340. A daily log file can be written to like an ordinary log file.
  341. """
  342. with contextlib.closing(RiggedDailyLogFile(self.name, self.dir)) as log:
  343. log.write("123")
  344. log.write("456")
  345. log.flush()
  346. log.write("7890")
  347. with open(self.path) as f:
  348. self.assertEqual(f.read(), "1234567890")
  349. def test_rotation(self):
  350. """
  351. Daily log files rotate daily.
  352. """
  353. log = RiggedDailyLogFile(self.name, self.dir)
  354. self.addCleanup(log.close)
  355. days = [(self.path + '.' + log.suffix(day * 86400)) for day in range(3)]
  356. # test automatic rotation
  357. log._clock = 0.0 # 1970/01/01 00:00.00
  358. log.write("123")
  359. log._clock = 43200 # 1970/01/01 12:00.00
  360. log.write("4567890")
  361. log._clock = 86400 # 1970/01/02 00:00.00
  362. log.write("1" * 11)
  363. self.assertTrue(os.path.exists(days[0]))
  364. self.assertFalse(os.path.exists(days[1]))
  365. log._clock = 172800 # 1970/01/03 00:00.00
  366. log.write('')
  367. self.assertTrue(os.path.exists(days[0]))
  368. self.assertTrue(os.path.exists(days[1]))
  369. self.assertFalse(os.path.exists(days[2]))
  370. log._clock = 259199 # 1970/01/03 23:59.59
  371. log.write("3")
  372. self.assertFalse(os.path.exists(days[2]))
  373. def test_getLog(self):
  374. """
  375. Test retrieving log files with L{DailyLogFile.getLog}.
  376. """
  377. data = ["1\n", "2\n", "3\n"]
  378. log = RiggedDailyLogFile(self.name, self.dir)
  379. self.addCleanup(log.close)
  380. for d in data:
  381. log.write(d)
  382. log.flush()
  383. # This returns the current log file.
  384. r = log.getLog(0.0)
  385. self.addCleanup(r.close)
  386. self.assertEqual(data, r.readLines())
  387. # We can't get this log, it doesn't exist yet.
  388. self.assertRaises(ValueError, log.getLog, 86400)
  389. log._clock = 86401 # New day
  390. r.close()
  391. log.rotate()
  392. r = log.getLog(0) # We get the previous log
  393. self.addCleanup(r.close)
  394. self.assertEqual(data, r.readLines())
  395. def test_rotateAlreadyExists(self):
  396. """
  397. L{DailyLogFile.rotate} doesn't do anything if they new log file already
  398. exists on the disk.
  399. """
  400. log = RiggedDailyLogFile(self.name, self.dir)
  401. self.addCleanup(log.close)
  402. # Build a new file with the same name as the file which would be created
  403. # if the log file is to be rotated.
  404. newFilePath = "{0}.{1}".format(log.path, log.suffix(log.lastDate))
  405. with open(newFilePath, "w") as fp:
  406. fp.write("123")
  407. previousFile = log._file
  408. log.rotate()
  409. self.assertEqual(previousFile, log._file)
  410. def test_rotatePermissionDirectoryNotOk(self):
  411. """
  412. L{DailyLogFile.rotate} doesn't do anything if the directory containing
  413. the log files can't be written to.
  414. """
  415. log = logfile.DailyLogFile(self.name, self.dir)
  416. self.addCleanup(log.close)
  417. os.chmod(log.directory, 0o444)
  418. # Restore permissions so tests can be cleaned up.
  419. self.addCleanup(os.chmod, log.directory, 0o755)
  420. previousFile = log._file
  421. log.rotate()
  422. self.assertEqual(previousFile, log._file)
  423. if runtime.platform.isWindows():
  424. test_rotatePermissionDirectoryNotOk.skip = (
  425. "Making read-only directories on Windows is too complex for this "
  426. "test to reasonably do.")
  427. def test_rotatePermissionFileNotOk(self):
  428. """
  429. L{DailyLogFile.rotate} doesn't do anything if the log file can't be
  430. written to.
  431. """
  432. log = logfile.DailyLogFile(self.name, self.dir)
  433. self.addCleanup(log.close)
  434. os.chmod(log.path, 0o444)
  435. previousFile = log._file
  436. log.rotate()
  437. self.assertEqual(previousFile, log._file)
  438. def test_toDate(self):
  439. """
  440. Test that L{DailyLogFile.toDate} converts its timestamp argument to a
  441. time tuple (year, month, day).
  442. """
  443. log = logfile.DailyLogFile(self.name, self.dir)
  444. self.addCleanup(log.close)
  445. timestamp = time.mktime((2000, 1, 1, 0, 0, 0, 0, 0, 0))
  446. self.assertEqual((2000, 1, 1), log.toDate(timestamp))
  447. def test_toDateDefaultToday(self):
  448. """
  449. Test that L{DailyLogFile.toDate} returns today's date by default.
  450. By mocking L{time.localtime}, we ensure that L{DailyLogFile.toDate}
  451. returns the first 3 values of L{time.localtime} which is the current
  452. date.
  453. Note that we don't compare the *real* result of L{DailyLogFile.toDate}
  454. to the *real* current date, as there's a slight possibility that the
  455. date changes between the 2 function calls.
  456. """
  457. def mock_localtime(*args):
  458. self.assertEqual((), args)
  459. return list(range(0, 9))
  460. log = logfile.DailyLogFile(self.name, self.dir)
  461. self.addCleanup(log.close)
  462. self.patch(time, "localtime", mock_localtime)
  463. logDate = log.toDate()
  464. self.assertEqual([0, 1, 2], logDate)
  465. def test_toDateUsesArgumentsToMakeADate(self):
  466. """
  467. Test that L{DailyLogFile.toDate} uses its arguments to create a new
  468. date.
  469. """
  470. log = logfile.DailyLogFile(self.name, self.dir)
  471. self.addCleanup(log.close)
  472. date = (2014, 10, 22)
  473. seconds = time.mktime(date + (0,)*6)
  474. logDate = log.toDate(seconds)
  475. self.assertEqual(date, logDate)
  476. def test_persistence(self):
  477. """
  478. L{DailyLogFile} objects can be pickled and unpickled, which preserves
  479. all the various attributes of the log file.
  480. """
  481. defaultMode = 0o642
  482. log = logfile.DailyLogFile(self.name, self.dir,
  483. defaultMode)
  484. self.addCleanup(log.close)
  485. log.write("123")
  486. # Check that the unpickled log is the same as the original one.
  487. copy = pickle.loads(pickle.dumps(log))
  488. self.addCleanup(copy.close)
  489. self.assertEqual(self.name, copy.name)
  490. self.assertEqual(self.dir, copy.directory)
  491. self.assertEqual(self.path, copy.path)
  492. self.assertEqual(defaultMode, copy.defaultMode)
  493. self.assertEqual(log.lastDate, copy.lastDate)