| 1 |
|
defmodule DaProductAppWeb.Plugs.ApiLogger do |
| 2 |
|
@moduledoc """ |
| 3 |
|
Plug for logging API requests and responses for audit trail compliance. |
| 4 |
|
|
| 5 |
|
This plug captures: |
| 6 |
|
- Full request details (method, path, headers, body) |
| 7 |
|
- Response details (status, headers, body) |
| 8 |
|
- User/partner context for audit |
| 9 |
|
- Timing information |
| 10 |
|
- IP address and user agent |
| 11 |
|
|
| 12 |
|
Sensitive data is automatically sanitized before storage. |
| 13 |
|
""" |
| 14 |
|
|
| 15 |
|
import Plug.Conn |
| 16 |
|
alias DaProductApp.Audit.ApiRequestLog |
| 17 |
|
alias DaProductApp.Repo |
| 18 |
|
alias DaProductApp.FeatureFlags |
| 19 |
|
|
| 20 |
|
require Logger |
| 21 |
|
|
| 22 |
:-( |
def init(opts), do: opts |
| 23 |
|
|
| 24 |
|
def call(conn, _opts) do |
| 25 |
|
# Only log if audit logging is enabled |
| 26 |
:-( |
if FeatureFlags.enabled?(:audit_logging_enabled) do |
| 27 |
:-( |
start_time = System.monotonic_time() |
| 28 |
|
|
| 29 |
|
# Capture request data |
| 30 |
:-( |
request_data = capture_request_data(conn) |
| 31 |
|
|
| 32 |
|
# Register callback to log after response is sent |
| 33 |
:-( |
register_before_send(conn, fn conn -> |
| 34 |
:-( |
end_time = System.monotonic_time() |
| 35 |
:-( |
response_time_ms = System.convert_time_unit(end_time - start_time, :native, :millisecond) |
| 36 |
|
|
| 37 |
|
# Capture response data |
| 38 |
:-( |
response_data = capture_response_data(conn, response_time_ms) |
| 39 |
|
|
| 40 |
|
# Log to database asynchronously |
| 41 |
:-( |
log_request_async(request_data, response_data, conn) |
| 42 |
|
|
| 43 |
:-( |
conn |
| 44 |
|
end) |
| 45 |
|
else |
| 46 |
:-( |
conn |
| 47 |
|
end |
| 48 |
|
end |
| 49 |
|
|
| 50 |
|
# ================================ |
| 51 |
|
# REQUEST DATA CAPTURE |
| 52 |
|
# ================================ |
| 53 |
|
|
| 54 |
|
defp capture_request_data(conn) do |
| 55 |
:-( |
%{ |
| 56 |
:-( |
method: conn.method, |
| 57 |
:-( |
path: conn.request_path, |
| 58 |
:-( |
query_string: conn.query_string, |
| 59 |
:-( |
headers: sanitize_headers(conn.req_headers), |
| 60 |
|
body: capture_request_body(conn), |
| 61 |
|
remote_ip: get_remote_ip(conn), |
| 62 |
|
user_agent: get_user_agent(conn), |
| 63 |
|
content_type: get_req_header(conn, "content-type") |> List.first(), |
| 64 |
|
timestamp: DateTime.utc_now() |
| 65 |
|
} |
| 66 |
|
end |
| 67 |
|
|
| 68 |
|
defp capture_request_body(conn) do |
| 69 |
:-( |
case conn.body_params do |
| 70 |
|
%Plug.Conn.Unfetched{} -> |
| 71 |
|
# Body not yet parsed, try to read from assigns or conn.params |
| 72 |
:-( |
case conn.params do |
| 73 |
:-( |
%{} when map_size(conn.params) == 0 -> nil |
| 74 |
:-( |
params -> sanitize_body_data(params) |
| 75 |
|
end |
| 76 |
|
|
| 77 |
|
body_params when is_map(body_params) -> |
| 78 |
:-( |
sanitize_body_data(body_params) |
| 79 |
|
|
| 80 |
:-( |
_ -> |
| 81 |
|
nil |
| 82 |
|
end |
| 83 |
|
end |
| 84 |
|
|
| 85 |
|
# ================================ |
| 86 |
|
# RESPONSE DATA CAPTURE |
| 87 |
|
# ================================ |
| 88 |
|
|
| 89 |
|
defp capture_response_data(conn, response_time_ms) do |
| 90 |
:-( |
%{ |
| 91 |
:-( |
status_code: conn.status, |
| 92 |
:-( |
headers: sanitize_headers(conn.resp_headers), |
| 93 |
|
body: capture_response_body(conn), |
| 94 |
|
response_time_ms: response_time_ms, |
| 95 |
|
timestamp: DateTime.utc_now() |
| 96 |
|
} |
| 97 |
|
end |
| 98 |
|
|
| 99 |
|
defp capture_response_body(conn) do |
| 100 |
:-( |
case conn.resp_body do |
| 101 |
|
body when is_binary(body) -> |
| 102 |
:-( |
sanitize_response_body(body, get_resp_header(conn, "content-type") |> List.first()) |
| 103 |
|
|
| 104 |
:-( |
_ -> |
| 105 |
|
nil |
| 106 |
|
end |
| 107 |
|
end |
| 108 |
|
|
| 109 |
|
# ================================ |
| 110 |
|
# DATA SANITIZATION |
| 111 |
|
# ================================ |
| 112 |
|
|
| 113 |
|
defp sanitize_headers(headers) do |
| 114 |
:-( |
sensitive_headers = ["authorization", "x-api-key", "cookie", "set-cookie", "x-auth-token"] |
| 115 |
|
|
| 116 |
|
headers |
| 117 |
|
|> Enum.into(%{}) |
| 118 |
|
|> Enum.map(fn {key, value} -> |
| 119 |
:-( |
if String.downcase(key) in sensitive_headers do |
| 120 |
|
{key, "[REDACTED]"} |
| 121 |
|
else |
| 122 |
|
{key, value} |
| 123 |
|
end |
| 124 |
|
end) |
| 125 |
:-( |
|> Enum.into(%{}) |
| 126 |
|
end |
| 127 |
|
|
| 128 |
|
defp sanitize_body_data(data) when is_map(data) do |
| 129 |
:-( |
sensitive_fields = [ |
| 130 |
|
"password", "pin", "cvv", "card_number", "account_number", |
| 131 |
|
"aadhaar", "pan", "otp", "token", "secret", "key", "credentials" |
| 132 |
|
] |
| 133 |
|
|
| 134 |
|
data |
| 135 |
|
|> Enum.map(fn {key, value} -> |
| 136 |
:-( |
if is_sensitive_field?(key, sensitive_fields) do |
| 137 |
|
{key, "[REDACTED]"} |
| 138 |
|
else |
| 139 |
:-( |
case value do |
| 140 |
:-( |
nested when is_map(nested) -> {key, sanitize_body_data(nested)} |
| 141 |
:-( |
list when is_list(list) -> {key, sanitize_list_data(list)} |
| 142 |
:-( |
_ -> {key, value} |
| 143 |
|
end |
| 144 |
|
end |
| 145 |
|
end) |
| 146 |
:-( |
|> Enum.into(%{}) |
| 147 |
|
end |
| 148 |
|
|
| 149 |
:-( |
defp sanitize_body_data(data), do: data |
| 150 |
|
|
| 151 |
|
defp sanitize_list_data(list) do |
| 152 |
:-( |
Enum.map(list, fn item -> |
| 153 |
:-( |
case item do |
| 154 |
:-( |
map when is_map(map) -> sanitize_body_data(map) |
| 155 |
:-( |
_ -> item |
| 156 |
|
end |
| 157 |
|
end) |
| 158 |
|
end |
| 159 |
|
|
| 160 |
:-( |
defp sanitize_response_body(body, content_type) do |
| 161 |
:-( |
cond do |
| 162 |
:-( |
content_type && String.contains?(content_type, "json") -> |
| 163 |
:-( |
case Jason.decode(body) do |
| 164 |
|
{:ok, json_data} -> |
| 165 |
|
json_data |
| 166 |
|
|> sanitize_body_data() |
| 167 |
:-( |
|> Jason.encode!() |
| 168 |
|
|
| 169 |
:-( |
{:error, _} -> |
| 170 |
|
"[INVALID_JSON]" |
| 171 |
|
end |
| 172 |
|
|
| 173 |
:-( |
String.length(body) > 10000 -> |
| 174 |
|
"[RESPONSE_TOO_LARGE]" |
| 175 |
|
|
| 176 |
:-( |
true -> |
| 177 |
:-( |
body |
| 178 |
|
end |
| 179 |
|
rescue |
| 180 |
:-( |
_ -> "[SANITIZATION_ERROR]" |
| 181 |
|
end |
| 182 |
|
|
| 183 |
|
defp is_sensitive_field?(field_name, sensitive_fields) do |
| 184 |
:-( |
field_lower = String.downcase(to_string(field_name)) |
| 185 |
:-( |
Enum.any?(sensitive_fields, &String.contains?(field_lower, &1)) |
| 186 |
|
end |
| 187 |
|
|
| 188 |
|
# ================================ |
| 189 |
|
# UTILITY FUNCTIONS |
| 190 |
|
# ================================ |
| 191 |
|
|
| 192 |
|
defp get_remote_ip(conn) do |
| 193 |
:-( |
case get_req_header(conn, "x-forwarded-for") do |
| 194 |
|
[forwarded | _] -> |
| 195 |
|
forwarded |
| 196 |
|
|> String.split(",") |
| 197 |
|
|> List.first() |
| 198 |
:-( |
|> String.trim() |
| 199 |
|
|
| 200 |
|
[] -> |
| 201 |
:-( |
case conn.remote_ip do |
| 202 |
:-( |
{a, b, c, d} -> "#{a}.#{b}.#{c}.#{d}" |
| 203 |
|
{a, b, c, d, e, f, g, h} -> |
| 204 |
:-( |
"#{Integer.to_string(a, 16)}:#{Integer.to_string(b, 16)}:#{Integer.to_string(c, 16)}:#{Integer.to_string(d, 16)}:#{Integer.to_string(e, 16)}:#{Integer.to_string(f, 16)}:#{Integer.to_string(g, 16)}:#{Integer.to_string(h, 16)}" |
| 205 |
:-( |
_ -> "unknown" |
| 206 |
|
end |
| 207 |
|
end |
| 208 |
|
end |
| 209 |
|
|
| 210 |
|
defp get_user_agent(conn) do |
| 211 |
:-( |
get_req_header(conn, "user-agent") |> List.first() || "unknown" |
| 212 |
|
end |
| 213 |
|
|
| 214 |
|
defp get_user_context(conn) do |
| 215 |
:-( |
%{ |
| 216 |
|
user_id: get_user_id_from_conn(conn), |
| 217 |
|
partner_id: get_partner_id_from_conn(conn), |
| 218 |
|
session_id: get_session_id_from_conn(conn) |
| 219 |
|
} |
| 220 |
|
end |
| 221 |
|
|
| 222 |
|
defp get_user_id_from_conn(conn) do |
| 223 |
:-( |
case conn.assigns do |
| 224 |
:-( |
%{current_user: %{id: user_id}} -> user_id |
| 225 |
:-( |
%{user_id: user_id} -> user_id |
| 226 |
:-( |
_ -> nil |
| 227 |
|
end |
| 228 |
|
end |
| 229 |
|
|
| 230 |
|
defp get_partner_id_from_conn(conn) do |
| 231 |
:-( |
case conn.assigns do |
| 232 |
:-( |
%{current_partner: %{id: partner_id}} -> partner_id |
| 233 |
:-( |
%{partner_id: partner_id} -> partner_id |
| 234 |
:-( |
_ -> nil |
| 235 |
|
end |
| 236 |
|
end |
| 237 |
|
|
| 238 |
|
defp get_session_id_from_conn(conn) do |
| 239 |
:-( |
case get_session(conn, "session_id") do |
| 240 |
|
nil -> |
| 241 |
:-( |
case get_req_header(conn, "x-session-id") do |
| 242 |
:-( |
[session_id | _] -> session_id |
| 243 |
:-( |
[] -> nil |
| 244 |
|
end |
| 245 |
:-( |
session_id -> session_id |
| 246 |
|
end |
| 247 |
|
end |
| 248 |
|
|
| 249 |
|
# ================================ |
| 250 |
|
# ASYNC LOGGING |
| 251 |
|
# ================================ |
| 252 |
|
|
| 253 |
|
defp log_request_async(request_data, response_data, conn) do |
| 254 |
:-( |
user_context = get_user_context(conn) |
| 255 |
|
|
| 256 |
|
# Use Task for async logging to avoid blocking the response |
| 257 |
:-( |
Task.start(fn -> |
| 258 |
:-( |
try do |
| 259 |
:-( |
log_entry = %{ |
| 260 |
|
request_id: generate_request_id(), |
| 261 |
:-( |
method: request_data.method, |
| 262 |
:-( |
path: request_data.path, |
| 263 |
:-( |
query_params: request_data.query_string, |
| 264 |
:-( |
request_headers: request_data.headers, |
| 265 |
:-( |
request_body: request_data.body, |
| 266 |
:-( |
response_status: response_data.status_code, |
| 267 |
:-( |
response_headers: response_data.headers, |
| 268 |
:-( |
response_body: response_data.body, |
| 269 |
:-( |
response_time_ms: response_data.response_time_ms, |
| 270 |
:-( |
ip_address: request_data.remote_ip, |
| 271 |
:-( |
user_agent: request_data.user_agent, |
| 272 |
:-( |
user_id: user_context.user_id, |
| 273 |
:-( |
partner_id: user_context.partner_id, |
| 274 |
:-( |
session_id: user_context.session_id, |
| 275 |
:-( |
created_at: request_data.timestamp |
| 276 |
|
} |
| 277 |
|
|
| 278 |
|
%ApiRequestLog{} |
| 279 |
|
|> ApiRequestLog.changeset(log_entry) |
| 280 |
|
|> Repo.insert() |
| 281 |
:-( |
|> case do |
| 282 |
:-( |
{:ok, _} -> |
| 283 |
|
:ok |
| 284 |
|
|
| 285 |
|
{:error, changeset} -> |
| 286 |
:-( |
Logger.error("Failed to log API request: #{inspect(changeset)}") |
| 287 |
|
|
| 288 |
|
# Fallback to file logging if database fails |
| 289 |
:-( |
if FeatureFlags.enabled?(:file_logging_fallback) do |
| 290 |
:-( |
log_to_file(log_entry) |
| 291 |
|
end |
| 292 |
|
end |
| 293 |
|
rescue |
| 294 |
:-( |
error -> |
| 295 |
:-( |
Logger.error("API logging error: #{inspect(error)}") |
| 296 |
|
|
| 297 |
|
# Fallback to basic logging |
| 298 |
:-( |
Logger.info("API: #{request_data.method} #{request_data.path} -> #{response_data.status_code} (#{response_data.response_time_ms}ms)") |
| 299 |
|
end |
| 300 |
|
end) |
| 301 |
|
end |
| 302 |
|
|
| 303 |
|
defp generate_request_id do |
| 304 |
:-( |
:crypto.strong_rand_bytes(16) |> Base.url_encode64(padding: false) |
| 305 |
|
end |
| 306 |
|
|
| 307 |
:-( |
defp log_to_file(log_entry) do |
| 308 |
:-( |
log_dir = Application.get_env(:da_product_app, :log_directory, "logs") |
| 309 |
:-( |
File.mkdir_p!(log_dir) |
| 310 |
|
|
| 311 |
:-( |
log_file = Path.join(log_dir, "api_requests_#{Date.utc_today()}.json") |
| 312 |
:-( |
log_line = Jason.encode!(log_entry) <> "\n" |
| 313 |
|
|
| 314 |
:-( |
File.write!(log_file, log_line, [:append]) |
| 315 |
|
rescue |
| 316 |
:-( |
error -> |
| 317 |
:-( |
Logger.error("Failed to write API log to file: #{inspect(error)}") |
| 318 |
|
end |
| 319 |
|
end |