Module: Tina4::Log

Defined in:
lib/tina4/log.rb

Overview

Structured logger. Conformant to the shared cross-framework contract at plan/v3/fixtures/logger_contract.json (feature 2), decided in plan/v3/features/002-structured-logger.md and ADR-0041.

BREAKING CHANGES from the pre-3.14 logger (this pass, 2026-08-13):

  • Format defaults to JSON in production and TEXT only when TINA4_DEBUG is truthy (Decision 3) -- unchanged in spirit, restated as the shared contract's canonical rule.
  • TINA4_LOG_APPEND is REMOVED -- setting it is now a hard configuration error.
  • TINA4_LOG_STRICT / TINA4_LOG_FUNC accept ONLY the literal tokens "true"/"false" (case-insensitive) -- not "1"/"yes"/"on" (Decision 19: "native booleans, not private truth-token parsing").
  • The legacy bracket level spelling ("[TINA4_LOG_ERROR]") is REMOVED -- it now hard-fails configuration; use the plain name ("ERROR").
  • Embedded CR/LF in a message is now ESCAPED in text format rather than passed through raw (Decision 11), and rotation is delegated to a hand-written, PREDICTIVE, byte-exact LogFileSink rather than stdlib ::Logger (whose backup numbering starts at ".0", not ".1", and whose rotation is reactive).
  • New TINA4_LOG_FILE_LEVEL (default ALL) independently gates the FILE sink; TINA4_LOG_LEVEL now gates the CONSOLE only (2026-08-10 owner override of Decision 8). enabled? accepts an optional sink: and is sink-aware.
  • reset is new: flushes/closes owned sinks and clears the snapshot AND the current thread's request id.
  • close_file_logger is removed (LOG-A02 prohibits it); reset is the one lifecycle method now.

Constant Summary collapse

LEVELS =
{ "ALL" => 0, "DEBUG" => 1, "INFO" => 2, "WARNING" => 3, "ERROR" => 4, "CRITICAL" => 5, "NONE" => 6 }.freeze
DEFAULT_LEVEL =
"INFO"
DEFAULT_FILE_LEVEL =
"ALL"
DEFAULT_ROTATE_SIZE =
10 * 1024 * 1024
DEFAULT_ROTATE_KEEP =
5
MIN_ROTATE_SIZE =
1024
STDOUT_MAX_BYTES =
8192
OVERFLOW_MESSAGE =
"Log event omitted: encoded size exceeds sink limit"
REMOVED_SETTINGS =
{
  "TINA4_LOG_MAX_SIZE" => "removed setting -- use TINA4_LOG_ROTATE_SIZE (bytes, not megabytes)",
  "TINA4_LOG_KEEP" => "removed setting -- use TINA4_LOG_ROTATE_KEEP",
  "TINA4_LOG_APPEND" => "removed setting -- logs always append; truncate explicitly outside logger startup",
  "TINA4_DEBUG_LEVEL" => "removed setting -- use TINA4_LOG_LEVEL",
  "TINA4_LOG_CRITICAL" => "removed setting -- critical always emits, subject only to TINA4_LOG_LEVEL"
}.freeze
COLORS =
{ "DEBUG" => "\e[36m", "INFO" => "\e[32m", "WARNING" => "\e[33m", "ERROR" => "\e[31m", "CRITICAL" => "\e[35m" }.freeze
RESET =
"\e[0m"
JSON_KEY_ORDER =
%w[timestamp level message request_id function context].freeze
CONTROL_CHARS =
/[\x00-\x08\x0b\x0c\x0e-\x1f\x7f]/.freeze

Class Method Summary collapse

Class Method Details

.clear_request_idObject



302
303
304
# File 'lib/tina4/log.rb', line 302

def clear_request_id
  Thread.current[:tina4_request_id] = nil
end

.configurationObject

A defensive native-map copy of the effective, stable configuration.



279
280
281
282
283
284
285
286
287
288
# File 'lib/tina4/log.rb', line 279

