rolling log

[SHSongs]

I use Slf4jBridge in my project, but zio-logging does not include rolling log function,
Therefore, I have created a simple rolling log function.
could you review the PR?

[justcoon]

hi @SHSongs

thank you for contribution, that is missing feature which will be nice to add, I appreciate yours contribution

however there are few things to improve:

1. instead of simple FileLoggerConfig.rolling boolean flag, we need to be more open, if you take https://logback.qos.ch/manual/appenders.html#onRollingPolicies as inspiration,
   we will need to add something like

object FileLoggerConfig {
  sealed trait FileRollingPolicy
  
  object FileRollingPolicy {
     case class TimeBasedRollingPolicy( /* some attributes related to this policy if needed */) extends FileRollingPolicy 
     // case class FixedWindowRollingPolicy() extends FileRollingPolicy   // can be implemented later ...
  }
}

then

final case class FileLoggerConfig(
  ...
  bufferedIOSize: Option[Int] = None
  rollingPolicy: Option[FileRollingPolicy] = None
)

then this needs to be added to FileLoggerConfig.config ...

2. FileWriter needs to work with this policy, if there is new file based on policy OutputStreamWriter needs to be opened just once, also you need to close previous one if there is new one created based on changes in relation to rolling policy

[SHSongs]

I think I fixed all the code you reviewed. Thanks for your time and effort reviewed my code.

[justcoon]

i assume this is for "Debug" purposes and it will be removed ...

[justcoon]

in case of rollingPolicy, i think some concurrent constructs will have to be used as at same time 2 threads/fibers may try to log, and we do not want to create new writer twice ...

in addition to that, personally i would do something like

private[logging] class FileWriter(
  destination: Path,
  charset: Charset,
  autoFlushBatchSize: Int,
  bufferedIOSize: Option[Int],
  rolling: Option[FileLoggerConfig.FileRollingPolicy]
) extends Writer {
  private val writerProvider: WriterProvider = rolling match {
  ...
  }

  final def writeln(line: String): Unit = {
    val writer  = writerProvider.writer
    writer.write(line)
    writer.write(System.lineSeparator)

    entriesWritten += 1

    if (entriesWritten % autoFlushBatchSize == 0)
      writer.flush()
  }

  ...


}



private[logging] sealed trait WriterProvider {
  def writer: Writer
}

private[logging] object WriterProvider {

  final case class SimpleWriterProvider(
    destination: Path,
    charset: Charset,
    bufferedIOSize: Option[Int]
  ) extends WriterProvider {
    override val writer: Writer = {
      val output = new OutputStreamWriter(new FileOutputStream(destination.toFile, true), charset)
      bufferedIOSize match {
        case Some(bufferSize) => new BufferedWriter(output, bufferSize)
        case None             => output
      }
    }
  }


  final case class TimeBasedRollingWriterProvider(
                                         destination: Path,
                                         charset: Charset,
                                         bufferedIOSize: Option[Int]
                                       ) extends WriterProvider {
    override def writer: Writer = ???
  }
}

with such design you can isolate underlying writer problem, and it should be easier to add next policy later ...

[SHSongs]

I rewrote. Could you check this commit? 15d1768

[justcoon]

ok, now i think it is better, just some other problems are still remaining

in case of rollingPolicy, i think some concurrent constructs will have to be used as at same time 2 threads/fibers may try to log, and we do not want to create new writer twice ...

#691 (comment)

[justcoon]

we will need more optimal comparison probably just based on currentDateTime,
as makeDatePath is relatively complex, to do it with every log line

we need to have logging as fast as possible, we need to avoid unnecessary memory allocations and computations

[SHSongs]

cb16d15
rewrote using currentDateTime. Could you check this commit?

[justcoon]

now WriterProvider is inside FileWriter

i think you can move it out, so also it can be tested separately

[SHSongs]

I wrote, Could you check this commit? 5dd2e73

[justcoon]

also documentation will need to be updated https://github.com/zio/zio-logging/blob/master/docs/file-logger.md

[SHSongs]

zio-logging/core/shared/src/main/scala/zio/logging/LogFormat.scala

Line 798 in 742bcbf

val now = ZonedDateTime.now()

i want to TestClock but not work. I think this part is the cause

so I used ZIO.logDebug("abcd").repeatWhileZIO(_ => ZIO.succeed(true).delay(100.millisecond)) in testing.

if this PR is close. Could I change java time to ZIO time?

[justcoon]

@SHSongs

zio.ZLogger in is not effectful

that is one of reason why in those underlying impl. of loggers we are not using zio.* (Console, Clock ...) if it is not really needed

you can create custom format using zio.Unsafe to do some testing

  def timestamp(formatter: => DateTimeFormatter): LogFormat =
    text {
      val d = zio.Unsafe.unsafe { implicit u =>
        Runtime.default.unsafe.run(zio.Clock.instant).getOrThrow()
      }
      formatter.format(d.atZone(ZoneId.systemDefault()))
    }

but i think in LogFormat.timestamp implementation we do not want to change it now, as with zio.Unsafe it is more expensive operation then ZonedDateTime.now(), and logging should have minimum impact on performance of system

[SHSongs]

also documentation will need to be updated https://github.com/zio/zio-logging/blob/master/docs/file-logger.md

I updated the documentation. let me know if there is any missing information or anything that needs to be added.
90edf38

