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 the client. Optionally you can log the entire FTP session by uncommenting the log message in CLIENT_DATA.

Code :

# 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 the client. Optionally you can log the 
# entire FTP session by uncommenting the log message in CLIENT_DATA.

when CLIENT_ACCEPTED {
    set vip [IP::local_addr]:[TCP::local_port]
    set user "unknown"
}

when CLIENT_DATA {
    # uncomment for full session logging
    #log local0. "[IP::client_addr]:[TCP::client_port]: collected payload ([TCP::payload length]): [TCP::payload]"
    
    # check if payload contains the string we want to replace
    if { [TCP::payload] contains "USER" } {
        # use a regular expression to save the user name
        ## regex modified by arkashik
        regexp "USER \(\[a-zA-Z0-9_-]+)"  [TCP::payload] all user

        # log connection mapping from client through BIG-IP to server
        log local0. "FTP connection from $client. Mapped to $inside -> $node, user $user"
        TCP::release
        TCP::collect
    } else {
        TCP::release
        TCP::collect
    }
}

when SERVER_CONNECTED {
    set client "[IP::client_addr]:[TCP::client_port]"
    set node "[IP::server_addr]:[TCP::server_port]"
    set inside "[serverside {IP::local_addr}]:[serverside {TCP::local_port}]"
    TCP::collect
}
 
when SERVER_DATA {
    TCP::release
    clientside { TCP::collect }
}
1 Like

I’m not good with TCL, is there a way to change the way the logging is done? I want to send it through HSL like I do for HTTP?

The regex doesn’t work to capture a username with a dot or other special characters in it. And, regex can be expensive cpu wise.

This irule seems to work well by just matching on the payload containing USER and printing that, then you don’t even need the regex. Also lets you capture if someone is trying to brute force with other special characters.

Rule /Common/log_ftp_sessions : FTP 10.0.0.0:60469: collected payload (30): USER S:LDEFJ:SLDFJS:DLFJ@@%

check if payload contains the string we want to log
if { [TCP::payload] contains "USER" } {
    log local0. "FTP Client IP [IP::client_addr]:[TCP::client_port]: ([TCP::payload length]): [TCP::payload]"

Although of course, if the user’s password is USER, it’ll capture the password.. but you’re using stricter password requirements than that, right? :wink:

Hello there,

I’m used this Irule to log every ftp session. At the moment works perfectly for me, but i realized that some things are not being logged. For example:

When a client get a file from the ftp behind the F5, last log shows " RETR filename ", that is ok, but I would like to add when the transfer has been completed and finally when the client disconnect.

Could be possible? Regards

I tried this irule but it logs the password in plain text. How to mask the password or remove it from logging.

worked 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.