Skip to content

Commit 1ebac25

Browse files
authored
Add active job support and colored job prefix (silva96#54)
* Add active job support and colored job prefix * Add plain ActiveJob support * Fix standard * enrich existing log lines if they dont have the colored job id already * Fix standard * use job_id name instead of jid * add job - request_id to map on the parsing process Add job prefix if needed, on the parsing process Add request id if needed, on the parsing process Also, created a conviniece access method to the state so we don't need to pass it around everywhere.
1 parent 735549f commit 1ebac25

20 files changed

Lines changed: 884 additions & 23 deletions

‎README.md‎

Lines changed: 76 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -187,6 +187,82 @@ LogBench works with JSON-formatted logs. Each log entry should include:
187187
- `message`: SQL query with timing information
188188
- `request_id`: Links query to HTTP request
189189

190+
## Job Logging
191+
192+
LogBench provides enhanced logging for background jobs with colored job prefixes in the TUI. Job logs are automatically prefixed with `[JobClass#job-id]` in orange/yellow color for easy identification.
193+
194+
### ActiveJob
195+
196+
For **ActiveJob** classes, use the job's `logger` method (not `Rails.logger`) to ensure logs get proper job context:
197+
198+
```ruby
199+
class EmailDeliveryJob < ApplicationJob
200+
def perform(user_id)
201+
logger.info "Starting email delivery for user #{user_id}" # ✅ Will have job prefix
202+
203+
user = User.find(user_id)
204+
logger.info "Found user: #{user.email}" # ✅ Will have job prefix
205+
206+
# SQL queries are automatically tagged
207+
user.update!(last_email_sent_at: Time.current) # ✅ Will have job prefix
208+
209+
logger.info "Email delivery completed" # ✅ Will have job prefix
210+
end
211+
end
212+
```
213+
214+
**❌ Don't use `Rails.logger` in ActiveJob:**
215+
```ruby
216+
class EmailDeliveryJob < ApplicationJob
217+
def perform(user_id)
218+
Rails.logger.info "This won't have job prefix" # ❌ No job context
219+
end
220+
end
221+
```
222+
223+
### Plain Sidekiq Jobs
224+
225+
For **plain Sidekiq** jobs (not using ActiveJob), LogBench automatically captures job context:
226+
227+
```ruby
228+
class DataProcessingJob
229+
include Sidekiq::Job
230+
231+
def perform(data_id)
232+
Rails.logger.info "Processing data #{data_id}" # ✅ Will have job prefix
233+
234+
# SQL queries are automatically tagged
235+
data = Data.find(data_id) # ✅ Will have job prefix
236+
data.process!
237+
238+
Rails.logger.info "Data processing completed" # ✅ Will have job prefix
239+
end
240+
end
241+
```
242+
243+
### Job Log Output
244+
245+
In the TUI, job-related logs appear with colored prefixes:
246+
247+
```
248+
🟡[EmailDeliveryJob#email-job-123] Starting email delivery for user 456
249+
🟡[EmailDeliveryJob#email-job-123] Found user: user@example.com
250+
🟡[EmailDeliveryJob#email-job-123] User Load (1.2ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1
251+
🟡[EmailDeliveryJob#email-job-123] Email delivery completed
252+
```
253+
254+
*(🟡 represents yellow bold colored job name, consistent with Rails SQL query coloring)*
255+
256+
### Job Context Detection
257+
258+
LogBench automatically detects job context through:
259+
260+
- **ActiveJob**: Uses Rails' tagged logging system with job class and job ID
261+
- **Plain Sidekiq**: Uses LogBench::Current attributes set by Sidekiq middleware
262+
- **SQL Queries**: Inherit job context from the current request/job execution
263+
264+
No additional configuration is required - job logging works automatically once LogBench is installed.
265+
190266
## Testing
191267

192268
LogBench includes a comprehensive test suite to ensure reliability and correctness.

‎lib/log_bench/app/main.rb‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,7 @@ class Main
1919

2020
def initialize(log_file_path = "log/development.log")
2121
self.log_file_path = find_log_file(log_file_path)
22-
self.state = State.new
22+
self.state = State.instance
2323
validate_log_file!
2424
end
2525

‎lib/log_bench/app/state.rb‎

Lines changed: 18 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,12 +1,20 @@
11
# frozen_string_literal: true
22

3+
require "singleton"
4+
35
module LogBench
46
module App
57
class State
8+
include Singleton
9+
610
attr_reader :main_filter, :sort, :detail_filter, :cleared_requests
711
attr_accessor :requests, :orphan_requests, :auto_scroll, :scroll_offset, :selected, :detail_scroll_offset, :detail_selected_entry, :text_selection_mode, :update_available, :update_version
812

913
def initialize
14+
reset!
15+
end
16+
17+
def reset!
1018
self.requests = []
1119
self.orphan_requests = []
1220
self.selected = 0
@@ -23,6 +31,7 @@ def initialize
2331
self.update_available = false
2432
self.update_version = nil
2533
self.cleared_requests = nil
34+
self.job_ids_map = {}
2635
end
2736

2837
def running?
@@ -280,9 +289,17 @@ def adjust_detail_scroll_for_entry_selection(visible_height, lines)
280289
end
281290
end
282291

292+
def register_job_enqueue(job_id, request_id)
293+
job_ids_map[job_id] = request_id
294+
end
295+
296+
def request_id_for_job(job_id)
297+
job_ids_map[job_id]
298+
end
299+
283300
private
284301

285-
attr_accessor :focused_pane, :running
302+
attr_accessor :focused_pane, :running, :job_ids_map
286303
attr_writer :main_filter, :detail_filter, :sort, :cleared_requests
287304
end
288305
end

‎lib/log_bench/current.rb‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
if defined?(ActiveSupport::CurrentAttributes)
44
module LogBench
55
class Current < ActiveSupport::CurrentAttributes
6-
attribute :request_id
6+
attribute :request_id, :jid, :job_class
77
end
88
end
99
end
Lines changed: 46 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,46 @@
1+
# frozen_string_literal: true
2+
3+
module LogBench
4+
# Shared module for formatting job prefixes with ANSI colors
5+
# Used by both JsonFormatter (when writing logs) and Parser (when reading old logs)
6+
module JobPrefixFormatter
7+
# Job color palette - using standard colors only (no bright colors)
8+
JOB_COLORS = [
9+
31, # Red
10+
32, # Green
11+
33, # Yellow
12+
34, # Blue
13+
35, # Magenta
14+
36 # Cyan
15+
].freeze
16+
17+
# Extract job info from ActiveJob tags
18+
# Returns [job_id, job_class] or nil if not a valid ActiveJob tag
19+
def extract_job_info_from_tags(tags)
20+
return nil unless tags.is_a?(Array) && tags.size >= 3
21+
return nil unless tags[0] == "ActiveJob"
22+
23+
# ActiveJob tags format: ["ActiveJob", "JobClassName", "job-id"]
24+
job_class = tags[1]
25+
job_id = tags[2]
26+
return nil unless job_class && job_id
27+
28+
[job_id, job_class]
29+
end
30+
31+
# Build colored job prefix using ANSI color codes
32+
def build_colored_job_prefix(job_class, job_id)
33+
# Pick a color based on the job ID for visual differentiation
34+
color_code = pick_job_color(job_id)
35+
"\u001b[1m\u001b[#{color_code}m[#{job_class}##{job_id}]\u001b[0m"
36+
end
37+
38+
# Pick a consistent color for a job based on its ID
39+
def pick_job_color(job_id)
40+
# Use a simple hash of the job ID to pick a consistent color
41+
# This ensures the same job ID always gets the same color
42+
hash = job_id.to_s.bytes.sum
43+
JOB_COLORS[hash % JOB_COLORS.length]
44+
end
45+
end
46+
end

‎lib/log_bench/json_formatter.rb‎

Lines changed: 52 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@ module LogBench
88
# JSON logs. Extends TaggedLogging::Formatter for full Rails compatibility.
99
class JsonFormatter < ::Logger::Formatter
1010
include ActiveSupport::TaggedLogging::Formatter
11+
include JobPrefixFormatter
1112

1213
def call(severity, timestamp, progname, message)
1314
log_entry = build_log_entry(severity, timestamp, progname, message)
@@ -25,6 +26,15 @@ def build_log_entry(severity, timestamp, progname, message)
2526
entry = parse_lograge_message(entry[:message]) if lograge_message?(entry)
2627
request_id = current_request_id
2728

29+
# Get job info from Current attributes (direct Sidekiq jobs) or tags (ActiveJob)
30+
job_id, job_class = get_job_info(tags)
31+
32+
# Add colored job prefix to message if we're in a job context
33+
if job_id && job_class && entry[:message]
34+
job_prefix = build_colored_job_prefix(job_class, job_id)
35+
entry[:message] = "#{job_prefix} #{entry[:message]}"
36+
end
37+
2838
base_entry = {
2939
level: severity,
3040
timestamp: timestamp.utc.iso8601(3),
@@ -74,19 +84,50 @@ def parse_lograge_message(message_string)
7484
end
7585

7686
def current_request_id
77-
request_id = nil
78-
79-
if defined?(LogBench::Current) && LogBench::Current.respond_to?(:request_id)
80-
request_id = LogBench::Current.request_id
81-
elsif defined?(Current) && Current.respond_to?(:request_id)
82-
request_id = Current.request_id
83-
elsif defined?(RequestStore) && RequestStore.exist?(:request_id)
84-
request_id = RequestStore.read(:request_id)
85-
elsif Thread.current[:request_id]
86-
request_id = Thread.current[:request_id]
87+
get_current_attribute(:request_id)
88+
end
89+
90+
def current_jid
91+
get_current_attribute(:jid)
92+
end
93+
94+
def current_job_class
95+
get_current_attribute(:job_class)
96+
end
97+
98+
# Generic method to get current attributes from various storage mechanisms
99+
def get_current_attribute(attribute_name)
100+
# Try LogBench::Current first (preferred)
101+
if defined?(LogBench::Current) && LogBench::Current.respond_to?(attribute_name)
102+
return LogBench::Current.public_send(attribute_name)
103+
end
104+
105+
# Try Current (fallback for apps that define their own Current)
106+
if defined?(Current) && Current.respond_to?(attribute_name)
107+
return Current.public_send(attribute_name)
108+
end
109+
110+
# Try RequestStore (for apps using request_store gem)
111+
if defined?(RequestStore) && RequestStore.exist?(attribute_name)
112+
return RequestStore.read(attribute_name)
113+
end
114+
115+
# Try Thread local storage (last resort)
116+
Thread.current[attribute_name]
117+
end
118+
119+
# Get job info from Current attributes (direct Sidekiq jobs) or tags (ActiveJob)
120+
def get_job_info(tags)
121+
# First try Current attributes (for direct Sidekiq jobs)
122+
current_jid = get_current_attribute(:jid)
123+
current_job_class = get_current_attribute(:job_class)
124+
125+
if current_jid && current_job_class
126+
return [current_jid, current_job_class]
87127
end
88128

89-
request_id
129+
# Fallback to tags (for ActiveJob)
130+
extract_job_info_from_tags(tags)
90131
end
91132
end
92133
end

‎lib/log_bench/log/collection.rb‎

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@ class Collection
88
attr_accessor :entries
99

1010
def initialize(input)
11+
self.parsed_entries = nil
1112
self.entries = parse_input(input)
1213
end
1314

@@ -59,6 +60,8 @@ def sort_by_timestamp
5960

6061
private
6162

63+
attr_accessor :parsed_entries
64+
6265
def create_collection_from_requests(requests)
6366
new_collection = self.class.new([])
6467
new_collection.entries = requests
@@ -67,7 +70,7 @@ def create_collection_from_requests(requests)
6770

6871
def parse_input(input)
6972
lines = normalize_input(input)
70-
parsed_entries = Parser.parse_lines(lines)
73+
self.parsed_entries = Parser.parse_lines(lines)
7174
Parser.group_by_request(parsed_entries)
7275
end
7376

‎lib/log_bench/log/entry.rb‎

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
module LogBench
44
module Log
55
class Entry
6-
attr_reader :type, :raw_line, :request_id, :timestamp, :content, :timing
6+
attr_reader :type, :raw_line, :request_id, :timestamp, :content, :timing, :json_data
77

88
def initialize(json_data)
99
self.json_data = json_data
@@ -23,8 +23,7 @@ def related_log?
2323

2424
private
2525

26-
attr_writer :type, :timestamp, :request_id, :content, :timing
27-
attr_accessor :json_data
26+
attr_writer :type, :timestamp, :request_id, :content, :timing, :json_data
2827

2928
def parse_timestamp(timestamp_str)
3029
return Time.now unless timestamp_str
Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,23 @@
1+
# frozen_string_literal: true
2+
3+
module LogBench
4+
module Log
5+
class JobEnqueueEntry < Entry
6+
attr_reader :job_id
7+
8+
def initialize(json_data)
9+
super
10+
self.type = :job_enqueue
11+
self.job_id = extract_job_id
12+
end
13+
14+
private
15+
16+
attr_writer :job_id
17+
18+
def extract_job_id
19+
Parser.extract_job_id_from_enqueue(content)
20+
end
21+
end
22+
end
23+
end

0 commit comments

Comments
 (0)