Skip to content

Commit

Permalink
Improve Crystal::Tracing (#15297)
Browse files Browse the repository at this point in the history
- Avoid spaces in fiber names (easier to columnize)
- Support more types (Bool, Char, Time::Span)
  • Loading branch information
ysbaddaden authored Dec 23, 2024
1 parent 47b948f commit bd4e0d4
Show file tree
Hide file tree
Showing 6 changed files with 43 additions and 22 deletions.
2 changes: 1 addition & 1 deletion src/crystal/event_loop/epoll.cr
Original file line number Diff line number Diff line change
Expand Up @@ -55,7 +55,7 @@ class Crystal::EventLoop::Epoll < Crystal::EventLoop::Polling
{% end %}

private def system_run(blocking : Bool, & : Fiber ->) : Nil
Crystal.trace :evloop, "run", blocking: blocking ? 1 : 0
Crystal.trace :evloop, "run", blocking: blocking

# wait for events (indefinitely when blocking)
buffer = uninitialized LibC::EpollEvent[128]
Expand Down
2 changes: 1 addition & 1 deletion src/crystal/event_loop/kqueue.cr
Original file line number Diff line number Diff line change
Expand Up @@ -73,7 +73,7 @@ class Crystal::EventLoop::Kqueue < Crystal::EventLoop::Polling
private def system_run(blocking : Bool, & : Fiber ->) : Nil
buffer = uninitialized LibC::Kevent[128]

Crystal.trace :evloop, "run", blocking: blocking ? 1 : 0
Crystal.trace :evloop, "run", blocking: blocking
timeout = blocking ? nil : Time::Span.zero
kevents = @kqueue.wait(buffer.to_slice, timeout)

Expand Down
6 changes: 3 additions & 3 deletions src/crystal/scheduler.cr
Original file line number Diff line number Diff line change
Expand Up @@ -66,7 +66,7 @@ class Crystal::Scheduler
end

def self.sleep(time : Time::Span) : Nil
Crystal.trace :sched, "sleep", for: time.total_nanoseconds.to_i64!
Crystal.trace :sched, "sleep", for: time
Thread.current.scheduler.sleep(time)
end

Expand Down Expand Up @@ -225,7 +225,7 @@ class Crystal::Scheduler
pending = Atomic(Int32).new(count - 1)
@@workers = Array(Thread).new(count) do |i|
if i == 0
worker_loop = Fiber.new(name: "Worker Loop") { Thread.current.scheduler.run_loop }
worker_loop = Fiber.new(name: "worker-loop") { Thread.current.scheduler.run_loop }
worker_loop.set_current_thread
Thread.current.scheduler.enqueue worker_loop
Thread.current
Expand Down Expand Up @@ -272,7 +272,7 @@ class Crystal::Scheduler

# Background loop to cleanup unused fiber stacks.
def spawn_stack_pool_collector
fiber = Fiber.new(name: "Stack pool collector", &->@stack_pool.collect_loop)
fiber = Fiber.new(name: "stack-pool-collector", &->@stack_pool.collect_loop)
{% if flag?(:preview_mt) %} fiber.set_current_thread {% end %}
enqueue(fiber)
end
Expand Down
2 changes: 1 addition & 1 deletion src/crystal/system/unix/signal.cr
Original file line number Diff line number Diff line change
Expand Up @@ -82,7 +82,7 @@ module Crystal::System::Signal
end

private def self.start_loop
spawn(name: "Signal Loop") do
spawn(name: "signal-loop") do
loop do
value = reader.read_bytes(Int32)
rescue IO::Error
Expand Down
2 changes: 1 addition & 1 deletion src/crystal/system/win32/process.cr
Original file line number Diff line number Diff line change
Expand Up @@ -203,7 +203,7 @@ struct Crystal::System::Process
def self.start_interrupt_loop : Nil
return unless @@setup_interrupt_handler.test_and_set

spawn(name: "Interrupt signal loop") do
spawn(name: "interrupt-signal-loop") do
while true
@@interrupt_count.wait { sleep 50.milliseconds }

Expand Down
51 changes: 36 additions & 15 deletions src/crystal/tracing.cr
Original file line number Diff line number Diff line change
Expand Up @@ -51,37 +51,58 @@ module Crystal
@size = 0
end

def write(bytes : Bytes) : Nil
def write(value : Bytes) : Nil
pos = @size
remaining = N - pos
return if remaining == 0

n = bytes.size.clamp(..remaining)
bytes.to_unsafe.copy_to(@buf.to_unsafe + pos, n)
n = value.size.clamp(..remaining)
value.to_unsafe.copy_to(@buf.to_unsafe + pos, n)
@size = pos + n
end

def write(string : String) : Nil
write string.to_slice
def write(value : String) : Nil
write value.to_slice
end

def write(fiber : Fiber) : Nil
write fiber.as(Void*)
write ":"
write fiber.name || "?"
def write(value : Char) : Nil
chars = uninitialized UInt8[4]
i = 0
value.each_byte do |byte|
chars[i] = byte
i += 1
end
write chars.to_slice[0, i]
end

def write(value : Fiber) : Nil
write value.as(Void*)
write ':'
write value.name || '?'
end

def write(ptr : Pointer) : Nil
def write(value : Pointer) : Nil
write "0x"
System.to_int_slice(ptr.address, 16, true, 2) { |bytes| write(bytes) }
System.to_int_slice(value.address, 16, true, 2) { |bytes| write(bytes) }
end

def write(value : Int::Signed) : Nil
System.to_int_slice(value, 10, true, 2) { |bytes| write(bytes) }
end

def write(value : Int::Unsigned) : Nil
System.to_int_slice(value, 10, false, 2) { |bytes| write(bytes) }
end

def write(value : Time::Span) : Nil
write(value.seconds * Time::NANOSECONDS_PER_SECOND + value.nanoseconds)
end

def write(int : Int::Signed) : Nil
System.to_int_slice(int, 10, true, 2) { |bytes| write(bytes) }
def write(value : Bool) : Nil
write value ? '1' : '0'
end

def write(uint : Int::Unsigned) : Nil
System.to_int_slice(uint, 10, false, 2) { |bytes| write(bytes) }
def write(value : Nil) : Nil
end

def to_slice : Bytes
Expand Down

0 comments on commit bd4e0d4

Please sign in to comment.