Depend on railties instead of rails, support SolidQueue job IDs, and write STDOUT unbuffered

.github/workflows/test.yml

@@ -243,3 +243,18 @@ jobs:
 
       - name: Run Rails integration tests
         run: scripts/rails_tests.sh
+
+  railties_only:
+    name: 'Tests: railties without the rest of Rails'
+    needs: [lint]
+    runs-on: ubuntu-22.04
+    steps:
+      - uses: actions/checkout@v4
+
+      - name: Setup Ruby
+        uses: ruby/setup-ruby@v1
+        with:
+          ruby-version: '.ruby-version'
+
+      - name: Boot an app that only bundles railties and actionpack
+        run: scripts/railties_smoke_test.sh

Gemfile.lock

@@ -2,8 +2,11 @@ PATH
   remote: .
   specs:
     logstruct (0.1.12)
+      actionpack (>= 7.1)
+      activesupport (>= 7.1)
+      globalid (>= 1.0)
       lograge (>= 0.11)
-      rails (>= 7.1)
+      railties (>= 7.1)
       semantic_logger (~> 4.15)
       sorbet-runtime (>= 0.5)
 

lib/log_struct/formatter.rb

@@ -81,13 +81,14 @@ def process_values(arg, recursion_depth: 0, ancestors: {}.compare_by_identity)
           arg.to_global_id
         rescue
           begin
-            case arg
-            when ActiveRecord::Base
-              "#{arg.class}(##{arg.id})"
+            object = T.cast(arg, Object)
+            # Active Record is optional
+            if defined?(::ActiveRecord::Base) && object.is_a?(::ActiveRecord::Base)
+              "#{object.class}(##{object.id})"
             else
               # For non-ActiveRecord objects that failed to_global_id, try to get a string representation
               # If this also fails, we want to catch it and return the error placeholder
-              String(T.cast(arg, Object))
+              String(object)
             end
           rescue => e
             LogStruct.handle_exception(e, source: Source::Internal)

lib/log_struct/integrations/active_job/log_subscriber.rb

@@ -83,7 +83,8 @@ def build_base_fields(job)
             job_class: job.class.to_s,
             queue_name: job.queue_name&.to_sym,
             executions: job.executions,
-            provider_job_id: job.provider_job_id,
+            # Backends use Strings or Integers (SolidQueue uses its job row ID)
+            provider_job_id: job.provider_job_id&.to_s,
             arguments: ((job.class.respond_to?(:log_arguments?) && job.class.log_arguments?) ? job.arguments : nil)
           )
         end

lib/log_struct/semantic_logger/setup.rb

@@ -138,6 +138,11 @@ def self.add_appenders(app)
         # Determine output destination
         io = determine_output(app)
 
+        # Ruby buffers STDOUT when it isn't a terminal, so in a container lines waited until the buffer
+        # filled or the process exited. (GoodJob's executable only syncs STDOUT when it writes its own
+        # text logs there.)
+        io.sync = true if io.equal?($stdout)
+
         if Rails.env.development?
           if config.prefer_json_in_development
             # Default to production-style JSON in development when enabled
@@ -171,8 +176,9 @@ def self.add_appenders(app)
           )
         end
 
