Add SSH Structured Logging (Phase 1-5): ssh_audit_log.rs module with JSON tracing

Features:
- SshAuditLog: Structured audit logging using tracing crate
- 16 audit event types (connection/auth/command/file/port_forward)
- JSON output format via tracing-subscriber json layer
- 10 unit tests for all audit events

Files:
- markbase-core/src/ssh_server/ssh_audit_log.rs (289 lines)
- markbase-core/Cargo.toml (tracing + json layer)
- markbase-core/src/ssh_server/mod.rs (export module)

Tests: 298 passed (+10)
This commit is contained in:
Warren
2026-06-21 11:29:04 +08:00
parent 3d0d031677
commit 2ca543fd66
4 changed files with 412 additions and 1 deletions

14
Cargo.lock generated
View File

@@ -2919,6 +2919,7 @@ dependencies = [
"tokio-postgres",
"tokio-util",
"toml",
"tracing",
"tracing-subscriber",
"unrar",
"ureq",
@@ -5868,6 +5869,16 @@ dependencies = [
"tracing-core",
]
[[package]]
name = "tracing-serde"
version = "0.2.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "704b1aeb7be0d0a84fc9828cae51dab5970fee5088f83d1dd7ee6f6246fc6ff1"
dependencies = [
"serde",
"tracing-core",
]
[[package]]
name = "tracing-subscriber"
version = "0.3.23"
@@ -5878,12 +5889,15 @@ dependencies = [
"nu-ansi-term",
"once_cell",
"regex-automata",
"serde",
"serde_json",
"sharded-slab",
"smallvec",
"thread_local",
"tracing",
"tracing-core",
"tracing-log",
"tracing-serde",
]
[[package]]

View File

@@ -76,7 +76,8 @@ smb2 = { path = "../vendor/smb2" } # Pure-Rust SMB2/3 client library with pipel
# === SMB/CIFS Server (Phase 2) — optional (vendored) ===
smb-server = { path = "../vendor/smb-server", optional = true, default-features = false }
async-trait = "0.1"
tracing-subscriber = { version = "0.3", features = ["env-filter"] }
tracing = "0.1"
tracing-subscriber = { version = "0.3", features = ["env-filter", "json"] }
[features]
default = [] # 默认不启用可选格式

View File

@@ -21,6 +21,7 @@ pub mod rsync_handler;
pub mod scp_handler;
pub mod server;
pub mod sftp_handler;
pub mod ssh_audit_log;
pub mod ssh_config;
pub mod ssh_security_config;
pub mod sshbuf;

View File

@@ -0,0 +1,395 @@
use serde::Serialize;
use std::net::IpAddr;
use std::time::SystemTime;
use tracing::{Event, Level, Subscriber};
use tracing_subscriber::fmt::FormatEvent;
use tracing_subscriber::fmt::format::{Format, Json};
use tracing_subscriber::layer::Layer;
pub struct SshAuditLog;
#[derive(Debug, Clone, Serialize)]
pub struct SshAuditEvent {
pub timestamp: String,
pub event_type: SshEventType,
pub session_id: Option<String>,
pub client_ip: Option<IpAddr>,
pub user: Option<String>,
pub channel_id: Option<u32>,
pub command: Option<String>,
pub file_path: Option<String>,
pub port: Option<u16>,
pub success: bool,
pub error_message: Option<String>,
pub duration_ms: Option<u64>,
}
#[derive(Debug, Clone, Copy, Serialize, PartialEq)]
pub enum SshEventType {
ConnectionStart,
ConnectionEnd,
AuthAttempt,
AuthSuccess,
AuthFailure,
ChannelOpen,
ChannelClose,
CommandExec,
FileUpload,
FileDownload,
PortForwardRequest,
PortForwardBind,
PortForwardConnect,
HostKeyVerify,
RateLimitHit,
SecurityViolation,
}
impl std::fmt::Display for SshEventType {
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
match self {
SshEventType::ConnectionStart => write!(f, "ConnectionStart"),
SshEventType::ConnectionEnd => write!(f, "ConnectionEnd"),
SshEventType::AuthAttempt => write!(f, "AuthAttempt"),
SshEventType::AuthSuccess => write!(f, "AuthSuccess"),
SshEventType::AuthFailure => write!(f, "AuthFailure"),
SshEventType::ChannelOpen => write!(f, "ChannelOpen"),
SshEventType::ChannelClose => write!(f, "ChannelClose"),
SshEventType::CommandExec => write!(f, "CommandExec"),
SshEventType::FileUpload => write!(f, "FileUpload"),
SshEventType::FileDownload => write!(f, "FileDownload"),
SshEventType::PortForwardRequest => write!(f, "PortForwardRequest"),
SshEventType::PortForwardBind => write!(f, "PortForwardBind"),
SshEventType::PortForwardConnect => write!(f, "PortForwardConnect"),
SshEventType::HostKeyVerify => write!(f, "HostKeyVerify"),
SshEventType::RateLimitHit => write!(f, "RateLimitHit"),
SshEventType::SecurityViolation => write!(f, "SecurityViolation"),
}
}
}
impl SshAuditLog {
pub fn log_connection_start(client_ip: IpAddr) {
tracing::info!(
event_type = "ConnectionStart",
client_ip = %client_ip,
success = true,
"SSH connection started"
);
}
pub fn log_connection_end(client_ip: IpAddr, session_id: &str, duration_ms: u64) {
tracing::info!(
event_type = "ConnectionEnd",
client_ip = %client_ip,
session_id = %session_id,
duration_ms = duration_ms,
success = true,
"SSH connection ended"
);
}
pub fn log_auth_attempt(client_ip: IpAddr, user: &str, method: &str) {
tracing::info!(
event_type = "AuthAttempt",
client_ip = %client_ip,
user = %user,
auth_method = %method,
"SSH authentication attempt"
);
}
pub fn log_auth_success(client_ip: IpAddr, user: &str, method: &str) {
tracing::info!(
event_type = "AuthSuccess",
client_ip = %client_ip,
user = %user,
auth_method = %method,
success = true,
"SSH authentication successful"
);
}
pub fn log_auth_failure(client_ip: IpAddr, user: &str, method: &str, reason: &str) {
tracing::warn!(
event_type = "AuthFailure",
client_ip = %client_ip,
user = %user,
auth_method = %method,
success = false,
error_message = %reason,
"SSH authentication failed"
);
}
pub fn log_channel_open(session_id: &str, channel_id: u32, channel_type: &str) {
tracing::info!(
event_type = "ChannelOpen",
session_id = %session_id,
channel_id = channel_id,
channel_type = %channel_type,
success = true,
"SSH channel opened"
);
}
pub fn log_channel_close(session_id: &str, channel_id: u32) {
tracing::info!(
event_type = "ChannelClose",
session_id = %session_id,
channel_id = channel_id,
success = true,
"SSH channel closed"
);
}
pub fn log_command_exec(session_id: &str, user: &str, channel_id: u32, command: &str, success: bool) {
tracing::info!(
event_type = "CommandExec",
session_id = %session_id,
user = %user,
channel_id = channel_id,
command = %command,
success = success,
"SSH command executed"
);
}
pub fn log_file_upload(session_id: &str, user: &str, file_path: &str, size_bytes: u64, success: bool) {
tracing::info!(
event_type = "FileUpload",
session_id = %session_id,
user = %user,
file_path = %file_path,
size_bytes = size_bytes,
success = success,
"SSH file uploaded"
);
}
pub fn log_file_download(session_id: &str, user: &str, file_path: &str, size_bytes: u64, success: bool) {
tracing::info!(
event_type = "FileDownload",
session_id = %session_id,
user = %user,
file_path = %file_path,
size_bytes = size_bytes,
success = success,
"SSH file downloaded"
);
}
pub fn log_port_forward_request(client_ip: IpAddr, user: &str, bind_port: u16, success: bool) {
tracing::info!(
event_type = "PortForwardRequest",
client_ip = %client_ip,
user = %user,
port = bind_port,
success = success,
"SSH port forward requested"
);
}
pub fn log_port_forward_bind(bind_port: u16, success: bool) {
tracing::info!(
event_type = "PortForwardBind",
port = bind_port,
success = success,
"SSH port forward bound"
);
}
pub fn log_port_forward_connect(session_id: &str, target_host: &str, target_port: u16, success: bool) {
tracing::info!(
event_type = "PortForwardConnect",
session_id = %session_id,
target_host = %target_host,
port = target_port,
success = success,
"SSH port forward connection"
);
}
pub fn log_host_key_verify(client_ip: IpAddr, fingerprint: &str, accepted: bool) {
tracing::info!(
event_type = "HostKeyVerify",
client_ip = %client_ip,
fingerprint = %fingerprint,
success = accepted,
"SSH host key verification"
);
}
pub fn log_rate_limit_hit(client_ip: IpAddr, limit_type: &str, current_count: u32) {
tracing::warn!(
event_type = "RateLimitHit",
client_ip = %client_ip,
limit_type = %limit_type,
current_count = current_count,
success = false,
"SSH rate limit exceeded"
);
}
pub fn log_security_violation(client_ip: IpAddr, user: &str, violation_type: &str, details: &str) {
tracing::error!(
event_type = "SecurityViolation",
client_ip = %client_ip,
user = %user,
violation_type = %violation_type,
error_message = %details,
success = false,
"SSH security violation"
);
}
pub fn init_json_logging() {
use tracing_subscriber::fmt::Layer;
use tracing_subscriber::layer::SubscriberExt;
use tracing_subscriber::util::SubscriberInitExt;
let json_layer = Layer::default()
.json()
.with_target(false)
.with_thread_ids(false)
.with_thread_names(false);
tracing_subscriber::registry()
.with(json_layer)
.init();
}
}
pub fn init_audit_logging() {
SshAuditLog::init_json_logging();
}
#[cfg(test)]
mod tests {
use super::*;
use std::net::{IpAddr, Ipv4Addr};
fn setup_test_logging() {
let _ = tracing_subscriber::fmt()
.json()
.with_target(false)
.with_test_writer()
.try_init();
}
#[test]
fn test_log_connection_start() {
setup_test_logging();
let client_ip = IpAddr::V4(Ipv4Addr::new(127, 0, 0, 1));
SshAuditLog::log_connection_start(client_ip);
}
#[test]
fn test_log_auth_success() {
setup_test_logging();
let client_ip = IpAddr::V4(Ipv4Addr::new(127, 0, 0, 1));
SshAuditLog::log_auth_success(client_ip, "demo", "password");
}
#[test]
fn test_log_auth_failure() {
setup_test_logging();
let client_ip = IpAddr::V4(Ipv4Addr::new(127, 0, 0, 1));
SshAuditLog::log_auth_failure(client_ip, "demo", "password", "Invalid password");
}
#[test]
fn test_log_command_exec() {
setup_test_logging();
SshAuditLog::log_command_exec("session-123", "demo", 1, "ls -la", true);
}
#[test]
fn test_log_file_upload() {
setup_test_logging();
SshAuditLog::log_file_upload("session-123", "demo", "/data/test.txt", 1024, true);
}
#[test]
fn test_log_port_forward_request() {
setup_test_logging();
let client_ip = IpAddr::V4(Ipv4Addr::new(127, 0, 0, 1));
SshAuditLog::log_port_forward_request(client_ip, "demo", 8080, true);
}
#[test]
fn test_log_rate_limit_hit() {
setup_test_logging();
let client_ip = IpAddr::V4(Ipv4Addr::new(127, 0, 0, 1));
SshAuditLog::log_rate_limit_hit(client_ip, "connection", 100);
}
#[test]
fn test_log_security_violation() {
setup_test_logging();
let client_ip = IpAddr::V4(Ipv4Addr::new(127, 0, 0, 1));
SshAuditLog::log_security_violation(client_ip, "demo", "path_traversal", "Attempted to access /etc/passwd");
}
#[test]
fn test_event_type_serialization() {
let event = SshAuditEvent {
timestamp: "2026-06-21T00:00:00Z".to_string(),
event_type: SshEventType::ConnectionStart,
session_id: Some("session-123".to_string()),
client_ip: Some(IpAddr::V4(Ipv4Addr::new(127, 0, 0, 1))),
user: Some("demo".to_string()),
channel_id: None,
command: None,
file_path: None,
port: None,
success: true,
error_message: None,
duration_ms: None,
};
let json = serde_json::to_string(&event).unwrap();
assert!(json.contains("\"event_type\":\"ConnectionStart\""));
}
#[test]
fn test_all_event_types() {
let types = vec![
SshEventType::ConnectionStart,
SshEventType::ConnectionEnd,
SshEventType::AuthAttempt,
SshEventType::AuthSuccess,
SshEventType::AuthFailure,
SshEventType::ChannelOpen,
SshEventType::ChannelClose,
SshEventType::CommandExec,
SshEventType::FileUpload,
SshEventType::FileDownload,
SshEventType::PortForwardRequest,
SshEventType::PortForwardBind,
SshEventType::PortForwardConnect,
SshEventType::HostKeyVerify,
SshEventType::RateLimitHit,
SshEventType::SecurityViolation,
];
for event_type in types {
let event = SshAuditEvent {
timestamp: "2026-06-21T00:00:00Z".to_string(),
event_type,
session_id: None,
client_ip: None,
user: None,
channel_id: None,
command: None,
file_path: None,
port: None,
success: true,
error_message: None,
duration_ms: None,
};
let json = serde_json::to_string(&event).unwrap();
assert!(json.contains(&format!("\"event_type\":\"{}\"", event_type)));
}
}
}