Skip to content

Commit 26369ff

Browse files
committed
feat: enhance telemetry system with comprehensive event logging
- Replace Logger.debug calls with structured telemetry events throughout the system - Add new telemetry events for worker lifecycle, session management, and cleanup operations - Implement TelemetryLogger module for backward-compatible logging behavior - Add helper functions for session module detection and enhanced metadata collection - Provide configurable event handlers for different logging levels and event types
1 parent b97039e commit 26369ff

File tree

5 files changed

+373
-6
lines changed

5 files changed

+373
-6
lines changed

lib/phoenix/session_process/cleanup.ex

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -97,7 +97,8 @@ defmodule Phoenix.SessionProcess.Cleanup do
9797
@impl true
9898
def handle_info({:cleanup_session, session_id}, state) do
9999
if Phoenix.SessionProcess.ProcessSupervisor.session_process_started?(session_id) do
100-
Logger.debug("Auto-cleanup expired session: #{session_id}")
100+
session_pid = Phoenix.SessionProcess.ProcessSupervisor.session_process_pid(session_id)
101+
Phoenix.SessionProcess.Telemetry.emit_auto_cleanup_event(session_id, Phoenix.SessionProcess.Helpers.get_session_module(session_pid), session_pid)
101102
Phoenix.SessionProcess.terminate(session_id)
102103
end
103104

lib/phoenix/session_process/helpers.ex

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -177,4 +177,15 @@ defmodule Phoenix.SessionProcess.Helpers do
177177
{:error, reason}
178178
end
179179
end
180+
181+
@doc """
182+
Gets the session module for a given process PID.
183+
"""
184+
@spec get_session_module(pid()) :: module()
185+
def get_session_module(pid) do
186+
case Registry.lookup(Phoenix.SessionProcess.Registry, pid) do
187+
[{_, module}] -> module
188+
_ -> Phoenix.SessionProcess.Config.session_process()
189+
end
190+
end
180191
end

lib/phoenix/session_process/process_superviser.ex

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -126,7 +126,7 @@ defmodule Phoenix.SessionProcess.ProcessSupervisor do
126126
"""
127127
def start_child(worker, worker_arg) do
128128
worker_spec = {worker, worker_arg}
129-
Logger.debug("Start Child Worker: #{inspect(worker_spec)}")
129+
Phoenix.SessionProcess.Telemetry.emit_worker_start(worker_spec)
130130
DynamicSupervisor.start_child(__MODULE__, worker_spec)
131131
end
132132

@@ -143,7 +143,7 @@ defmodule Phoenix.SessionProcess.ProcessSupervisor do
143143
- `{:error, reason}` - Failed to terminate child process
144144
"""
145145
def terminate_child(pid) do
146-
Logger.debug("Terminating Child Worker: #{inspect(pid)}")
146+
Phoenix.SessionProcess.Telemetry.emit_worker_terminate(pid)
147147
DynamicSupervisor.terminate_child(__MODULE__, pid)
148148
end
149149

