From e09e558485dce7741118606255d6d8794b0e44ac Mon Sep 17 00:00:00 2001 From: Ivo Petkovic Date: Wed, 22 Feb 2023 15:02:42 +0100 Subject: [PATCH] Json logger: log JSON values correctly (#657) --- .../scala/zio/logging/JsonGenerator.scala | 161 +++++++ .../scala/zio/logging/JsonLogFormatSpec.scala | 414 +++++++++++------- .../logging/internal/JsonValidatorSpec.scala | 265 +++++++++++ .../zio/logging/internal/JsonValidator.scala | 202 +++++++++ .../zio/logging/internal/LogAppender.scala | 15 +- docs/console-logger.md | 28 +- .../zio/logging/example/ConsoleJsonApp.scala | 18 +- 7 files changed, 928 insertions(+), 175 deletions(-) create mode 100644 core/jvm/src/test/scala/zio/logging/JsonGenerator.scala create mode 100644 core/jvm/src/test/scala/zio/logging/internal/JsonValidatorSpec.scala create mode 100644 core/shared/src/main/scala/zio/logging/internal/JsonValidator.scala diff --git a/core/jvm/src/test/scala/zio/logging/JsonGenerator.scala b/core/jvm/src/test/scala/zio/logging/JsonGenerator.scala new file mode 100644 index 00000000..d5563ad7 --- /dev/null +++ b/core/jvm/src/test/scala/zio/logging/JsonGenerator.scala @@ -0,0 +1,161 @@ +package zio.logging + +import zio.logging.GenExt.GenExtOps +import zio.test.Gen + +import scala.annotation.tailrec + +private object GenExt { + + implicit class GenExtOps(gen: Gen[Any, String]) { + + def andThen(that: Gen[Any, String]): Gen[Any, String] = + (gen zipWith that)(_ + _) + } +} + +private final case class BlockGenerator( + whitespaceGenerator: Gen[Any, String], + commaGenerator: Gen[Any, String], + oneItem: String => Gen[Any, String], + openBracketGenerator: Gen[Any, String] = Gen.const("{"), + closedBracketGenerator: Gen[Any, String] = Gen.const("}") +) { + def generate(values: List[String]): Gen[Any, String] = + contentInsideBlockGen(values).flatMap { insideObject => + (openBracketGenerator zipWith closedBracketGenerator)(_ + insideObject + _) + } + + def contentInsideBlockGen(values: List[String]): Gen[Any, String] = { + @tailrec + def inner(values: List[String], gen: Gen[Any, String]): Gen[Any, String] = + values match { + case Nil => whitespaceGenerator + case head :: Nil => oneItem(head) andThen gen + case head :: tail => + inner( + tail, + for { + comma <- commaGenerator + item <- oneItem(head) + value <- gen + } yield comma + item + value + ) + } + + inner(values, Gen.const("")) + } +} + +object JsonGenerator { + final case class ObjectGenerator( + whitespaceGenerator: Gen[Any, String] = JsonGenerator.validWhitespaceGen, + keyGenerator: Gen[Any, String] = JsonGenerator.validStringGen, + commaGenerator: Gen[Any, String] = Gen.const(","), + colonGenerator: Gen[Any, String] = Gen.const(":"), + openBracketGenerator: Gen[Any, String] = Gen.const("{"), + closedBracketGenerator: Gen[Any, String] = Gen.const("}") + ) { + + def generate(values: List[String]): Gen[Any, String] = + BlockGenerator( + whitespaceGenerator, + commaGenerator, + oneItem, + openBracketGenerator, + closedBracketGenerator + ).generate(values) + + private def oneItem(value: String) = + for { + w1 <- whitespaceGenerator + k <- keyGenerator + w2 <- whitespaceGenerator + c <- colonGenerator + w3 <- whitespaceGenerator + v <- Gen.const(value) + w4 <- whitespaceGenerator + } yield w1 + k + w2 + c + w3 + v + w4 + } + + final case class ArrayGenerator( + whitespaceGenerator: Gen[Any, String] = JsonGenerator.validWhitespaceGen, + commaGenerator: Gen[Any, String] = Gen.const(","), + openBracketGenerator: Gen[Any, String] = Gen.const("["), + closedBracketGenerator: Gen[Any, String] = Gen.const("]") + ) { + + def generate(values: List[String]): Gen[Any, String] = + BlockGenerator( + whitespaceGenerator, + commaGenerator, + oneItem, + openBracketGenerator, + closedBracketGenerator + ).generate(values) + + private def oneItem(value: String) = + for { + w1 <- whitespaceGenerator + v <- Gen.const(value) + w2 <- whitespaceGenerator + } yield w1 + v + w2 + } + + def validWhitespaceCharacters: Set[Char] = Set(' ', '\t', '\r', '\n') + + def validWhitespaceGen: Gen[Any, String] = + Gen.string(Gen.oneOf(validWhitespaceCharacters.map(Gen.const(_)).toSeq: _*)) + + def validNumberGen: Gen[Any, String] = { + val firstPart = ( + Gen.oneOf(Gen.const("-"), Gen.const("")) andThen + Gen.oneOf( + Gen.const("0"), + ((Gen.stringN(1)(Gen.char('1', '9')) andThen + Gen.string(Gen.numericChar))) + ) + ) + + val fractionPart = Gen.oneOf( + Gen.const(""), + (Gen.const(".") andThen Gen.string1(Gen.numericChar)) + ) + + val exponentPart = for { + e <- Gen.oneOf(Gen.const("e"), Gen.const("E")) + sign <- Gen.oneOf(Gen.const("+"), Gen.const("-"), Gen.const("")) + digits <- Gen.string1(Gen.numericChar) + } yield (e + sign + digits) + + firstPart andThen fractionPart andThen exponentPart + } + + def validStringGen: Gen[Any, String] = { + val allowedChar = Gen + .weighted( + (Gen.printableChar, 0.5), + (Gen.unicodeChar, 0.2), + (Gen.char, 0.3) + ) + .filterNot(c => c == '\\' || c == '"') + + val backSlashed = List("\\\"", "\\\\", "\\/", "\\b", "\\f", "\\n", "\\r", "\\t") + val backSlashedGen = (Gen.oneOf(backSlashed.map(Gen.const(_)): _*)) + + val validString = (for { + string <- Gen.string(allowedChar) + backSlashedChar <- Gen.weighted((backSlashedGen, 0.1), (Gen.const(""), 0.9)) + newString <- Gen.int(0, string.length).flatMap { pos => + Gen.const(string.substring(0, pos) + backSlashedChar + string.substring(pos)) + } + } yield newString).filterNot(_.endsWith("\"")) + + validString.map("\"" + _ + "\"") + } + + def validBooleanGen: Gen[Any, String] = Gen.oneOf(Gen.const("true"), Gen.const("false")) + + def validNullGen: Gen[Any, String] = Gen.const("null") + +} diff --git a/core/jvm/src/test/scala/zio/logging/JsonLogFormatSpec.scala b/core/jvm/src/test/scala/zio/logging/JsonLogFormatSpec.scala index 4e3f5875..2ac697ad 100644 --- a/core/jvm/src/test/scala/zio/logging/JsonLogFormatSpec.scala +++ b/core/jvm/src/test/scala/zio/logging/JsonLogFormatSpec.scala @@ -6,29 +6,67 @@ import zio.test._ import zio.{ Cause, FiberId, FiberRefs, LogLevel, Trace } object JsonLogFormatSpec extends ZIOSpecDefault { - private val nonEmptyString = Gen.stringBounded(1, 5)(Gen.alphaNumericChar) + private val nonEmptyNonJsonString = + Gen.stringBounded(1, 5)(Gen.alphaNumericChar).filter(isNotJson) + + private def isNotJson(s: String) = !(s.startsWith("{") || s.startsWith("[")) val spec: Spec[Environment, Any] = suite("JsonLogFormatSpec")( - test("line") { - val format = line - check(nonEmptyString) { line => - val result = format - .toJsonLogger( + suite("standard text")( + test("line") { + val format = line + check(nonEmptyNonJsonString) { line => + val result = format + .toJsonLogger( + Trace.empty, + FiberId.None, + LogLevel.Info, + () => line, + Cause.empty, + FiberRefs.empty, + Nil, + Map.empty + ) + assertTrue(result == s"""{"text_content":"${JsonEscape(line)}"}""") + } + }, + test("annotation") { + val format = annotation("test") + check(Gen.string.filter(isNotJson)) { annotationValue => + val result = format.toJsonLogger( Trace.empty, FiberId.None, LogLevel.Info, - () => line, + () => "", Cause.empty, FiberRefs.empty, Nil, + Map("test" -> annotationValue) + ) + assertTrue(result == s"""{"test":"${JsonEscape(annotationValue)}"}""") + } + }, + test("annotation (structured)") { + val format = annotation(LogAnnotation.UserId) + check(Gen.string.filter(isNotJson)) { annotationValue => + val result = format.toJsonLogger( + Trace.empty, + FiberId.None, + LogLevel.Info, + () => "", + Cause.empty, + FiberRefs.empty.updatedAs(FiberId.Runtime(0, 0, Trace.empty))( + logContext, + LogContext.empty.annotate(LogAnnotation.UserId, annotationValue) + ), + Nil, Map.empty ) - assertTrue(result == s"""{"text_content":"${JsonEscape(line)}"}""") - } - }, - test("annotation") { - val format = annotation("test") - check(Gen.string) { annotationValue => + assertTrue(result == s"""{"user_id":"${JsonEscape(annotationValue)}"}""") + } + }, + test("empty annotation") { + val format = annotation("test") val result = format.toJsonLogger( Trace.empty, FiberId.None, @@ -37,147 +75,190 @@ object JsonLogFormatSpec extends ZIOSpecDefault { Cause.empty, FiberRefs.empty, Nil, - Map("test" -> annotationValue) - ) - assertTrue(result == s"""{"test":"${JsonEscape(annotationValue)}"}""") - } - }, - test("annotation (structured)") { - val format = annotation(LogAnnotation.UserId) - check(Gen.string) { annotationValue => - val result = format.toJsonLogger( - Trace.empty, - FiberId.None, - LogLevel.Info, - () => "", - Cause.empty, - FiberRefs.empty.updatedAs(FiberId.Runtime(0, 0, Trace.empty))( - logContext, - LogContext.empty.annotate(LogAnnotation.UserId, annotationValue) - ), - Nil, - Map.empty - ) - assertTrue(result == s"""{"user_id":"${JsonEscape(annotationValue)}"}""") - } - }, - test("empty annotation") { - val format = annotation("test") - val result = format.toJsonLogger( - Trace.empty, - FiberId.None, - LogLevel.Info, - () => "", - Cause.empty, - FiberRefs.empty, - Nil, - Map.empty - ) - assertTrue(result == "{}") - }, - test("several labels") { - val format = label("msg", line) + label("fiber", fiberId) - check(Gen.string, Gen.int) { (line, fiberId) => - val result = format.toJsonLogger( - Trace.empty, - FiberId(fiberId, 1, Trace.empty), - LogLevel.Info, - () => line, - Cause.empty, - FiberRefs.empty, - Nil, - Map.empty - ) - val msg = JsonEscape(line) - val fiber = s"zio-fiber-${JsonEscape(fiberId.toString)}" - assertTrue(result == s"""{"msg":"$msg","fiber":"$fiber"}""") - } - }, - test("nested labels") { - val format = label("msg", line) + label("nested", label("fiber", fiberId) + annotation("test")) - check(Gen.alphaNumericString, Gen.int, nonEmptyString) { (line, fiberId, annotationValue) => - val result = format.toJsonLogger( - Trace.empty, - FiberId(fiberId, 1, Trace.empty), - LogLevel.Info, - () => line, - Cause.empty, - FiberRefs.empty, - Nil, - Map("test" -> annotationValue) - ) - val msg = JsonEscape(line) - val fiber = s"zio-fiber-${JsonEscape(fiberId.toString)}" - val ann = JsonEscape(annotationValue) - assertTrue(result == s"""{"msg":"$msg","nested":{"fiber":"$fiber","test":"$ann"}}""") - } - }, - test("mixed structured / unstructured ") { - val format = - label("msg", line) + text("hi") + - label( - "nested", - label("fiber", fiberId |-| text("abc") + label("third", text("3"))) + annotation("test") - ) + text(" there") - check(Gen.alphaNumericString, Gen.int, nonEmptyString) { (line, fiberId, annotationValue) => - val result = format.toJsonLogger( - Trace.empty, - FiberId(fiberId, 1, Trace.empty), - LogLevel.Info, - () => line, - Cause.empty, - FiberRefs.empty, - Nil, - Map("test" -> annotationValue) - ) - val msg = JsonEscape(line) - val fiber = s"zio-fiber-${JsonEscape(fiberId.toString)}" - val ann = JsonEscape(annotationValue) - assertTrue( - result == s"""{"text_content":"hi there","msg":"$msg","nested":{"fiber":{"text_content":"$fiber abc","third":"3"},"test":"$ann"}}""" - ) - } - }, - test("numeric value") { - val format = label("line", traceLine) - check(Gen.int) { i => - val result = format.toJsonLogger( - Trace.apply("", "", i), - FiberId.None, - LogLevel.Info, - () => "", - Cause.empty, - FiberRefs.empty, - Nil, Map.empty ) + assertTrue(result == "{}") + }, + test("several labels") { + val format = label("msg", line) + label("fiber", fiberId) + check(Gen.string.filter(isNotJson), Gen.int) { (line, fiberId) => + val result = format.toJsonLogger( + Trace.empty, + FiberId(fiberId, 1, Trace.empty), + LogLevel.Info, + () => line, + Cause.empty, + FiberRefs.empty, + Nil, + Map.empty + ) + val msg = JsonEscape(line) + val fiber = s"zio-fiber-${JsonEscape(fiberId.toString)}" + assertTrue(result == s"""{"msg":"$msg","fiber":"$fiber"}""") + } + }, + test("nested labels") { + val format = label("msg", line) + label("nested", label("fiber", fiberId) + annotation("test")) + check(Gen.alphaNumericString, Gen.int, nonEmptyNonJsonString) { (line, fiberId, annotationValue) => + val result = format.toJsonLogger( + Trace.empty, + FiberId(fiberId, 1, Trace.empty), + LogLevel.Info, + () => line, + Cause.empty, + FiberRefs.empty, + Nil, + Map("test" -> annotationValue) + ) + val msg = JsonEscape(line) + val fiber = s"zio-fiber-${JsonEscape(fiberId.toString)}" + val ann = JsonEscape(annotationValue) + assertTrue(result == s"""{"msg":"$msg","nested":{"fiber":"$fiber","test":"$ann"}}""") + } + }, + test("mixed structured / unstructured ") { + val format = + label("msg", line) + text("hi") + + label( + "nested", + label("fiber", fiberId |-| text("abc") + label("third", text("3"))) + annotation("test") + ) + text(" there") + check(Gen.alphaNumericString, Gen.int, nonEmptyNonJsonString) { (line, fiberId, annotationValue) => + val result = format.toJsonLogger( + Trace.empty, + FiberId(fiberId, 1, Trace.empty), + LogLevel.Info, + () => line, + Cause.empty, + FiberRefs.empty, + Nil, + Map("test" -> annotationValue) + ) + val msg = JsonEscape(line) + val fiber = s"zio-fiber-${JsonEscape(fiberId.toString)}" + val ann = JsonEscape(annotationValue) + assertTrue( + result == s"""{"text_content":"hi there","msg":"$msg","nested":{"fiber":{"text_content":"$fiber abc","third":"3"},"test":"$ann"}}""" + ) + } + }, + test("numeric value") { + val format = label("line", traceLine) + check(Gen.int) { i => + val result = format.toJsonLogger( + Trace.apply("", "", i), + FiberId.None, + LogLevel.Info, + () => "", + Cause.empty, + FiberRefs.empty, + Nil, + Map.empty + ) - assertTrue(result == s"""{"line":$i}""") - } - }, - test("numeric value concatenated with string") { - val format = label("line", traceLine |-| line) - check(Gen.alphaNumericString, Gen.int) { (line, i) => - val result = format.toJsonLogger( - Trace.apply("", "", i), - FiberId.None, - LogLevel.Info, - () => line, - Cause.empty, - FiberRefs.empty, - Nil, - Map.empty - ) + assertTrue(result == s"""{"line":$i}""") + } + }, + test("numeric value concatenated with string") { + val format = label("line", traceLine |-| line) + check(Gen.alphaNumericString, Gen.int) { (line, i) => + val result = format.toJsonLogger( + Trace.apply("", "", i), + FiberId.None, + LogLevel.Info, + () => line, + Cause.empty, + FiberRefs.empty, + Nil, + Map.empty + ) - val msg = JsonEscape(s"$i $line") - assertTrue(result == s"""{"line":"$msg"}""") + val msg = JsonEscape(s"$i $line") + assertTrue(result == s"""{"line":"$msg"}""") + } + }, + test("Don't show ansi escape codes from colored log format") { + val format = line.color(LogColor.WHITE) |-| line |-| line.color(LogColor.BLUE) + check(nonEmptyNonJsonString) { line => + val result = format + .toJsonLogger( + Trace.empty, + FiberId.None, + LogLevel.Info, + () => line, + Cause.empty, + FiberRefs.empty, + Nil, + Map.empty + ) + val msg = JsonEscape(line) + assertTrue(result == s"""{"text_content":"$msg $msg $msg"}""") + } } - }, - test("Don't show ansi escape codes from colored log format") { - val format = line.color(LogColor.WHITE) |-| line |-| line.color(LogColor.BLUE) - check(nonEmptyString) { line => - val result = format - .toJsonLogger( + ), + suite("json text")( + test("json label") { + val format = label("json", line) + check( + Gen.string.flatMap(string => + JsonGenerator + .ObjectGenerator() + .generate(List("\"" + string + "\"")) + ) + ) { line => + val result = format.toJsonLogger( + Trace.empty, + FiberId.None, + LogLevel.Info, + () => line, + Cause.empty, + FiberRefs.empty, + Nil, + Map.empty + ) + val msg = line + assertTrue(result == s"""{"json":$msg}""") + } + }, + test("json annotation") { + val format = annotation("test") + check( + Gen + .listOf(Gen.alphaNumericString) + .flatMap(list => + JsonGenerator + .ObjectGenerator() + .generate(list.map("\"" + _ + "\"")) + ) + ) { annotationValue => + val result = format.toJsonLogger( + Trace.empty, + FiberId.None, + LogLevel.Info, + () => "", + Cause.empty, + FiberRefs.empty.updatedAs(FiberId.Runtime(0, 0, Trace.empty))( + logContext, + LogContext.empty.annotate(LogAnnotation.UserId, annotationValue) + ), + Nil, + Map("test" -> annotationValue) + ) + assertTrue(result == s"""{"test":${annotationValue}}""") + } + }, + test("mixed json and non-json labels") { + val format = label("random_json", line) + label("nonJson", text("""notA"json"""")) + + label("static_json", text("""{"value": "I am JSON"}""")) + check( + Gen.string.flatMap(string => + JsonGenerator + .ObjectGenerator() + .generate(List("\"" + string + "\"")) + ), + Gen.string.filter(isNotJson) + ) { case (line, annotationValue) => + val result = format.toJsonLogger( Trace.empty, FiberId.None, LogLevel.Info, @@ -187,9 +268,38 @@ object JsonLogFormatSpec extends ZIOSpecDefault { Nil, Map.empty ) - val msg = JsonEscape(line) - assertTrue(result == s"""{"text_content":"$msg $msg $msg"}""") + + val msg = line + assertTrue( + result == s"""{"random_json":$msg,"nonJson":"notA\\"json\\"","static_json":{"value": "I am JSON"}}""" + ) + } + }, + test("mixed json and non-json annotations") { + val format = annotation("json_annotation") + annotation("nonjson_annotation") + check( + Gen.string.flatMap(string => + JsonGenerator + .ObjectGenerator() + .generate(List("\"" + string + "\"")) + ), + Gen.string.filter(isNotJson) + ) { case (jsonAnnotation, nonJsonAnnotation) => + val result = format.toJsonLogger( + Trace.empty, + FiberId.None, + LogLevel.Info, + () => "", + Cause.empty, + FiberRefs.empty, + Nil, + Map("json_annotation" -> jsonAnnotation, "nonjson_annotation" -> nonJsonAnnotation) + ) + val annEscaped = JsonEscape(nonJsonAnnotation) + assertTrue(result == s"""{"json_annotation":$jsonAnnotation,"nonjson_annotation":"$annEscaped"}""") + } } - } + ) ) + } diff --git a/core/jvm/src/test/scala/zio/logging/internal/JsonValidatorSpec.scala b/core/jvm/src/test/scala/zio/logging/internal/JsonValidatorSpec.scala new file mode 100644 index 00000000..0422947f --- /dev/null +++ b/core/jvm/src/test/scala/zio/logging/internal/JsonValidatorSpec.scala @@ -0,0 +1,265 @@ +package zio.logging.internal + +import zio.logging.JsonGenerator +import zio.logging.JsonGenerator.{ ArrayGenerator, ObjectGenerator } +import zio.test.TestAspect._ +import zio.test._ + +import scala.annotation.tailrec + +object JsonValidatorSpec extends ZIOSpecDefault { + + private def simpleValueGen() = Gen.oneOf( + JsonGenerator.validStringGen, + JsonGenerator.validNumberGen, + JsonGenerator.validBooleanGen, + JsonGenerator.validNullGen + ) + + private def simpleValueWithEmptyBlock() = Gen.oneOf( + simpleValueGen(), + ObjectGenerator().generate(List.empty), + ArrayGenerator().generate(List.empty) + ) + + private def nestedJsonGen( + objectGenerator: ObjectGenerator, + arrayGenerator: ArrayGenerator, + valueGen: Gen[Any, String], + listOf: Gen[Any, String] => Gen[Any, List[String]], + depth: Int + ) = { + @tailrec + def inner(gen: Gen[Any, String], depth: Int): Gen[Any, String] = + if (depth <= 0) gen + else + inner( + listOf(gen).flatMap { l => + Gen.oneOf(objectGenerator.generate(l), arrayGenerator.generate(l)) + }, + depth - 1 + ) + + inner(valueGen, depth) + } + + val spec: Spec[Environment, Any] = suite("JsonValidator")( + test("deeply nested json") { + val keyGenerator = Gen.string(Gen.alphaNumericChar).map("\"" + _ + "\"") + check( + nestedJsonGen( + ObjectGenerator().copy(keyGenerator = keyGenerator), + ArrayGenerator(), + Gen.const("{}"), + Gen.listOfN(1), + 100 + ) + ) { json => + assert(JsonValidator.isJson(json))(Assertion.isTrue) + } + } @@ samples(2), + test("Simple valid json objects") { + val simpleValues = Gen.listOf(simpleValueWithEmptyBlock()) + + val simpleJson = + simpleValues.flatMap(ObjectGenerator().generate) + + check(simpleJson) { json => + assert(JsonValidator.isJson(json))(Assertion.isTrue) + } + + } @@ samples(50), + test("Valid nested json objects") { + val maxDepth = 5 + val json = Gen + .int(1, maxDepth) + .flatMap(depth => + nestedJsonGen( + ObjectGenerator(), + ArrayGenerator(), + simpleValueWithEmptyBlock(), + Gen.listOf1, + depth + ) + ) + + check(json) { json => + assert(JsonValidator.isJson(json))(Assertion.isTrue) + } + + } @@ samples(30), + test("Invalid json strings") { + assert(JsonValidator.isJson("This is not JSON."))(Assertion.isFalse) + assert(JsonValidator.isJson(" "))(Assertion.isFalse) + assert(JsonValidator.isJson("{]"))(Assertion.isFalse) + assert(JsonValidator.isJson("{"))(Assertion.isFalse) + assert(JsonValidator.isJson("}"))(Assertion.isFalse) + assert(JsonValidator.isJson("]"))(Assertion.isFalse) + assert(JsonValidator.isJson("{{]}"))(Assertion.isFalse) + + val invalidCommaGen = + Gen.oneOf( + Gen.const(",,"), + Gen.const(", ,"), + Gen.char.filterNot(_ == ',').map(_.toString) + ) + + val invalidColonGenerator = Gen.oneOf( + Gen.const("::"), + Gen.const(": :"), + Gen.const(" "), + Gen.alphaNumericChar.map(_.toString) + ) + + val invalidWhiteSpaceGenerator = + Gen.stringBounded(1, 2)( + Gen.oneOf( + Gen.char.filterNot(c => + JsonGenerator.validWhitespaceCharacters.contains(c) || + c == ',' + ) + ) + ) + + val invalidStringGenerator = Gen.oneOf( + Gen.const("\"\"\""), + Gen.const("\""), + Gen.alphaNumericChar.map("'" + _ + "'") + ) + + val invalidObjectKeyGenerator = Gen.oneOf( + invalidStringGenerator, + JsonGenerator.validNullGen, + JsonGenerator.validWhitespaceGen, + JsonGenerator.validNumberGen + ) + + val invalidBooleanOrNull = Gen.oneOf( + Gen.const("truee"), + Gen.const("falsee"), + Gen.const("tru"), + Gen.const("fals"), + Gen.const("t"), + Gen.const("f"), + Gen.const("nulll"), + Gen.const("nul"), + Gen.const("n") + ) + + val digitsWithoutZero = Gen.string1(Gen.numericChar.filterNot(_ == '0')) + + val invalidNumber = Gen.oneOf( + digitsWithoutZero.map("+" + _), + digitsWithoutZero.map("--" + _), + Gen.string1(Gen.numericChar).map("0" + _), + digitsWithoutZero.map(_ + "."), + digitsWithoutZero.map("." + _), + digitsWithoutZero.map(_ + "e"), + digitsWithoutZero.map(_ + "E") + ) + + check(simpleValueGen()) { simpleValue => + assert(JsonValidator.isJson(simpleValue))(Assertion.isFalse) + } && check { + Gen + .listOfN(2)(simpleValueGen()) + .flatMap { l => + Gen.oneOf( + ObjectGenerator() + .copy(commaGenerator = invalidCommaGen) + .generate(l), + ArrayGenerator() + .copy(commaGenerator = invalidCommaGen) + .generate(l) + ) + + } + } { json => + assert(JsonValidator.isJson(json))(Assertion.isFalse) + } && check { + Gen + .listOfN(2)(simpleValueGen()) + .flatMap { l => + Gen.oneOf( + ObjectGenerator() + .copy(whitespaceGenerator = invalidWhiteSpaceGenerator) + .generate(l), + ArrayGenerator() + .copy(whitespaceGenerator = invalidWhiteSpaceGenerator) + .generate(l) + ) + } + } { json => + assert(JsonValidator.isJson(json))(Assertion.isFalse) + } && check { + Gen + .listOfN(2)(simpleValueGen()) + .flatMap { l => + ObjectGenerator() + .copy(colonGenerator = invalidColonGenerator) + .generate(l) + } + } { json => + assert(JsonValidator.isJson(json))(Assertion.isFalse) + } && + check { + simpleValueGen().flatMap { v => + Gen.oneOf( + ObjectGenerator() + .copy(keyGenerator = invalidObjectKeyGenerator) + .generate(List(v)), + invalidStringGenerator.flatMap(invalidString => + ArrayGenerator() + .generate(List(v, invalidString)) + ) + ) + } + } { json => + assert(JsonValidator.isJson(json))(Assertion.isFalse) + } && check { + Gen.oneOf(invalidBooleanOrNull, invalidNumber).flatMap { v => + Gen.oneOf( + ObjectGenerator() + .generate(List(v)), + ArrayGenerator() + .generate(List(v)) + ) + } + } { json => + assert(JsonValidator.isJson(json))(Assertion.isFalse) + } + } @@ samples(50), + test("json example") { + val json = + """ + |{ + | "name": "John Doe", + | "age": 42, + | "weight": 100.5, + | "isEmployed": true, + | "addresses": [ + | { + | "street": "123 Main St", + | "city": "Anytown", + | "state": "CA", + | "zip": "12345" + | }, + | { + | "street": "456 Elm St", + | "city": "Othertown", + | "state": "NY", + | "zip": "67890" + | } + | ], + | "phoneNumbers": [ + | "+1-555-123-4567", + | "+1-555-987-6543" + | ], + | "notes": null + |} + |""".stripMargin + + assert(JsonValidator.isJson(json))(Assertion.isTrue) + } + ) +} diff --git a/core/shared/src/main/scala/zio/logging/internal/JsonValidator.scala b/core/shared/src/main/scala/zio/logging/internal/JsonValidator.scala new file mode 100644 index 00000000..8f7ac6f8 --- /dev/null +++ b/core/shared/src/main/scala/zio/logging/internal/JsonValidator.scala @@ -0,0 +1,202 @@ +package zio.logging.internal + +import scala.annotation.tailrec + +object JsonValidator { + + def isJson(string: String): Boolean = { + val startIdx = stringCouldBeJson(string) + if (startIdx == NOT_A_JSON) false + else + checkJson( + string, + startIdx, + STATE_EXPECTING_VALUE, + if (string(startIdx) == '{') OBJECT + else ARRAY + ) == string.length + } + + private def checkJson( + string: String, + startIdx: Int, + startState: Byte, + blockType: Boolean + ): Int = { + var idx = startIdx + var state = startState + + while (state != STATE_BLOCK_END && idx < string.length) { + val c = string(idx) + + if (isWhitespace(c)) idx += 1 + else if (state == STATE_EXPECTING_VALUE) { + + if (c == '{') idx = checkJson(string, idx + 1, STATE_BLOCK_START, OBJECT) + else if (c == '[') idx = checkJson(string, idx + 1, STATE_BLOCK_START, ARRAY) + else idx = skipSimpleValue(string, idx) + + state = STATE_VALUE_PROCESSED + + } else if (state == STATE_VALUE_PROCESSED) + if (c == ',' && blockType == OBJECT) { + idx = handleObjectKey(string, skipWhitespaces(string, idx + 1)) + state = STATE_EXPECTING_VALUE + } else if (c == ',' && blockType == ARRAY) { + idx += 1 + state = STATE_EXPECTING_VALUE + } else if ((c == '}' && blockType == OBJECT) || (c == ']' && blockType == ARRAY)) { + idx += 1 + state = STATE_BLOCK_END + } else + idx = NOT_A_JSON + else if (state == STATE_BLOCK_START) + if (((c == '}' && blockType == OBJECT) || (c == ']' && blockType == ARRAY))) { + idx += 1 + state = STATE_BLOCK_END + } else if (blockType == OBJECT) { + idx = handleObjectKey(string, skipWhitespaces(string, idx)) + state = STATE_EXPECTING_VALUE + } else + state = STATE_EXPECTING_VALUE + else idx = NOT_A_JSON + } + + idx + } + + private def skipSimpleValue(string: String, startIdx: Int) = + if (startIdx < string.length) { + val c = string(startIdx) + if (c == '"') + skipString(string, startIdx) + else if (isDigit(c) || c == '-') + skipNumber(string, startIdx) + else if (c == 'f' || c == 'n' || c == 't') + skipBooleanOrNull(string, startIdx) + else NOT_A_JSON + } else NOT_A_JSON + + private def handleObjectKey(string: String, startIdx: Int) = { + val idx = skipWhitespaces(string, skipString(string, startIdx)) + if (idx < string.length && string(idx) == ':') idx + 1 + else NOT_A_JSON + } + + private def stringCouldBeJson(string: String): Int = { + val idxStart = skipWhitespaces(string, 0) + val idxEnd = skipWhitespacesBackwards(string, string.length - 1) + + if (idxStart >= string.length || idxEnd <= 0) NOT_A_JSON + else if (string.charAt(idxStart) == '{' & string.charAt(idxEnd) == '}') idxStart + else if (string.charAt(idxStart) == '[' & string.charAt(idxEnd) == ']') idxStart + else NOT_A_JSON + } + + private def skipBooleanOrNull(string: String, idx: Int): Int = + if (idx + 3 >= string.length) NOT_A_JSON + else { + val c1 = string(idx) + val c2 = string(idx + 1) + val c3 = string(idx + 2) + val c4 = string(idx + 3) + val fifthIsE = (idx + 4 < string.length) && string(idx + 4) == 'e' + + if (c1 == 't' && c2 == 'r' && c3 == 'u' && c4 == 'e') + idx + 4 + else if (c1 == 'f' && c2 == 'a' && c3 == 'l' && c4 == 's' && fifthIsE) + idx + 5 + else if (c1 == 'n' && c2 == 'u' && c3 == 'l' && c4 == 'l') + idx + 4 + else + NOT_A_JSON + } + + private def skipString(string: String, startIdx: Int): Int = { + @tailrec def inner(string: String, idx: Int, isBackslashed: Boolean): Int = + if (idx >= string.length) NOT_A_JSON + else if (!isBackslashed && string(idx) == '"') idx + 1 + else inner(string, idx + 1, !isBackslashed && string(idx) == '\\') + + if (startIdx < string.length && string(startIdx) == '"') + inner(string, startIdx + 1, false) + else NOT_A_JSON + } + + @tailrec private def skipWhitespaces(string: String, idx: Int): Int = + if (idx >= string.length) NOT_A_JSON + else if (isWhitespace(string.charAt(idx))) skipWhitespaces(string, idx + 1) + else idx + + @inline private def isWhitespace(c: Char) = + c <= ' ' && whitespaceLookup(c) + + @inline private def isDigit(c: Char) = c >= '0' && c <= '9' + + @tailrec private def skipWhitespacesBackwards(string: String, idx: Int): Int = + if (idx >= string.length || idx <= 0) idx + else if (!isWhitespace(string.charAt(idx))) idx + else skipWhitespacesBackwards(string, idx - 1) + + @tailrec private def skipDigits(string: String, idx: Int): Int = + if (idx >= string.length) NOT_A_JSON + else if (!isDigit(string.charAt(idx))) idx + else skipDigits(string, idx + 1) + + private def skipExponentPart(string: String, startIdx: Int) = + if (startIdx < string.length && (string(startIdx) == 'e' || string(startIdx) == 'E')) { + val idxOfDigitMaybe = if (startIdx + 1 < string.length) { + val c = string(startIdx + 1) + if (c == '-' | c == '+') startIdx + 2 + else startIdx + 1 + } else NOT_A_JSON + + if (idxOfDigitMaybe < string.length && isDigit(string(idxOfDigitMaybe))) skipDigits(string, idxOfDigitMaybe + 1) + else NOT_A_JSON + } else startIdx + + private def skipFractionPart(string: String, startIdx: Int) = + if (startIdx < string.length && string(startIdx) == '.') { + val digitSkippedIdx = skipDigits(string, startIdx + 1) + if (digitSkippedIdx == startIdx + 1) NOT_A_JSON + else digitSkippedIdx + } else startIdx + + private def skipNumber(string: String, startIdx: Int): Int = { + def inner(string: String, startIdx: Int, minusAllowed: Boolean): Int = { + val idxFractionPart = if (startIdx < string.length) { + val c = string(startIdx) + + if (c == '0') startIdx + 1 + else if (isDigit(c)) skipDigits(string, startIdx + 1) + else if (c == '-' && minusAllowed) inner(string, startIdx + 1, false) + else NOT_A_JSON + } else NOT_A_JSON + + skipExponentPart(string, skipFractionPart(string, idxFractionPart)) + } + + inner(string, startIdx, true) + + } + + private val OBJECT = false + private val ARRAY = true + + private val NOT_A_JSON = Int.MaxValue + + private val STATE_EXPECTING_VALUE: Byte = 0 + private val STATE_BLOCK_START: Byte = 1 + private val STATE_VALUE_PROCESSED: Byte = 2 + private val STATE_BLOCK_END: Byte = 3 + + private val whitespaceLookup: Array[Boolean] = { + val lookup = Array.fill(33)(false) + lookup(' ') = true + lookup('\t') = true + lookup('\n') = true + lookup('\r') = true + lookup + } + +} diff --git a/core/shared/src/main/scala/zio/logging/internal/LogAppender.scala b/core/shared/src/main/scala/zio/logging/internal/LogAppender.scala index 6f2a4b68..3e88b124 100644 --- a/core/shared/src/main/scala/zio/logging/internal/LogAppender.scala +++ b/core/shared/src/main/scala/zio/logging/internal/LogAppender.scala @@ -142,6 +142,7 @@ private[logging] object LogAppender { var separateKeyValue: Boolean = false, var writingKey: Boolean = false, val content: mutable.StringBuilder = new mutable.StringBuilder, + var textContentIsJson: Boolean = false, var textContent: mutable.StringBuilder = new mutable.StringBuilder, var quoteTextContent: Boolean = false ) { @@ -163,9 +164,11 @@ private[logging] object LogAppender { if (current.writingKey) current.appendContent(numeric.toString) else current.appendTextContent(numeric.toString, false) - override def appendText(text: String): Unit = + override def appendText(text: String): Unit = { + current.textContentIsJson = JsonValidator.isJson(text) if (current.writingKey) current.appendContent(text) - else current.appendTextContent(text, true) + else current.appendTextContent(text, !current.textContentIsJson) + } def beginStructure(root: Boolean = false): Unit = { stack.push(new State(root = root)); () } @@ -190,7 +193,7 @@ private[logging] object LogAppender { if (current.content.isEmpty && !current.root) { // Simple value if (current.quoteTextContent) result.append("\"") - result.append(JsonEscape(cleanedTextContent)) + result.append(escapeTextContent(cleanedTextContent)) if (current.quoteTextContent) result.append("\"") } else { // Structure @@ -199,7 +202,7 @@ private[logging] object LogAppender { if (current.textContent.nonEmpty) { result.append(""""text_content":""") if (current.quoteTextContent) result.append("\"") - result.append(JsonEscape(cleanedTextContent)) + result.append(escapeTextContent(cleanedTextContent)) if (current.quoteTextContent) result.append("\"") } @@ -242,5 +245,9 @@ private[logging] object LogAppender { stack.clear() beginStructure(true) } + + private def escapeTextContent(content: String): CharSequence = + if (current.textContentIsJson) content + else JsonEscape(content) } } diff --git a/docs/console-logger.md b/docs/console-logger.md index 67567cd2..4eeec03c 100644 --- a/docs/console-logger.md +++ b/docs/console-logger.md @@ -80,26 +80,30 @@ import java.util.UUID object ConsoleJsonApp extends ZIOAppDefault { - private val userLogAnnotation = LogAnnotation[UUID]("user", (_, i) => i, _.toString) + case class User(firstName: String, lastName: String) { + def toJson: String = s"""{"first_name":"$firstName","last_name":"$lastName"}""".stripMargin + } + + private val userLogAnnotation = LogAnnotation[User]("user", (_, u) => u, _.toJson) + private val uuid = LogAnnotation[UUID]("uuid", (_, i) => i, _.toString) override val bootstrap: ZLayer[ZIOAppArgs, Any, Any] = Runtime.removeDefaultLoggers >>> consoleJson( - LogFormat.default + LogFormat.annotation(LogAnnotation.TraceId) + LogFormat.annotation( - userLogAnnotation - ) + LogFormat.default + LogFormat.annotation(LogAnnotation.TraceId) + + LogFormat.annotation(userLogAnnotation) + LogFormat.annotation(uuid) ) - private val users = List.fill(2)(UUID.randomUUID()) + private val uuids = List.fill(2)(UUID.randomUUID()) override def run: ZIO[Scope, Any, ExitCode] = (for { traceId <- ZIO.succeed(UUID.randomUUID()) - _ <- ZIO.foreachPar(users) { uId => + _ <- ZIO.foreachPar(uuids) { uId => { ZIO.logInfo("Starting operation") *> ZIO.sleep(500.millis) *> ZIO.logInfo("Stopping operation") - } @@ userLogAnnotation(uId) + } @@ userLogAnnotation(User("John", "Doe")) @@ uuid(uId) } @@ LogAnnotation.TraceId(traceId) _ <- ZIO.logInfo("Done") } yield ExitCode.success) @@ -110,9 +114,9 @@ object ConsoleJsonApp extends ZIOAppDefault { Expected console output: ``` -{"timestamp":"2022-10-28T13:48:20.350244+02:00","level":"INFO","thread":"zio-fiber-8","message":"Starting operation","trace_id":"674a118e-2944-46a7-8db2-ceb79d91d51d","user":"b4cf9c71-5b1d-4fe1-bfb4-35a6e51483b2"} -{"timestamp":"2022-10-28T13:48:20.350238+02:00","level":"INFO","thread":"zio-fiber-7","message":"Starting operation","trace_id":"674a118e-2944-46a7-8db2-ceb79d91d51d","user":"372071a6-a643-452b-a07c-d0966e556bfa"} -{"timestamp":"2022-10-28T13:48:20.899453+02:00","level":"INFO","thread":"zio-fiber-7","message":"Stopping operation","trace_id":"674a118e-2944-46a7-8db2-ceb79d91d51d","user":"372071a6-a643-452b-a07c-d0966e556bfa"} -{"timestamp":"2022-10-28T13:48:20.899453+02:00","level":"INFO","thread":"zio-fiber-8","message":"Stopping operation","trace_id":"674a118e-2944-46a7-8db2-ceb79d91d51d","user":"b4cf9c71-5b1d-4fe1-bfb4-35a6e51483b2"} -{"timestamp":"2022-10-28T13:48:20.908254+02:00","level":"INFO","thread":"zio-fiber-6","message":"Done"} +{"timestamp":"2023-02-22T00:20:09.04078+01:00 ","level":"INFO","thread":"zio-fiber-6","message":"Starting operation","trace_id":"0c787f94-d8b1-40c6-bcf9-c479a8733902","user":{"first_name":"John","last_name":"Doe"},"uuid":"b997115e-c939-485f-a931-39e16ca9f786"} +{"timestamp":"2023-02-22T00:20:09.040778+01:00","level":"INFO","thread":"zio-fiber-5","message":"Starting operation","trace_id":"0c787f94-d8b1-40c6-bcf9-c479a8733902","user":{"first_name":"John","last_name":"Doe"},"uuid":"da26ff30-57de-44fa-895b-ef7864fc8e7e"} +{"timestamp":"2023-02-22T00:20:09.576845+01:00","level":"INFO","thread":"zio-fiber-6","message":"Stopping operation","trace_id":"0c787f94-d8b1-40c6-bcf9-c479a8733902","user":{"first_name":"John","last_name":"Doe"},"uuid":"b997115e-c939-485f-a931-39e16ca9f786"} +{"timestamp":"2023-02-22T00:20:09.577009+01:00","level":"INFO","thread":"zio-fiber-5","message":"Stopping operation","trace_id":"0c787f94-d8b1-40c6-bcf9-c479a8733902","user":{"first_name":"John","last_name":"Doe"},"uuid":"da26ff30-57de-44fa-895b-ef7864fc8e7e"} +{"timestamp":"2023-02-22T00:20:09.581515+01:00","level":"INFO","thread":"zio-fiber-4","message":"Done"} ``` diff --git a/examples/core/src/main/scala/zio/logging/example/ConsoleJsonApp.scala b/examples/core/src/main/scala/zio/logging/example/ConsoleJsonApp.scala index fb4c9072..550f5379 100644 --- a/examples/core/src/main/scala/zio/logging/example/ConsoleJsonApp.scala +++ b/examples/core/src/main/scala/zio/logging/example/ConsoleJsonApp.scala @@ -22,26 +22,30 @@ import java.util.UUID object ConsoleJsonApp extends ZIOAppDefault { - private val userLogAnnotation = LogAnnotation[UUID]("user", (_, i) => i, _.toString) + case class User(firstName: String, lastName: String) { + def toJson: String = s"""{"first_name":"$firstName","last_name":"$lastName"}""".stripMargin + } + + private val userLogAnnotation = LogAnnotation[User]("user", (_, u) => u, _.toJson) + private val uuid = LogAnnotation[UUID]("uuid", (_, i) => i, _.toString) override val bootstrap: ZLayer[ZIOAppArgs, Any, Any] = Runtime.removeDefaultLoggers >>> consoleJson( - LogFormat.default + LogFormat.annotation(LogAnnotation.TraceId) + LogFormat.annotation( - userLogAnnotation - ) + LogFormat.default + LogFormat.annotation(LogAnnotation.TraceId) + + LogFormat.annotation(userLogAnnotation) + LogFormat.annotation(uuid) ) - private val users = List.fill(2)(UUID.randomUUID()) + private val uuids = List.fill(2)(UUID.randomUUID()) override def run: ZIO[Scope, Any, ExitCode] = (for { traceId <- ZIO.succeed(UUID.randomUUID()) - _ <- ZIO.foreachPar(users) { uId => + _ <- ZIO.foreachPar(uuids) { uId => { ZIO.logInfo("Starting operation") *> ZIO.sleep(500.millis) *> ZIO.logInfo("Stopping operation") - } @@ userLogAnnotation(uId) + } @@ userLogAnnotation(User("John", "Doe")) @@ uuid(uId) } @@ LogAnnotation.TraceId(traceId) _ <- ZIO.logInfo("Done") } yield ExitCode.success)