-        # Add file appender if Rails has a log path configured (normal Rails behavior)
-        if app.config.paths["log"].first
+        # Add file appender if Rails has a log path configured (normal Rails behavior), unless
+        # RAILS_LOG_TO_STDOUT says to log to STDOUT instead: in a container the file only fills the disk
+        if app.config.paths["log"].first && ENV["RAILS_LOG_TO_STDOUT"].blank?
           ::SemanticLogger.add_appender(
             file_name: app.config.paths["log"].first,
             formatter: LogStruct::SemanticLogger::Formatter.new,

logstruct.gemspec

@@ -33,8 +33,11 @@ Gem::Specification.new do |spec|
   spec.executables = spec.files.grep(%r{\Aexe/}) { |f| File.basename(f) }
   spec.require_paths = ["lib"]
 
+  spec.add_dependency "actionpack", ">= 7.1"
+  spec.add_dependency "activesupport", ">= 7.1"
+  spec.add_dependency "globalid", ">= 1.0"
   spec.add_dependency "lograge", ">= 0.11"
-  spec.add_dependency "rails", ">= 7.1"
+  spec.add_dependency "railties", ">= 7.1"
   spec.add_dependency "semantic_logger", "~> 4.15"
   spec.add_dependency "sorbet-runtime", ">= 0.5"
 

scripts/railties_smoke_test.sh

@@ -0,0 +1,69 @@
+#!/usr/bin/env bash
+# Boots a Rails app whose bundle has railties and actionpack but not the rest of Rails
+# (no Active Record, Active Job, Action Mailer, etc.), and checks that LogStruct sets up
+# and logs a request.
+set -euo pipefail
+
+SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)"
+PROJECT_ROOT="$(dirname "$SCRIPT_DIR")"
+APP_DIR="$(mktemp -d)"
+trap 'rm -rf "$APP_DIR"' EXIT
+
+cat > "$APP_DIR/Gemfile" <<GEMFILE
+source "https://rubygems.org"
+
+gem "logstruct", path: "$PROJECT_ROOT"
+gem "railties", "${RAILS_VERSION:->= 7.1}"
+# ActiveSupport's JSON encoder passes quirks_mode to JSON.generate, which json 3 rejects
+gem "json", "< 3"
+GEMFILE
+
+cat > "$APP_DIR/app.rb" <<'RUBY'
+require "bundler/setup"
+require "rails"
+require "action_controller/railtie"
+require "logstruct"
+
+class SmokeApp < Rails::Application
+  config.load_defaults Rails::VERSION::STRING.to_f
+  config.eager_load = false
+  config.secret_key_base = "0" * 64
+  config.hosts.clear
+  config.logger = ActiveSupport::Logger.new(nil)
+  routes.append { root "smoke#index" }
+end
+
+class SmokeController < ActionController::Base
+  def index
+    Rails.logger.info("smoke test")
+    render plain: "ok"
+  end
+end
+
+Rails.application.initialize!
+
+status, = Rack::MockRequest.new(Rails.application).get("/").then { |r| [r.status] }
+SemanticLogger.flush
+
+missing = %w[activerecord activejob actionmailer activestorage actioncable].select { |name| Gem.loaded_specs.key?(name) }
+raise "Bundle includes #{missing.join(", ")}" if missing.any?
+raise "Expected 200, got #{status}" unless status == 200
+raise "LogStruct isn't enabled" unless LogStruct.enabled?
+
+lines = File.readlines(ENV.fetch("SMOKE_LOG")).map { |line| JSON.parse(line) }
+raise "No app log line in #{lines.inspect}" unless lines.any? { |line| line["msg"] == "smoke test" }
+raise "No request log line in #{lines.inspect}" unless lines.any? { |line| line["evt"] == "request" && line["status"] == 200 }
+
+puts "Railties-only app booted and logged #{lines.size} JSON lines"
+RUBY
+
+mkdir -p "$APP_DIR/log"
+cd "$APP_DIR"
+unset BUNDLE_GEMFILE BUNDLE_PATH BUNDLE_WITH BUNDLE_WITHOUT RUBYOPT
+export BUNDLE_GEMFILE="$APP_DIR/Gemfile"
+export BUNDLE_PATH="$APP_DIR/vendor/bundle"
+bundle install --quiet
+LOGSTRUCT_ENABLED=true RAILS_ENV=production SMOKE_LOG="$APP_DIR/log.jsonl" \
+  bundle exec ruby -e 'STDOUT.reopen(ENV.fetch("SMOKE_LOG"), "w"); STDOUT.sync = true; load "app.rb"' ||
+  { echo "Smoke test failed. Log output:"; cat "$APP_DIR/log.jsonl"; exit 1; }
+tail -1 "$APP_DIR/log.jsonl"

test/log_struct/integrations/active_job/log_subscriber_test.rb

@@ -47,6 +47,20 @@ def perform
           assert_in_delta now.to_f, finished_at.to_f, 5.0
         end
 
+        test "logs Integer provider job IDs as strings" do
+          clear_log_buffer(@log_output)
+
+          job = TestActiveJob.new
+          job.provider_job_id = 2905
+          start_time = ::Process.clock_gettime(::Process::CLOCK_MONOTONIC)
+          event = build_event("perform.active_job", start_time, start_time + 0.1, {job: job})
+
+          @subscriber.perform(event)
+          ::SemanticLogger.flush
+
+          assert_equal "2905", parse_first_log(@log_output)["provider_job_id"]
+        end
+
         private
 
         def build_event(name, start_time, finish_time, payload)

test/log_struct/semantic_logger_test.rb

@@ -4,6 +4,7 @@
 require "test_helper"
 require "log_struct/semantic_logger/formatter"
 require "log_struct/semantic_logger/logger"
+require "tempfile"
 
 module LogStruct
   class SemanticLoggerTest < ActiveSupport::TestCase
@@ -16,6 +17,35 @@ class SemanticLoggerTest < ActiveSupport::TestCase
       teardown_isolated_logger
     end
 
+    test "writes to STDOUT without buffering" do
+      # Like STDOUT when it's a pipe or a file
+      stdout = Tempfile.new("stdout")
+      stdout.sync = false
+      saved_stdout = $stdout
+      $stdout = stdout
+
+      ClimateControl.modify(RAILS_LOG_TO_STDOUT: "true") do
+        LogStruct::SemanticLogger::Setup.add_appenders(Rails.application)
+      end
+
+      assert stdout.sync
+    ensure
+      # Remove the appenders writing to it before closing it; teardown puts back the others
+      ::SemanticLogger.clear_appenders!
+      $stdout = saved_stdout
+      stdout&.close!
+    end
+
+    test "logs only to STDOUT when RAILS_LOG_TO_STDOUT is set" do
+      ClimateControl.modify(RAILS_LOG_TO_STDOUT: "true") do
+        LogStruct::SemanticLogger::Setup.add_appenders(Rails.application)
+      end
+
+      assert_empty(::SemanticLogger.appenders.select { |appender| appender.is_a?(::SemanticLogger::Appender::File) })
+    ensure
+      ::SemanticLogger.clear_appenders!
+    end
+
     test "logs plain messages through SemanticLogger" do
       @logger.info("Test message")
       ::SemanticLogger.flush