def configuration
  snap = ensure_snapshot
  {
    "level" => snap[:level], "file_level" => snap[:file_level], "format" => snap[:format],
    "output" => snap[:output], "log_dir" => snap[:log_dir], "log_file" => snap[:log_file],
    "layout" => snap[:layout], "rotate_size" => snap[:rotate_size], "rotate_keep" => snap[:rotate_keep],
    "strict" => snap[:strict], "caller" => snap[:caller_capture],
    "stdout_enabled" => snap[:stdout_enabled], "file_enabled" => snap[:file_enabled]
  }
end

.configure(log_dir: nil, log_file: nil, level: nil, file_level: nil, format: nil, output: nil, rotate_size: nil, rotate_keep: nil, strict: nil, caller_capture: nil) ⇒ Object

Resolve and activate a new configuration snapshot.

Precedence for every field (ADR-0041): explicit argument, then the matching TINA4_LOG_* environment value, then the built-in default. Every field is validated BEFORE any directory is created or file is opened; a failed reconfiguration leaves the prior snapshot untouched.



192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
# File 'lib/tina4/log.rb', line 192

def configure(log_dir: nil, log_file: nil, level: nil, file_level: nil, format: nil,
               output: nil, rotate_size: nil, rotate_keep: nil, strict: nil, caller_capture: nil)
  REMOVED_SETTINGS.each do |name, hint|
    raise LogConfigurationError.new("#{name} is a removed setting -- #{hint}", setting: name, value: ENV[name]) if ENV.key?(name)
  end

  resolved_level = resolve_level(level, "TINA4_LOG_LEVEL", DEFAULT_LEVEL)
  resolved_file_level = resolve_level(file_level, "TINA4_LOG_FILE_LEVEL", DEFAULT_FILE_LEVEL)
  resolved_format = resolve_format(format)
  stdout_enabled, file_enabled = resolve_output(output)
  resolved_rotate_size = resolve_int(rotate_size, "TINA4_LOG_ROTATE_SIZE", DEFAULT_ROTATE_SIZE, MIN_ROTATE_SIZE)
  resolved_rotate_keep = resolve_int(rotate_keep, "TINA4_LOG_ROTATE_KEEP", DEFAULT_ROTATE_KEEP, 0)
  resolved_strict = resolve_bool(strict, "TINA4_LOG_STRICT", false)
  resolved_caller = resolve_bool(caller_capture, "TINA4_LOG_FUNC", false)

  dir_raw = resolve_str(log_dir, "TINA4_LOG_DIR", "logs", allow_empty: false)
  file_raw = resolve_str(log_file, "TINA4_LOG_FILE", nil, allow_empty: true)

  project_root = Dir.pwd
  dir_candidate = dir_raw
  file_candidate = file_raw
  if file_candidate.nil? && target_is_file?(dir_candidate)
    file_candidate = File.basename(dir_candidate)
    dir_candidate = File.dirname(dir_candidate)
  end

  resolved_log_dir = File.absolute_path?(dir_candidate) ? dir_candidate : File.join(project_root, dir_candidate)
  resolved_log_dir = resolved_log_dir.chomp("/")

  if file_candidate && !file_candidate.empty?
    resolved_log_file = File.absolute_path?(file_candidate) ? file_candidate : File.join(resolved_log_dir, file_candidate)
    layout = "single"
  else
    resolved_log_file = nil
    layout = "directory"
  end

  output_selector = if stdout_enabled && file_enabled
                       "both"
                     else
                       file_enabled ? "file" : "stdout"
                     end

  snap = {
    level: resolved_level, file_level: resolved_file_level, format: resolved_format,
    output: output_selector, log_dir: resolved_log_dir, log_file: resolved_log_file,
    layout: layout, rotate_size: resolved_rotate_size, rotate_keep: resolved_rotate_keep,
    strict: resolved_strict, caller_capture: resolved_caller,
    stdout_enabled: stdout_enabled, file_enabled: file_enabled,
    main_sink: nil, error_sink: nil
  }

  if file_enabled
    if layout == "single"
      sink = LogFileSink.new(resolved_log_file, resolved_rotate_size, resolved_rotate_keep)
      sink.open
      snap[:main_sink] = sink
    else
      main_sink = LogFileSink.new(File.join(resolved_log_dir, "tina4.log"), resolved_rotate_size, resolved_rotate_keep)
      main_sink.open
      error_sink = LogFileSink.new(File.join(resolved_log_dir, "error.log"), resolved_rotate_size, resolved_rotate_keep)
      error_sink.open
      snap[:main_sink] = main_sink
      snap[:error_sink] = error_sink
    end
  end

  # v3.13.14: unbuffer stdout so logs reach `docker logs` / k8s
  # immediately -- a non-TTY $stdout (every container) is
  # block-buffered by default, so lines sat in the buffer until it
  # filled or the process exited.
  $stdout.sync = true if stdout_enabled

  @snapshot = snap
  @pid = Process.pid
  nil