@@ -255,7 +255,7 @@ defmodule Phoenix.SessionProcess.ProcessSupervisor do
255255
"""
256256
@spec terminate_session(binary()) :: :ok | {:error, :not_found}
257257
def terminate_session(session_id) do
258-
Logger.debug("End Session: #{inspect(session_id)}")
258+
Phoenix.SessionProcess.Telemetry.emit_session_end_event(session_id)
259259
start_time = System.monotonic_time()
260260

261261
case session_process_pid(session_id) do
@@ -360,7 +360,7 @@ defmodule Phoenix.SessionProcess.ProcessSupervisor do
360360

361361
with :ok <- validate_session_id(session_id),
362362
:ok <- check_session_limits() do
363-
Logger.debug("Start Session: #{inspect(session_id)}")
363+
Phoenix.SessionProcess.Telemetry.emit_session_start_event(session_id)
364364

365365
worker_args =
366366
if arg, do: [name: child_name(session_id), arg: arg], else: [name: child_name(session_id)]

lib/phoenix/session_process/telemetry.ex

Lines changed: 71 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -19,14 +19,24 @@ defmodule Phoenix.SessionProcess.Telemetry do
1919
- `[:phoenix, :session_process, :cast]` - When a cast is made to a session
2020
- `[:phoenix, :session_process, :communication_error]` - When communication fails
2121
22+
### Process Management
23+
- `[:phoenix, :session_process, :worker_start]` - When a worker process starts
24+
- `[:phoenix, :session_process, :worker_terminate]` - When a worker process terminates
25+
- `[:phoenix, :session_process, :session_start]` - When a session process starts
26+
- `[:phoenix, :session_process, :session_end]` - When a session process ends
27+
2228
### Cleanup
29+
- `[:phoenix, :session_process, :auto_cleanup]` - When a session is auto-cleaned up
2330
- `[:phoenix, :session_process, :cleanup]` - When a session is cleaned up
2431
- `[:phoenix, :session_process, :cleanup_error]` - When cleanup fails
2532
2633
All events include the following metadata:
27-
- `session_id` - The session ID
34+
- `session_id` - The session ID (when applicable)
2835
- `module` - The session module
2936
- `pid` - The process PID (when applicable)
37+
- `worker_spec` - Worker specification details (for worker events)
38+
- `operation` - Operation type (for error events)
39+
- `reason` - Error reason (for error events)
3040
- `measurements` - Performance measurements
3141
"""
3242

@@ -171,4 +181,64 @@ defmodule Phoenix.SessionProcess.Telemetry do
171181
:erlang.raise(kind, reason, __STACKTRACE__)
172182
end
173183
end
184+
185+
@doc """
186+
Emits a telemetry event for worker process start.
187+
"""
188+
@spec emit_worker_start(term(), keyword()) :: :ok
189+
def emit_worker_start(worker_spec, measurements \\ []) do
190+
:telemetry.execute(
191+
[:phoenix, :session_process, :worker_start],
192+
Map.new(measurements),
193+
%{worker_spec: inspect(worker_spec)}
194+
)
195+
end
196+
197+
@doc """
198+
Emits a telemetry event for worker process termination.
199+
"""
200+
@spec emit_worker_terminate(pid(), keyword()) :: :ok
201+
def emit_worker_terminate(pid, measurements \\ []) do
202+
:telemetry.execute(
203+
[:phoenix, :session_process, :worker_terminate],
204+
Map.new(measurements),
205+
%{pid: pid}
206+
)
207+
end
208+
209+
@doc """
210+
Emits a telemetry event for session process start.
211+
"""
212+
@spec emit_session_start_event(String.t(), atom(), pid(), keyword()) :: :ok
213+
def emit_session_start_event(session_id, measurements \\ []) do
214+
:telemetry.execute(
215+
[:phoenix, :session_process, :session_start],
216+
Map.new(measurements),
217+
%{session_id: session_id}
218+
)
219+
end
220+
221+
@doc """
222+
Emits a telemetry event for session process end.
223+
"""
224+
@spec emit_session_end_event(String.t(), atom(), pid(), keyword()) :: :ok
225+
def emit_session_end_event(session_id, measurements \\ []) do
226+
:telemetry.execute(
227+
[:phoenix, :session_process, :session_end],
228+
Map.new(measurements),
229+
%{session_id: session_id}
230+
)
231+
end
232+
233+
@doc """
234+
Emits a telemetry event for automatic session cleanup.
235+
"""
236+
@spec emit_auto_cleanup_event(String.t(), atom(), pid(), keyword()) :: :ok
237+
def emit_auto_cleanup_event(session_id, module, pid, measurements \\ []) do
238+
:telemetry.execute(
239+
[:phoenix, :session_process, :auto_cleanup],
240+
Map.new(measurements),
241+
%{session_id: session_id, module: module, pid: pid}
242+
)
243+
end
174244
end

0 commit comments

Comments
 (0)