FTP Session Logging
Problem this snippet solves: This iRule logs FTP connections and username information. By default connection mapping from client through BIG-IP to server is logged as well as the username entered by...
Published Mar 17, 2015
Version 1.0
pstinson
Nimbostratus
Nimbostratusworked on an irule that might be of some help to people. bit of copilot help and splunk logging with local logging fallback. Just leaving it here if it helps anyone else to log FTP traffic. I also added a session_id generated if you wanted to easily join data log lines together based on a session.
#############################################################################
# FTP Connection Logging iRule with Splunk HSL Integration
#
# PURPOSE:
# Capture full FTP session lifecycle (CLIENT connects → negotiates AUTH
# → connects to backend SERVER → closes) and log to both local syslog
# and Splunk via HSL (High Speed Logging) for real-time SIEM ingestion.
#
# LOGGING ARCHITECTURE:
# - All sessions produce a deterministic session_id for correlation
# - Fields are logged in CONSISTENT ORDER across all event types
# to enable single-regex Splunk field extraction
# - Placeholders (-/unknown) appear for fields not yet populated
# - HSL pool is configured in RULE_INIT for easy updates
# - Local logging continues even if HSL is unavailable (failsafe)
#
# FIELD ORDER (STANDARD ACROSS ALL EVENTS):
# event_type session_id src vip backend user auth inside [event-specific]
#
# FIELD DEFINITIONS:
# event_type = FTP_SESSION_START | FTP_LB_SELECTED | FTP_LB_FAILED |
# FTP_SERVER_CONNECTED | FTP_AUTH_RESULT | FTP_USER_SEEN |
# FTP_SESSION_END | FTP_DEBUG_*
# session_id = Unique per flow: [clock clicks]-[src_ip]-[src_port]
# src = Client IP:Port (initiates FTP connection)
# vip = Virtual IP:Port (BIG-IP listening interface)
# backend = Server IP:Port (backend FTP server, or "-" if unknown)
# user = Extracted FTP username, or "unknown"
# auth = FTP auth result: success | failed | unknown
# inside = BIG-IP local socket to backend, or "-"
# [event-specific] = duration_s, closed_by, result, len, payload, err
#
# SPLUNK EXTRACTION REGEX (works on all events):
# (?<event_type>\w+)\s+session_id=(?<session_id>[\w-]+)\s+src=(?<src>[\d.]+:\d+)
# \s+vip=(?<vip>[\d.]+:\d+)(?:\s+backend=(?<backend>[\d.:-]+))?
# (?:\s+user=(?<user>\w+))?(?:\s+auth=(?<auth>\w+))?(?:\s+inside=(?<inside>[\d.:-]+))?
#
# BEST PRACTICES IMPLEMENTED:
# 1. Consistent field ordering → predictable extraction
# 2. Placeholder values → no "missing field" extraction errors
# 3. TMOS-safe session_id → no MD5/CRC32 dependencies
# 4. HSL failover → logging survives pool unavailability
# 5. Payload truncation → prevents unbounded log growth
# 6. Syslog severity levels → allows filtering by importance
# 7. Comments on lifecycle → makes correlation obvious
#
# SYSLOG SEVERITY MAP (RFC 5424):
# <190> = local7.notice (normal events: start, select, auth, user, end)
# <187> = local7.err (errors: LB_FAILED, HSL_OPEN_FAILED)
# local0.debug (optional debug: payload inspection, disabled by default)
#
# TROUBLESHOOTING:
# - If HSL pool is down, check logs for FTP_HSL_OPEN_FAILED
# - If username not captured, check CLIENT_DATA regex for FTP commands
# - If backend stays "-", verify SERVER_CONNECTED event fires
# - Enable static::debug=1 temporarily to see payload contents
#
#############################################################################
when RULE_INIT {
# HSL destination pool for Splunk forwarding.
# Update this single location to change all logging destinations.
# Must be a UDP pool; Splunk typically listens on 514.
set static::hsl_pool "Pool-Splunk-logging"
# Debug mode: logs full TCP payloads for troubleshooting.
# IMPORTANT: Disable in production (payloads may contain credentials).
# 0 = normal operation (recommended in production)
# 1 = logs payloads up to 120 chars per FTP_DEBUG_* event
set static::debug 0
}
when CLIENT_ACCEPTED {
#=========================================================================
# LIFECYCLE STAGE 1: Client connects to BIG-IP VIP
# At this point: client IP/port known, session starts, no backend yet
#=========================================================================
# Capture client-side tuple: who is connecting?
set source_ip [IP::client_addr]
set source_port [TCP::client_port]
# Capture VIP tuple: which BIG-IP service are they connecting to?
set vip_ip [IP::local_addr]
set vip_port [TCP::local_port]
set vip "${vip_ip}:${vip_port}"
# Generate session_id from high-resolution clock + source tuple.
# This is deterministic and requires no external functions.
# Format: [microseconds since TMOS boot]-[client_ip]-[client_port]
# Guarantees uniqueness even under high connection rates.
set session_id "[clock clicks]-${source_ip}-${source_port}"
# Initialize session lifecycle tracking.
set session_start [clock seconds]
set session_closed 0
# Default values: These will be populated as session progresses.
# Using sensible defaults here ensures log lines never have unset vars.
set user "unknown" ;# Will be filled when USER command captured
set auth_state "unknown" ;# Will become success or failed after 230/530
set server_ip "-" ;# Filled at LB_SELECTED or SERVER_CONNECTED
set server_port "-" ;# Filled at LB_SELECTED or SERVER_CONNECTED
set inside "-" ;# Filled at SERVER_CONNECTED (BIG-IP→backend socket)
set cmd_buf "" ;# Buffer for partial FTP commands across TCP packets
# Open HSL (High Speed Logging) connection to Splunk.
# HSL is non-blocking and async—better than blocking syslog for scale.
# If HSL pool is unavailable, catch error and continue with local logging.
set hsl ""
if {[catch { set hsl [HSL::open -proto UDP -pool $static::hsl_pool] } open_err]} {
# HSL open failed (pool down, network issue, etc.)
# Still log the event locally; Splunk forwarder may pick up local syslog.
set hsl ""
log local0.warn "FTP_HSL_OPEN_FAILED session_id=${session_id} src=${source_ip}:${source_port} vip=${vip} err=${open_err}"
}
# Log session start. This is the FIRST event for every FTP connection.
# Include all standard fields (with placeholders for not-yet-known values).
set msg "FTP_SESSION_START session_id=${session_id} src=${source_ip}:${source_port} vip=${vip} backend=- user=unknown auth=unknown inside=-"
log local0.notice $msg
if {$hsl ne ""} {
# <190> = syslog priority local7.notice (informational, normal flow)
HSL::send $hsl "<190>$msg"
}
}
when LB_SELECTED {
#=========================================================================
# LIFECYCLE STAGE 2: BIG-IP selected a backend server (load balancing)
# At this point: BIG-IP has chosen which FTP server to use from pool
# Note: This is metadata from the pool/LB decision; may differ from
# actual connected server if connection fails.
#=========================================================================
# Capture the server that load balancing selected.
# Use catch blocks: some profiles may not provide LB metadata.
if {[catch { set server_ip [LB::server addr] }]} { set server_ip "-" }
if {[catch { set server_port [LB::server port] }]} { set server_port "-" }
# Log the LB decision. This lets Splunk correlate client→VIP→backend routing.
# Field order: CONSISTENT with all other events.
set msg "FTP_LB_SELECTED session_id=${session_id} src=${source_ip}:${source_port} vip=${vip} backend=${server_ip}:${server_port} user=unknown auth=unknown inside=-"
log local0.notice $msg
if {$hsl ne ""} {
HSL::send $hsl "<190>$msg"
}
}
when LB_FAILED {
#=========================================================================
# ERROR STAGE: Load balancing failed to find a healthy backend
# At this point: No server available in pool (all down, full, etc.)
# Connection will be closed by BIG-IP.
#=========================================================================
# Log the outage event at ERROR severity (lower priority in Splunk).
set msg "FTP_LB_FAILED session_id=${session_id} src=${source_ip}:${source_port} vip=${vip} backend=- user=unknown auth=unknown inside=-"
log local0.err $msg
if {$hsl ne ""} {
# <187> = syslog priority local7.err (error, should trigger alerting)
HSL::send $hsl "<187>$msg"
}
}
when SERVER_CONNECTED {
#=========================================================================
# LIFECYCLE STAGE 3: TCP connection established to backend server
# At this point: 3-way handshake complete, sockets are live
# Server will now send FTP banner (220 response).
#=========================================================================
# Refresh backend IP/port from ACTUAL connection (not LB metadata).
# This is more accurate if the connection succeeded to a different member.
if {[catch { set server_ip [IP::server_addr] }]} { set server_ip "-" }
if {[catch { set server_port [TCP::server_port] }]} { set server_port "-" }
# Capture BIG-IP's local socket address used for this backend connection.
# This "inside" address is useful for:
# - Debugging NAT/routing issues
# - Correlating with backend firewall logs
# - Detecting source IP changes mid-session
set inside "[IP::local_addr]:[TCP::local_port]"
# Log the successful backend connection.
# "inside" field now populated; all core fields present.
set msg "FTP_SERVER_CONNECTED session_id=${session_id} src=${source_ip}:${source_port} vip=${vip} backend=${server_ip}:${server_port} user=unknown auth=unknown inside=${inside}"
log local0.notice $msg
if {$hsl ne ""} {
HSL::send $hsl "<190>$msg"
}
# Start collecting server-side data (FTP banner + responses).
# By collecting first (not sending), we avoid banner-related flow stalls.
# FTP banner is usually 220 "Welcome" which helps signal health.
TCP::collect
}
when SERVER_DATA {
#=========================================================================
# DATA CAPTURE STAGE 1: Server sends FTP response (banner, 230/530, etc.)
# At this point: Inspecting responses to detect auth success/failure
# Field to extract: FTP response code (first 3 chars of line)
#=========================================================================
# Capture the full response payload from the server.
set rsp [TCP::payload]
# Optional debug logging: inspect payload contents (DISABLED IN PRODUCTION).
# Use this only when troubleshooting FTP auth issues.
if {$static::debug == 1} {
set dbg $rsp
if {[string length $dbg] > 120} { set dbg "[string range $dbg 0 119]..." }
# Escape newlines/carriage-returns for safe logging.
set dbg [string map {"\r" "\\r" "\n" "\\n"} $dbg]
# LOG AT DEBUG LEVEL (Splunk may drop these; check index settings).
log local0.debug "FTP_DEBUG_SERVER_DATA session_id=${session_id} src=${source_ip}:${source_port} vip=${vip} backend=${server_ip}:${server_port} user=${user} auth=${auth_state} inside=${inside} len=[TCP::payload length] payload=${dbg}"
}
# Parse FTP response codes to detect authentication status.
# FTP RFC 959 defines these multi-line responses:
# 230 = User logged in, proceed. (AUTH SUCCESS)
# 530 = Not logged in. (AUTH FAILED)
# These responses end with \r\n and may have intermediate lines (421, etc.)
# Use regex to match code at line start: (^|[\r\n])230[ -]
# (^|[\r\n]) = start of payload or after CRLF
# 230[ -] = code followed by space or dash (dash = more lines coming)
if {[regexp {(^|[\r\n])230[ -]} $rsp]} {
# Authorization successful; user can proceed.
set auth_state "success"
set msg "FTP_AUTH_RESULT session_id=${session_id} src=${source_ip}:${source_port} vip=${vip} backend=${server_ip}:${server_port} user=${user} auth=${auth_state} inside=${inside}"
log local0.notice $msg
if {$hsl ne ""} {
HSL::send $hsl "<190>$msg"
}
} elseif {[regexp {(^|[\r\n])530[ -]} $rsp]} {
# Authorization failed; user credentials rejected.
# This is important for security monitoring: detect brute-force attacks.
set auth_state "failed"
set msg "FTP_AUTH_RESULT session_id=${session_id} src=${source_ip}:${source_port} vip=${vip} backend=${server_ip}:${server_port} user=${user} auth=${auth_state} inside=${inside}"
log local0.notice $msg
if {$hsl ne ""} {
HSL::send $hsl "<190>$msg"
}
}
# Release the current data and switch to client-side collection.
# This allows client's next command (RETR, STOR, etc.) to be captured.
TCP::release
clientside { TCP::collect }
}
when CLIENT_DATA {
#=========================================================================
# DATA CAPTURE STAGE 2: Client sends FTP command (USER, PASS, RETR, etc.)
# At this point: Inspecting commands to extract username for logging
# Field to extract: Username from "USER <username>" command
#=========================================================================
# Capture the full command payload from the client.
set payload [TCP::payload]
# Optional debug logging: inspect commands being sent.
# CAUTION: May log passwords if iRule modified to capture PASS command.
if {$static::debug == 1} {
set dbg $payload
if {[string length $dbg] > 120} { set dbg "[string range $dbg 0 119]..." }
set dbg [string map {"\r" "\\r" "\n" "\\n"} $dbg]
log local0.debug "FTP_DEBUG_CLIENT_DATA session_id=${session_id} src=${source_ip}:${source_port} vip=${vip} backend=${server_ip}:${server_port} user=${user} auth=${auth_state} inside=${inside} len=[TCP::payload length] payload=${dbg}"
}
# Buffer commands to handle FTP USER command split across TCP segments.
# Example: First packet = "USER my", Second packet = "account\r\n"
# Concatenate and search for complete "USER myaccount\r\n" pattern.
append cmd_buf $payload
if {[string length $cmd_buf] > 8192} {
# Prevent unbounded growth during long sessions (many commands).
# Keep the most recent 4KB of commands; discard old ones.
set cmd_buf [string range $cmd_buf end-4095 end]
}
# Extract FTP username from the USER command.
# FTP RFC 959: "USER <SP> <username> <CRLF>"
# Example matched line: "USER myaccount\r\n"
# Regex breakdown:
# (^|[\r\n]) = start of buffer or after CRLF (new command)
# USER[ \t]+ = "USER" keyword + whitespace
# ([^\r\n \t]+) = capture non-whitespace chars (the username)
if {[regexp -nocase {(^|[\r\n])USER[ \t]+([^\r\n \t]+)} $cmd_buf -> _prefix _captured_user]} {
# -nocase allows "user", "USER", "User" etc. (FTP is case-insensitive)
# -> _prefix = the (^|[\r\n]) match (we discard it)
# -> _captured_user = the actual username (we keep this)
set user [string trim $_captured_user]
# Log when username is seen. This is important for:
# - Auditing login attempts
# - Detecting which users access which files
# - Correlating with failed auth (compare USER with 530)
set msg "FTP_USER_SEEN session_id=${session_id} src=${source_ip}:${source_port} vip=${vip} backend=${server_ip}:${server_port} user=${user} auth=${auth_state} inside=${inside}"
log local0.notice $msg
if {$hsl ne ""} {
HSL::send $hsl "<190>$msg"
}
# Clear the command buffer to save memory (USER already captured).
set cmd_buf ""
}
# Release the current data and switch back to server-side collection.
# This allows server's next response to be captured (200, 350, etc.).
TCP::release
serverside { TCP::collect }
}
when CLIENT_CLOSED {
#=========================================================================
# LIFECYCLE STAGE 4A: Client closes the connection (or idle timeout)
# At this point: Client terminated the FTP session cleanly
# Calculate session duration and log final state.
#=========================================================================
# Guard against logging the same close event twice.
# Both CLIENT_CLOSED and SERVER_CLOSED can fire; we only want one "END" log.
if {$session_closed == 0} {
set session_closed 1
# Calculate session duration in seconds from session start time.
set duration_s [expr {[clock seconds] - $session_start}]
# Log the final state of the session.
# Include all fields captured during the session:
# - session_id: for correlation
# - src: who was connected
# - user: which account was used (or "unknown" if never sent USER)
# - auth: did they authenticate (success/failed/unknown)
# - backend: which FTP server
# - inside: BIG-IP's local socket
# - duration_s: how long the session lasted
# - closed_by: client or server (helps identify abnormal terminations)
set msg "FTP_SESSION_END session_id=${session_id} src=${source_ip}:${source_port} vip=${vip} backend=${server_ip}:${server_port} user=${user} auth=${auth_state} inside=${inside} duration_s=${duration_s} closed_by=client"
log local0.notice $msg
if {$hsl ne ""} {
HSL::send $hsl "<190>$msg"
}
}
}
when SERVER_CLOSED {
#=========================================================================
# LIFECYCLE STAGE 4B: Server closes the connection
# At this point: Server terminated the FTP session (or idle, network issue)
# Same logging as CLIENT_CLOSED, but with closed_by=server marker.
#=========================================================================
# Guard against duplicate close events.
if {$session_closed == 0} {
set session_closed 1
set duration_s [expr {[clock seconds] - $session_start}]
# Log from server-side perspective.
# closed_by=server indicates the server initiated termination.
# This is unusual in normal FTP (clients usually close), so investigate
# high "closed_by=server" counts: may indicate server timeouts or crashes.
set msg "FTP_SESSION_END session_id=${session_id} src=${source_ip}:${source_port} vip=${vip} backend=${server_ip}:${server_port} user=${user} auth=${auth_state} inside=${inside} duration_s=${duration_s} closed_by=server"
log local0.notice $msg
if {$hsl ne ""} {
HSL::send $hsl "<190>$msg"
}
}
}feel free to alter as you like. Any feedback welcome.