end

.critical(message, context = {}) ⇒ Object

Critical -- the highest severity. Always emitted, subject only to the configured threshold.



357
358
359
# File 'lib/tina4/log.rb', line 357

def critical(message, context = {})
  emit("CRITICAL", message, context)
end

.debug(message, context = {}) ⇒ Object

── event methods (Decision 23, section 5) ───────────────────────



339
340
341
# File 'lib/tina4/log.rb', line 339

def debug(message, context = {})
  emit("DEBUG", message, context)
end

.enabled?(level, sink: nil) ⇒ Boolean

True when level passes the queried sink's threshold and that sink is active. sink: is nil (console, the historical meaning), :console/"console"/:stdout/"stdout", or :file/"file".

Returns:

  • (Boolean)

Raises:



319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
# File 'lib/tina4/log.rb', line 319

def enabled?(level, sink: nil)
  raise LogArgumentError.new("enabled? requires a level", argument: "level") if level.nil?

  key = level.to_s.strip.upcase
  raise LogArgumentError.new("#{level.inspect} is not a valid level", argument: "level", accepted: LEVELS.keys) unless LEVELS.key?(key)

  snap = ensure_snapshot
  sink_key = sink.nil? ? nil : sink.to_s
  case sink_key
  when nil, "console", "stdout"
    snap[:stdout_enabled] && LEVELS[key] >= LEVELS[snap[:level]]
  when "file"
    snap[:file_enabled] && LEVELS[key] >= LEVELS[snap[:file_level]]
  else
    raise LogArgumentError.new("#{sink.inspect} is not a valid sink", argument: "sink", accepted: %w[console file])
  end
end

.error(message, context = {}) ⇒ Object



351
352
353
# File 'lib/tina4/log.rb', line 351

def error(message, context = {})
  emit("ERROR", message, context)
end

.get_request_idObject



297
298
299
300
# File 'lib/tina4/log.rb', line 297

def get_request_id
  discard_state_if_forked
  Thread.current[:tina4_request_id]
end

.info(message, context = {}) ⇒ Object



343
344
345
# File 'lib/tina4/log.rb', line 343

def info(message, context = {})
  emit("INFO", message, context)
end

.resetObject

Flush/close owned sinks, clear the snapshot and the current thread's request id. Idempotent; the next use resolves a fresh snapshot.



272
273
274
275
276
# File 'lib/tina4/log.rb', line 272

def reset
  @snapshot = nil
  Thread.current[:tina4_request_id] = nil
  nil
end

.sanitize_request_id(value) ⇒ Object



306
307
308
309
310
311
312
# File 'lib/tina4/log.rb', line 306

def sanitize_request_id(value)
  return nil if value.nil? || value.empty?
  return nil if value.length > 128
  return nil if value =~ /[^A-Za-z0-9._-]/

  value
end

.set_request_id(request_id) ⇒ Object

── request id (thread-local; Decision 12) ───────────────────────



292
293
294
295
# File 'lib/tina4/log.rb', line 292

def set_request_id(request_id)
  discard_state_if_forked
  Thread.current[:tina4_request_id] = request_id
end

.warning(message, context = {}) ⇒ Object



347
348
349
# File 'lib/tina4/log.rb', line 347

def warning(message, context = {})
  emit("WARNING", message, context)
end