fix: Converts time to use rfc3339 w/ 3 precision on json logs (27ff1033) · Commits · GitLab.org / ruby / gems / labkit-ruby

lib/labkit/logging/json_logger.rb

+18 −5

Original line number	Diff line number	Diff line
		# frozen_string_literal: true
		require "time"
		require "date"
		require "logger"
		require "json"

		@@ -52,7 +53,7 @@ module Labkit
		data[:message] = message
		when Hash
		reject_reserved_log_keys!(message)
		format_time!(data)
		format_time!(message)
		data.merge!(message)
		end

		@@ -81,11 +82,23 @@ module Labkit

		def format_time!(hash)
		hash.each do \|key, value\|
		if value.is_a?(Time)
		hash[key] = value.utc.iso8601(3)
		elsif value.is_a?(Hash)
		format_time!(value)
		hash[key] = convert_time_value(value)
		end
		end

		def convert_time_value(value)
		case value
		when Time
		value.utc.iso8601(3)
		when DateTime
		value.to_time.utc.iso8601(3)
		when Hash
		format_time!(value)
		value
		when Array
		value.map { \|v\| convert_time_value(v) }
		else
		value
		end
		end
		end

spec/labkit/logging/json_logger_spec.rb

+118 −0

Original line number	Diff line number	Diff line
		@@ -176,6 +176,124 @@ RSpec.describe Labkit::Logging::JsonLogger do
		end
		end

		describe "time formatting" do
		let(:time_value) { Time.utc(2024, 1, 15, 10, 30, 45, 123456) }
		let(:datetime_value) { DateTime.new(2024, 1, 15, 10, 30, 45.123456, '+00:00') }
		let(:expected_iso8601) { "2024-01-15T10:30:45.123Z" }

		it "formats Time values to iso8601(3)" do
		output = subject.format_message("INFO", now, "test", { timestamp: time_value })
		data = JSON.parse(output)

		expect(data["timestamp"]).to eq(expected_iso8601)
		end

		it "formats DateTime values to iso8601(3)" do
		output = subject.format_message("INFO", now, "test", { timestamp: datetime_value })
		data = JSON.parse(output)

		expect(data["timestamp"]).to eq(expected_iso8601)
		end

		it "formats Time values in nested hashes" do
		output = subject.format_message("INFO", now, "test", {
		event: {
		created_at: time_value,
		metadata: {
		updated_at: time_value
		}
		}
		})
		data = JSON.parse(output)

		expect(data["event"]["created_at"]).to eq(expected_iso8601)
		expect(data["event"]["metadata"]["updated_at"]).to eq(expected_iso8601)
		end

		it "formats DateTime values in nested hashes" do
		output = subject.format_message("INFO", now, "test", {
		event: {
		created_at: datetime_value,
		metadata: {
		updated_at: datetime_value
		}
		}
		})
		data = JSON.parse(output)

		expect(data["event"]["created_at"]).to eq(expected_iso8601)
		expect(data["event"]["metadata"]["updated_at"]).to eq(expected_iso8601)
		end

		it "formats Time values in arrays" do
		output = subject.format_message("INFO", now, "test", {
		timestamps: [time_value, time_value]
		})
		data = JSON.parse(output)

		expect(data["timestamps"]).to eq([expected_iso8601, expected_iso8601])
		end

		it "formats DateTime values in arrays" do
		output = subject.format_message("INFO", now, "test", {
		timestamps: [datetime_value, datetime_value]
		})
		data = JSON.parse(output)

		expect(data["timestamps"]).to eq([expected_iso8601, expected_iso8601])
		end

		it "formats Time values in nested arrays" do
		output = subject.format_message("INFO", now, "test", {
		events: [
		{ created_at: time_value },
		{ created_at: time_value }
		]
		})
		data = JSON.parse(output)

		expect(data["events"][0]["created_at"]).to eq(expected_iso8601)
		expect(data["events"][1]["created_at"]).to eq(expected_iso8601)
		end

		it "handles mixed types in arrays" do
		output = subject.format_message("INFO", now, "test", {
		mixed: [time_value, "string", 42, { nested_time: datetime_value }]
		})
		data = JSON.parse(output)

		expect(data["mixed"][0]).to eq(expected_iso8601)
		expect(data["mixed"][1]).to eq("string")
		expect(data["mixed"][2]).to eq(42)
		expect(data["mixed"][3]["nested_time"]).to eq(expected_iso8601)
		end

		it "preserves non-time values" do
		output = subject.format_message("INFO", now, "test", {
		string: "hello",
		number: 42,
		boolean: true,
		null: nil,
		timestamp: time_value
		})
		data = JSON.parse(output)

		expect(data["string"]).to eq("hello")
		expect(data["number"]).to eq(42)
		expect(data["boolean"]).to be(true)
		expect(data["null"]).to be_nil
		expect(data["timestamp"]).to eq(expected_iso8601)
		end

		it "converts Time values with different timezones to UTC" do
		local_time = Time.new(2024, 1, 15, 15, 30, 45.123456, "+05:00")
		output = subject.format_message("INFO", now, "test", { timestamp: local_time })
		data = JSON.parse(output)

		expect(data["timestamp"]).to eq("2024-01-15T10:30:45.123Z")
		end
		end

		describe "reserved log keys" do
		let(:reserved_key_data) { described_class::RESERVED_LOG_KEYS.to_h { \|k\| [k, 42] } }
		let(:expected_error) { /^The following log keys used are reserved: #{described_class::RESERVED_LOG_KEYS.join(", ")}.*/ }