[justcoon]

please add also test for paths like:

• /tmp/file_app
• /tmp/file.app.log
• /tmp/file.app.out.log

[SHSongs]

I added test case

[justcoon]

as i mentioned before, i think this implementation is not thread safe, some concurrency patterns should be used so only one caller will create new writer and close current one if it is needed

[SHSongs]

Do I make it like the code below? Also, could you provide an example code for concurrent patterns?

    import java.util.concurrent.locks.ReentrantLock
    private val lock: ReentrantLock = new ReentrantLock()

    override def writer: Writer = {
      val newTime = makeNewTime
      if (newTime != timeInUse) {
        lock.lock()
        try {
          currentWriter.close()
          currentWriter = makeWriter(makePath(destination, timeInUse), charset, bufferedIOSize)
          timeInUse = newTime
        } finally {
          lock.unlock()
        }
      }
      currentWriter
    }

[justcoon]

this could work

however i think time should be checked also under the lock

  override def writer: Writer = {
    val newTime = makeNewTime
    if (newTime != timeInUse) {
      lock.lock()
      try {
         if (newTime != timeInUse) {
            currentWriter.close() 
            currentWriter = makeWriter(makePath(destination, newTime), charset, bufferedIOSize) 
            timeInUse = newTime
        }
      } finally {
        lock.unlock()
      }
    } 
     currentWriter
  }

or just

 override def writer: Writer = {
    val newTime = makeNewTime
    
      lock.lock()
      try {
         if (newTime != timeInUse) {
            currentWriter.close() 
            currentWriter = makeWriter(makePath(destination, newTime), charset, bufferedIOSize) 
            timeInUse = newTime
        }
      } finally {
        lock.unlock()
      }
    
     currentWriter
  }

i think that first version should be less locking, even if it is probably less correct

[justcoon]

this example now do not match with https://github.com/zio/zio-logging/blob/master/docs/slf4j2-bridge.md, i recommend to rollback this change to not make it complicated

[SHSongs]

I have completed rollback

[justcoon]

you should modify also https://github.com/zio/zio-logging/blob/master/examples/core/src/main/scala/zio/logging/example/FileApp.scala, to match with this documentation

[SHSongs]

I applied

[justcoon]

maybe you can add

val dateTimeFormatter: DateTimeFormatter = DateTimeFormatter.ofPattern("yyyy-MM-dd")

here to companion object, so it will be crated just once, and you don't have to have it like argument in makePath

[SHSongs]

I applied

[justcoon]

is this used ?

[SHSongs]

Not use, I removed formatter in provider class

[SHSongs]

#691 (comment) continuously..

I applied a concurrent pattern and checked the time under the lock.
After acquiring the lock, I created a new timestamp value using makeNewTime(), because I think that if I were to use the time that was determined before acquiring the lock to create a new file, repeatedly create and close new writers.

A: 
set(newTime) -> lock -> if(newTime..) -> create 
B: 
set(newTime) -> lock -> wait                 -> if(newTime..) -> create

[justcoon]

   override def writer: Writer = {
      val newTime = makeNewTime
      if (newTime != timeInUse) { // if they are same it will not go inside if, so it will not be locked
        lock.lock()
        try {

// considering that time is date, basically it should not happen that newTimeInLock != newTime
// otherwise it will have to wait for lock more almost one day
          val newTimeInLock = makeNewTime 
        
         // considering proposed    if (newTime != timeInUse) this additional check here in lock,
         // this is for situation, when 2 threads at same time try to obtain lock, (after first if condition)
        // one will get lock first, and this will change writer and timeInUse
        // then after lock will be released, second one will get lock, and enter here
        // but timeInUse and writer are already changed, 
        // so it should not be needed to recreate basically same thing
          if (newTimeInLock != timeInUse) {
            currentWriter.close()
            currentWriter = makeWriter(makePath(destination, newTimeInLock), charset, bufferedIOSize)
            timeInUse = newTimeInLock
          }
        } finally {
          lock.unlock()
        }
      }
      currentWriter
    }

[SHSongs]

I understand the comments (timeInUse and writer are already changed), and I rewrote code.

[justcoon]

it will be good if we can test it

if we add here another attribute

makeNewTime: () => LocalDateTime = TimeBasedRollingWriterProvider.makeNewTime

then in WriterProviderSpec

it should be possible to do something like:

  val timeRef = new AtomicReference[LocalDateTime](LocalDateTime.now())
  
   timeRef.set(LocalDateTime.now().plusDays(1))
  
   val testMakeNewTime: () => LocalDateTime = () => timeRef.get()

and then test it if in case of parallel execution, when WriterProvider.writer is called multiple times with same time, if it return same writer

[SHSongs]

I wrote test code. Could you check this commit? 4fe78ca

[justcoon]

good to add check sameWriter1 != sameWriter2

[justcoon]

please add better description of test case

[justcoon]

ZIOAspect.parallel(5) should not be needed

[SHSongs]

I rewrote code. Could you check this commit? 0aa8499

[justcoon]

@SHSongs please run fmt and fix, CI is failing

[SHSongs]

@justcoon I ran fmt and fix, CI success

[justcoon]

thank you very much for contribution

[justcoon]

@SHSongs did you accepted license/cla ?

[SHSongs]

@justcoon
Yes, I accepted license/cla. this is my Screen