[ruby-core:58788] [ruby-trunk - Bug #9130] logger continues to write in old log file after rotation

Issue #9130 has been updated by no6v (Nobuhiro IMAI).


nagachika (Tomoyuki Chikanaga) wrote:
> This issue seems introduced by r43511. So I assign this to naruse san.

No. This bug is what logger.rb has been having for a long time.
The above patch fixes the newly implemented method for simplicity.
The actual problem is #9133. Updated patch is also available there.
Please see to it.

$ ruby -v l.rb 
ruby 2.0.0p247 (2013-06-27 revision 41674) [x86_64-linux]
$ egrep -Tv '^#' log* | sort -k3
log.1  :D, [2013-12-02T21:19:25.262587 #12207] DEBUG -- : 
log.1  :D, [2013-12-02T21:19:25.262713 #12204] DEBUG -- : 
log.1  :D, [2013-12-02T21:19:25.577349 #12207] DEBUG -- : 
log.1  :D, [2013-12-02T21:19:27.339095 #12204] DEBUG -- : 
log.1  :D, [2013-12-02T21:19:27.961317 #12207] DEBUG -- : 
log.0  :D, [2013-12-02T21:19:29.225823 #12207] DEBUG -- : 
log    :D, [2013-12-02T21:19:30.152343 #12204] DEBUG -- : 
log.0  :D, [2013-12-02T21:19:31.307252 #12207] DEBUG -- : 
log    :D, [2013-12-02T21:19:32.378369 #12204] DEBUG -- : 
log    :D, [2013-12-02T21:19:32.693861 #12204] DEBUG -- : 

----------------------------------------
Bug #9130: logger continues to write in old log file after rotation
https://bugs.ruby-lang.org/issues/9130#change-43357

Author: no6v (Nobuhiro IMAI)
Status: Assigned
Priority: Normal
Assignee: naruse (Yui NARUSE)
Category: lib
Target version: 
ruby -v: ruby 2.1.0dev (2013-11-18 trunk 43704) [x86_64-linux]
Backport: 1.9.3: DONTNEED, 2.0.0: DONTNEED


=begin
Logger continues to write in old log file after rotation as follow:

 $ cat l.rb
 require "logger"
 
 logdev = "log"
 pids = []
 2.times do |n|
   pids << fork{
     logger = Logger.new(logdev, 10, 300)
     5.times do
       logger.debug("")
       sleep(rand * 3)
     end
     exit
   }
 end
 pids.each do |pid|
   Process.waitpid(pid)
 end
 $ rm -f log*
 $ time ruby -v l.rb
 ruby 2.1.0dev (2013-11-18 trunk 43704) [x86_64-linux]
 
 real	0m8.498s
 user	0m0.044s
 sys	0m0.016s
 $ ls -ltrn --full-time log*
 -rw-r--r-- 1 1000 1000 322 2013-11-20 10:36:40.059247700 +0900 log.1
 -rw-r--r-- 1 1000 1000 169 2013-11-20 10:36:41.251247688 +0900 log
 -rw-r--r-- 1 1000 1000 220 2013-11-20 10:36:43.851247663 +0900 log.0
 $ egrep -Tv '^#' log* | sort -k3
 log.1  :D, [2013-11-20T10:36:35.983308 #16870] DEBUG -- : 
 log.1  :D, [2013-11-20T10:36:35.983409 #16867] DEBUG -- : 
 log.1  :D, [2013-11-20T10:36:37.194691 #16867] DEBUG -- : 
 log.1  :D, [2013-11-20T10:36:38.242855 #16870] DEBUG -- : 
 log.1  :D, [2013-11-20T10:36:40.062467 #16867] DEBUG -- : 
 log.0  :D, [2013-11-20T10:36:40.347119 #16870] DEBUG -- : 
 log    :D, [2013-11-20T10:36:40.953420 #16867] DEBUG -- : 
 log    :D, [2013-11-20T10:36:41.257187 #16867] DEBUG -- : 
 log.0  :D, [2013-11-20T10:36:43.145010 #16870] DEBUG -- : 
 log.0  :D, [2013-11-20T10:36:43.856779 #16870] DEBUG -- : 
=end



-- 
http://bugs.ruby-lang.org/