Merge pull request #7 from tanmaykm/tan/misc

add RollingFileWriterTee

Author: tanmaykm

LICENSE.md

@@ -1,6 +1,6 @@
 The LogRoller.jl package is licensed under the MIT "Expat" License:
 
-> Copyright (c) 2019-2020: Tanmay Mohapatra, Julia Computing
+> Copyright (c) 2020-2021: Tanmay Mohapatra, Julia Computing
 >
 > Permission is hereby granted, free of charge, to any person obtaining
 > a copy of this software and associated documentation files (the

Project.toml

@@ -3,7 +3,7 @@ uuid = "c41e01d8-14e5-11ea-185b-e7eabed7be4b"
 keywords = ["log", "rotate", "roller", "logrotate"]
 license = "MIT"
 authors = ["Tanmay Mohapatra <[email protected]>"]
-version = "0.2.2"
+version = "0.3.0"
 
 [compat]
 julia = "1"

README.md

@@ -28,6 +28,22 @@ Rotates files as below:
 - ...
 - `<filename>_n.gz` : last rotated file is discarded when rotated
 
+
+## `RollingFileWriterTee`
+
+Tees raw log entries made a RollingFileWriter on to a Julia `AbstractLogger`.
+
+Each line of text is taken as a single log message.
+
+All log entries are made with the same log level, which can be provided during construction. It leaves
+further examination/parsing of log messages (to extract parameters, or detect exact log levels) to the
+downstream logger.
+
+Constructor parameters in addition to those for `RollingFileWriter`:
+- `logger`: instance of AbstractLogger to tee log entries to
+- `assumed_level`: level of the log messages to assume (default Info)
+
+
 ## `RollingLogger`
 
 A logger that implements `AbstractLogger` interface and uses a `RollingFileWriter` to provide log rotation.
@@ -66,6 +82,16 @@ julia> io = RollingFileWriter("/tmp/mylog.log", 1000, 3);
 julia> run(pipeline(`myshellscript.sh`; stdout=io, stderr=io));
 ```
 
+Using `RollingFileWriterTee`
+
+```julia
+julia> using LogRoller, Logging
+
+julia> io = RollingFileWriterTee("/tmp/mylog.log", 1000, 3, ConsoleLogger(stderr));
+
+julia> run(pipeline(`myshellscript.sh`; stdout=io, stderr=io));
+```
+
 Using `RollingLogger`
 
 ```julia

src/LogRoller.jl

@@ -7,7 +7,7 @@ using Logging
 
 import Logging: shouldlog, min_enabled_level, catch_exceptions, handle_message
 import Base: write, close, rawhandle
-export RollingLogger, RollingFileWriter, postrotate
+export RollingLogger, RollingFileWriter, RollingFileWriterTee, postrotate
 
 const BUFFSIZE = 1024*16  # try and read 16K pages when possible
 
@@ -28,12 +28,14 @@ mutable struct RollingFileWriter <: IO
     lck::ReentrantLock
     procstream::Union{Nothing,Pipe}
     procstreamer::Union{Nothing,Task}
+    procstreamteelogger::Union{Nothing,AbstractLogger}
+    assumed_level::LogLevel
     postrotate::Union{Nothing,Function}
 
     function RollingFileWriter(filename::String, sizelimit::Int, nfiles::Int)
         stream = open(filename, "a")
         filesize = stat(stream).size
-        new(filename, sizelimit, nfiles, filesize, stream, ReentrantLock(), nothing, nothing, nothing)
+        new(filename, sizelimit, nfiles, filesize, stream, ReentrantLock(), nothing, nothing, nothing, Logging.Info, nothing)
     end
 end
 
@@ -47,6 +49,15 @@ function postrotate(fn::Function, io::RollingFileWriter)
     nothing
 end
 
+"""
+Tee all lines to the provided logger
+"""
+function tee(io::RollingFileWriter, logger::AbstractLogger, level::LogLevel)
+    io.procstreamteelogger = logger
+    io.assumed_level = level
+    io
+end
+
 """
 Close any open file handle and streams.
 A closed object must not be used again.
@@ -57,6 +68,7 @@ function close(io::RollingFileWriter)
         lock(io.lck) do
             io.procstream = nothing
             io.procstreamer = nothing
+            io.procstreamteelogger = nothing
         end
     end
     close(io.stream)
@@ -128,6 +140,24 @@ function rotate_file(io::RollingFileWriter)
     nothing
 end
 
+"""
+Tees raw log entries made a RollingFileWriter on to a provided Julia AbstractLogger.
+
+Each line of text is taken as a single log message.
+
+All log entries are made with the same log level, which can be provided during construction. It leaves
+further examination/parsing of log messages (to extract parameters, or detect exact log levels) to the
+downstream logger.
+"""
+function RollingFileWriterTee(filename::String, sizelimit::Int, nfiles::Int, logger::AbstractLogger, assumed_level::LogLevel=Logging.Info)
+    io = RollingFileWriter(filename, sizelimit, nfiles)
+    RollingFileWriterTee(io, logger, assumed_level)
+end
+
+function RollingFileWriterTee(io::RollingFileWriter, logger::AbstractLogger, assumed_level::LogLevel=Logging.Info)
+    tee(io, logger, assumed_level)
+end
+
 """
 RollingLogger(filename, sizelimit, nfiles, min_level=Info; timestamp_identifier::Symbol=:time)
 Log into a log file. Rotate log file based on file size. Compress rotated logs.
@@ -205,10 +235,15 @@ end
 
 function stream_process_logs(writer::RollingFileWriter)
     try
-        bytes = readavailable(writer.procstream)
-        while !isempty(bytes)
-            write(writer, bytes)
-            bytes = readavailable(writer.procstream)
+        while true
+            logline = readline(writer.procstream; keep=true)
+            if !isempty(logline)
+                write(writer, logline)
+                if writer.procstreamteelogger !== nothing
+                    @logmsg(writer.assumed_level, strip(logline))
+                end
+            end
+            eof(writer.procstream) && break
         end
     finally
         close(writer.procstream)
@@ -225,7 +260,13 @@ function rawhandle(writer::RollingFileWriter)
             writer.procstream = Pipe()
             Base.link_pipe!(writer.procstream)
             writer.procstreamer = @async begin
-                stream_process_logs(writer)
+                if writer.procstreamteelogger !== nothing
+                    with_logger(writer.procstreamteelogger) do
+                        stream_process_logs(writer)
+                    end
+                else
+                    stream_process_logs(writer)
+                end
             end
         end
         return rawhandle(Base.pipe_writer(writer.procstream))

test/runtests.jl

@@ -73,6 +73,35 @@ function test_filewriter()
     end
 end
 
+function test_pipelined_tee()
+    mktempdir() do logdir
+        filename1 = "test1.log"
+        filename2 = "test2.log"
+        filepath1 = joinpath(logdir, filename1)
+        filepath2 = joinpath(logdir, filename2)
+        @test !isfile(filepath1)
+        @test !isfile(filepath2)
+
+        logger1io = open(filepath1, "w+")
+        logger1 = SimpleLogger(logger1io)
+        logger2 = RollingFileWriterTee(filepath2, 1000, 3, logger1, Logging.Info)
+
+        julia = joinpath(Sys.BINDIR, "julia")
+        cmd = pipeline(`$julia -e 'for i in 1:5 println(string("hello",i)) end; flush(stdout)'`; stdout=logger2, stderr=logger2)
+        run(cmd)
+
+        close(logger2)
+        close(logger1io)
+
+        @test isfile(filepath1)
+        @test isfile(filepath2)
+        @test (2*length(readlines(filepath2))) == length(readlines(filepath1)) # Julia logger entry will be two lines for every raw message
+        if !Sys.iswindows()    # streams do not seem to be flushed cleanly on Windows
+            @test length(readlines(filepath2)) == 5
+        end
+    end
+end
+
 function test_logger()
     mktempdir() do logdir
         filename = "test.log"
@@ -249,6 +278,7 @@ function test_timestamp_handling()
 end
 
 test_filewriter()
+test_pipelined_tee()
 test_logger()
 test_process_streams()
 test_postrotate()