From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from firstgate.proxmox.com (firstgate.proxmox.com [212.224.123.68]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits)) (No client certificate requested) by lists.proxmox.com (Postfix) with ESMTPS id 419CD6B234 for ; Mon, 20 Sep 2021 09:38:59 +0200 (CEST) Received: from firstgate.proxmox.com (localhost [127.0.0.1]) by firstgate.proxmox.com (Proxmox) with ESMTP id 374101C57C for ; Mon, 20 Sep 2021 09:38:29 +0200 (CEST) Received: from proxmox-new.maurer-it.com (proxmox-new.maurer-it.com [94.136.29.106]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits)) (No client certificate requested) by firstgate.proxmox.com (Proxmox) with ESMTPS id D707C1C429 for ; Mon, 20 Sep 2021 09:38:20 +0200 (CEST) Received: from proxmox-new.maurer-it.com (localhost.localdomain [127.0.0.1]) by proxmox-new.maurer-it.com (Proxmox) with ESMTP id B0C224499D; Mon, 20 Sep 2021 09:38:20 +0200 (CEST) From: Dietmar Maurer To: pbs-devel@lists.proxmox.com Date: Mon, 20 Sep 2021 09:38:10 +0200 Message-Id: <20210920073813.3178009-12-dietmar@proxmox.com> X-Mailer: git-send-email 2.30.2 In-Reply-To: <20210920073813.3178009-1-dietmar@proxmox.com> References: <20210920073813.3178009-1-dietmar@proxmox.com> MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-SPAM-LEVEL: Spam detection results: 0 AWL 0.643 Adjusted score from AWL reputation of From: address BAYES_00 -1.9 Bayes spam probability is 0 to 1% KAM_DMARC_STATUS 0.01 Test Rule for DKIM or SPF Failure with Strict Alignment SPF_HELO_NONE 0.001 SPF: HELO does not publish an SPF Record SPF_PASS -0.001 SPF: sender matches SPF record Subject: [pbs-devel] [PATCH proxmox-backup 12/15] rest server: cleanup auth-log handling X-BeenThere: pbs-devel@lists.proxmox.com X-Mailman-Version: 2.1.29 Precedence: list List-Id: Proxmox Backup Server development discussion List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 20 Sep 2021 07:38:59 -0000 Handle auth logs the same way as access log. - Configure with ApiConfig - CommandoSocket command to reload auth-logs "api-auth-log-reopen" Inside API calls, we now access the ApiConfig using the RestEnvironment. The openid_login api now also logs failed logins and return http_err!(UNAUTHORIZED, ..) on failed logins. --- pbs-server/src/api_config.rs | 45 ++++++++++- pbs-server/src/environment.rs | 49 +++++++++++- src/api2/access/mod.rs | 26 +++---- src/api2/access/openid.rs | 134 ++++++++++++++++++-------------- src/bin/proxmox-backup-api.rs | 8 ++ src/bin/proxmox-backup-proxy.rs | 31 +++++++- src/server/rest.rs | 30 ++----- 7 files changed, 215 insertions(+), 108 deletions(-) diff --git a/pbs-server/src/api_config.rs b/pbs-server/src/api_config.rs index fee94e88..e09f7af9 100644 --- a/pbs-server/src/api_config.rs +++ b/pbs-server/src/api_config.rs @@ -26,6 +26,7 @@ pub struct ApiConfig { templates: RwLock>, template_files: RwLock>, request_log: Option>>, + auth_log: Option>>, pub api_auth: Arc, get_index_fn: GetIndexFn, } @@ -46,6 +47,7 @@ impl ApiConfig { templates: RwLock::new(Handlebars::new()), template_files: RwLock::new(HashMap::new()), request_log: None, + auth_log: None, api_auth, get_index_fn, }) @@ -172,7 +174,7 @@ impl ApiConfig { self.request_log = Some(Arc::clone(&request_log)); commando_sock.register_command("api-access-log-reopen".into(), move |_args| { - println!("re-opening log file"); + println!("re-opening access-log file"); request_log.lock().unwrap().reopen()?; Ok(serde_json::Value::Null) })?; @@ -180,7 +182,46 @@ impl ApiConfig { Ok(()) } - pub fn get_file_log(&self) -> Option<&Arc>> { + pub fn enable_auth_log

( + &mut self, + path: P, + dir_opts: Option, + file_opts: Option, + commando_sock: &mut CommandoSocket, + ) -> Result<(), Error> + where + P: Into + { + let path: PathBuf = path.into(); + if let Some(base) = path.parent() { + if !base.exists() { + create_path(base, None, dir_opts).map_err(|err| format_err!("{}", err))?; + } + } + + let logger_options = FileLogOptions { + append: true, + prefix_time: true, + file_opts: file_opts.unwrap_or(CreateOptions::default()), + ..Default::default() + }; + let auth_log = Arc::new(Mutex::new(FileLogger::new(&path, logger_options)?)); + self.auth_log = Some(Arc::clone(&auth_log)); + + commando_sock.register_command("api-auth-log-reopen".into(), move |_args| { + println!("re-opening auth-log file"); + auth_log.lock().unwrap().reopen()?; + Ok(serde_json::Value::Null) + })?; + + Ok(()) + } + + pub fn get_access_log(&self) -> Option<&Arc>> { self.request_log.as_ref() } + + pub fn get_auth_log(&self) -> Option<&Arc>> { + self.auth_log.as_ref() + } } diff --git a/pbs-server/src/environment.rs b/pbs-server/src/environment.rs index 0548b5bc..57d0d7d5 100644 --- a/pbs-server/src/environment.rs +++ b/pbs-server/src/environment.rs @@ -1,24 +1,65 @@ +use std::sync::Arc; +use std::net::SocketAddr; + use serde_json::{json, Value}; use proxmox::api::{RpcEnvironment, RpcEnvironmentType}; +use crate::ApiConfig; + /// Encapsulates information about the runtime environment pub struct RestEnvironment { env_type: RpcEnvironmentType, result_attributes: Value, auth_id: Option, - client_ip: Option, + client_ip: Option, + api: Arc, } impl RestEnvironment { - pub fn new(env_type: RpcEnvironmentType) -> Self { + pub fn new(env_type: RpcEnvironmentType, api: Arc) -> Self { Self { result_attributes: json!({}), auth_id: None, client_ip: None, env_type, + api, } } + + pub fn api_config(&self) -> &ApiConfig { + &self.api + } + + pub fn log_auth(&self, auth_id: &str) { + let msg = format!("successful auth for user '{}'", auth_id); + log::info!("{}", msg); + if let Some(auth_logger) = self.api.get_auth_log() { + auth_logger.lock().unwrap().log(&msg); + } + } + + pub fn log_failed_auth(&self, failed_auth_id: Option, msg: &str) { + let msg = match (self.client_ip, failed_auth_id) { + (Some(peer), Some(user)) => { + format!("authentication failure; rhost={} user={} msg={}", peer, user, msg) + } + (Some(peer), None) => { + format!("authentication failure; rhost={} msg={}", peer, msg) + } + (None, Some(user)) => { + format!("authentication failure; rhost=unknown user={} msg={}", user, msg) + } + (None, None) => { + format!("authentication failure; rhost=unknown msg={}", msg) + } + }; + log::error!("{}", msg); + if let Some(auth_logger) = self.api.get_auth_log() { + auth_logger.lock().unwrap().log(&msg); + } + } + } impl RpcEnvironment for RestEnvironment { @@ -43,11 +84,11 @@ impl RpcEnvironment for RestEnvironment { self.auth_id.clone() } - fn set_client_ip(&mut self, client_ip: Option) { + fn set_client_ip(&mut self, client_ip: Option) { self.client_ip = client_ip; } - fn get_client_ip(&self) -> Option { + fn get_client_ip(&self) -> Option { self.client_ip } } diff --git a/src/api2/access/mod.rs b/src/api2/access/mod.rs index 58ac8ca4..0d247288 100644 --- a/src/api2/access/mod.rs +++ b/src/api2/access/mod.rs @@ -12,7 +12,7 @@ use proxmox::{http_err, list_subdirs_api_method}; use proxmox::{identity, sortable}; use pbs_api_types::{ - Userid, Authid, PASSWORD_SCHEMA, ACL_PATH_SCHEMA, + Userid, Authid, PASSWORD_SCHEMA, ACL_PATH_SCHEMA, PRIVILEGES, PRIV_PERMISSIONS_MODIFY, PRIV_SYS_AUDIT, }; use pbs_tools::auth::private_auth_key; @@ -196,6 +196,12 @@ pub fn create_ticket( tfa_challenge: Option, rpcenv: &mut dyn RpcEnvironment, ) -> Result { + + use pbs_server::RestEnvironment; + + let env: &RestEnvironment = rpcenv.as_any().downcast_ref::() + .ok_or_else(|| format_err!("detected worng RpcEnvironment type"))?; + match authenticate_user(&username, &password, path, privs, port, tfa_challenge) { Ok(AuthResult::Success) => Ok(json!({ "username": username })), Ok(AuthResult::CreateTicket) => { @@ -203,8 +209,7 @@ pub fn create_ticket( let ticket = Ticket::new("PBS", &api_ticket)?.sign(private_auth_key(), None)?; let token = assemble_csrf_prevention_token(csrf_secret(), &username); - crate::server::rest::auth_logger()? - .log(format!("successful auth for user '{}'", username)); + env.log_auth(username.as_str()); Ok(json!({ "username": username, @@ -223,20 +228,7 @@ pub fn create_ticket( })) } Err(err) => { - let client_ip = match rpcenv.get_client_ip().map(|addr| addr.ip()) { - Some(ip) => format!("{}", ip), - None => "unknown".into(), - }; - - let msg = format!( - "authentication failure; rhost={} user={} msg={}", - client_ip, - username, - err.to_string() - ); - crate::server::rest::auth_logger()?.log(&msg); - log::error!("{}", msg); - + env.log_failed_auth(Some(username.to_string()), &err.to_string()); Err(http_err!(UNAUTHORIZED, "permission check failed.")) } } diff --git a/src/api2/access/openid.rs b/src/api2/access/openid.rs index 38fab409..22166c5a 100644 --- a/src/api2/access/openid.rs +++ b/src/api2/access/openid.rs @@ -1,14 +1,13 @@ //! OpenID redirect/login API use std::convert::TryFrom; -use anyhow::{bail, Error}; +use anyhow::{bail, format_err, Error}; use serde_json::{json, Value}; use proxmox::api::router::{Router, SubdirMap}; use proxmox::api::{api, Permission, RpcEnvironment}; -use proxmox::{list_subdirs_api_method}; -use proxmox::{identity, sortable}; +use proxmox::{http_err, list_subdirs_api_method, identity, sortable}; use proxmox_openid::{OpenIdAuthenticator, OpenIdConfig}; @@ -80,76 +79,95 @@ pub fn openid_login( state: String, code: String, redirect_url: String, - _rpcenv: &mut dyn RpcEnvironment, + rpcenv: &mut dyn RpcEnvironment, ) -> Result { + use pbs_server::RestEnvironment; + + let env: &RestEnvironment = rpcenv.as_any().downcast_ref::() + .ok_or_else(|| format_err!("detected worng RpcEnvironment type"))?; + let user_info = CachedUserInfo::new()?; - let (realm, private_auth_state) = - OpenIdAuthenticator::verify_public_auth_state(PROXMOX_BACKUP_RUN_DIR_M!(), &state)?; + let mut tested_username = None; - let (domains, _digest) = pbs_config::domains::config()?; - let config: OpenIdRealmConfig = domains.lookup("openid", &realm)?; + let result = proxmox::try_block!({ - let open_id = openid_authenticator(&config, &redirect_url)?; + let (realm, private_auth_state) = + OpenIdAuthenticator::verify_public_auth_state(PROXMOX_BACKUP_RUN_DIR_M!(), &state)?; + + let (domains, _digest) = pbs_config::domains::config()?; + let config: OpenIdRealmConfig = domains.lookup("openid", &realm)?; + + let open_id = openid_authenticator(&config, &redirect_url)?; - let info = open_id.verify_authorization_code(&code, &private_auth_state)?; + let info = open_id.verify_authorization_code(&code, &private_auth_state)?; - // eprintln!("VERIFIED {} {:?} {:?}", info.subject().as_str(), info.name(), info.email()); + // eprintln!("VERIFIED {} {:?} {:?}", info.subject().as_str(), info.name(), info.email()); - let unique_name = match config.username_claim { - None | Some(OpenIdUserAttribute::Subject) => info.subject().as_str(), - Some(OpenIdUserAttribute::Username) => { - match info.preferred_username() { - Some(name) => name.as_str(), - None => bail!("missing claim 'preferred_name'"), + let unique_name = match config.username_claim { + None | Some(OpenIdUserAttribute::Subject) => info.subject().as_str(), + Some(OpenIdUserAttribute::Username) => { + match info.preferred_username() { + Some(name) => name.as_str(), + None => bail!("missing claim 'preferred_name'"), + } } - } - Some(OpenIdUserAttribute::Email) => { - match info.email() { - Some(name) => name.as_str(), - None => bail!("missing claim 'email'"), + Some(OpenIdUserAttribute::Email) => { + match info.email() { + Some(name) => name.as_str(), + None => bail!("missing claim 'email'"), + } } - } - }; - - let user_id = Userid::try_from(format!("{}@{}", unique_name, realm))?; - - if !user_info.is_active_user_id(&user_id) { - if config.autocreate.unwrap_or(false) { - use pbs_config::user; - let _lock = open_backup_lockfile(user::USER_CFG_LOCKFILE, None, true)?; - let user = User { - userid: user_id.clone(), - comment: None, - enable: None, - expire: None, - firstname: info.given_name().and_then(|n| n.get(None)).map(|n| n.to_string()), - lastname: info.family_name().and_then(|n| n.get(None)).map(|n| n.to_string()), - email: info.email().map(|e| e.to_string()), - }; - let (mut config, _digest) = user::config()?; - if config.sections.get(user.userid.as_str()).is_some() { - bail!("autocreate user failed - '{}' already exists.", user.userid); + }; + + + let user_id = Userid::try_from(format!("{}@{}", unique_name, realm))?; + tested_username = Some(unique_name.to_string()); + + if !user_info.is_active_user_id(&user_id) { + if config.autocreate.unwrap_or(false) { + use pbs_config::user; + let _lock = open_backup_lockfile(user::USER_CFG_LOCKFILE, None, true)?; + let user = User { + userid: user_id.clone(), + comment: None, + enable: None, + expire: None, + firstname: info.given_name().and_then(|n| n.get(None)).map(|n| n.to_string()), + lastname: info.family_name().and_then(|n| n.get(None)).map(|n| n.to_string()), + email: info.email().map(|e| e.to_string()), + }; + let (mut config, _digest) = user::config()?; + if config.sections.get(user.userid.as_str()).is_some() { + bail!("autocreate user failed - '{}' already exists.", user.userid); + } + config.set_data(user.userid.as_str(), "user", &user)?; + user::save_config(&config)?; + } else { + bail!("user account '{}' missing, disabled or expired.", user_id); } - config.set_data(user.userid.as_str(), "user", &user)?; - user::save_config(&config)?; - } else { - bail!("user account '{}' missing, disabled or expired.", user_id); } - } - let api_ticket = ApiTicket::full(user_id.clone()); - let ticket = Ticket::new("PBS", &api_ticket)?.sign(private_auth_key(), None)?; - let token = assemble_csrf_prevention_token(csrf_secret(), &user_id); + let api_ticket = ApiTicket::full(user_id.clone()); + let ticket = Ticket::new("PBS", &api_ticket)?.sign(private_auth_key(), None)?; + let token = assemble_csrf_prevention_token(csrf_secret(), &user_id); + + env.log_auth(user_id.as_str()); - crate::server::rest::auth_logger()? - .log(format!("successful auth for user '{}'", user_id)); + Ok(json!({ + "username": user_id, + "ticket": ticket, + "CSRFPreventionToken": token, + })) + }); + + if let Err(ref err) = result { + let msg = err.to_string(); + env.log_failed_auth(tested_username, &msg); + return Err(http_err!(UNAUTHORIZED, "{}", msg)) + } - Ok(json!({ - "username": user_id, - "ticket": ticket, - "CSRFPreventionToken": token, - })) + result } #[api( diff --git a/src/bin/proxmox-backup-api.rs b/src/bin/proxmox-backup-api.rs index bb083b7d..f9f82ee8 100644 --- a/src/bin/proxmox-backup-api.rs +++ b/src/bin/proxmox-backup-api.rs @@ -96,11 +96,19 @@ async fn run() -> Result<(), Error> { config.enable_file_log( pbs_buildcfg::API_ACCESS_LOG_FN, + Some(dir_opts.clone()), + Some(file_opts.clone()), + &mut commando_sock, + )?; + + config.enable_auth_log( + pbs_buildcfg::API_AUTH_LOG_FN, Some(dir_opts), Some(file_opts), &mut commando_sock, )?; + let rest_server = RestServer::new(config); // http server future: diff --git a/src/bin/proxmox-backup-proxy.rs b/src/bin/proxmox-backup-proxy.rs index 5e75ec72..f9277644 100644 --- a/src/bin/proxmox-backup-proxy.rs +++ b/src/bin/proxmox-backup-proxy.rs @@ -196,6 +196,13 @@ async fn run() -> Result<(), Error> { config.enable_file_log( pbs_buildcfg::API_ACCESS_LOG_FN, + Some(dir_opts.clone()), + Some(file_opts.clone()), + &mut commando_sock, + )?; + + config.enable_auth_log( + pbs_buildcfg::API_AUTH_LOG_FN, Some(dir_opts), Some(file_opts), &mut commando_sock, @@ -762,7 +769,7 @@ async fn schedule_task_log_rotate() { if logrotate.rotate(max_size, None, Some(max_files))? { println!("rotated access log, telling daemons to re-open log file"); - pbs_runtime::block_on(command_reopen_logfiles())?; + pbs_runtime::block_on(command_reopen_access_logfiles())?; worker.log("API access log was rotated".to_string()); } else { worker.log("API access log was not rotated".to_string()); @@ -772,6 +779,8 @@ async fn schedule_task_log_rotate() { .ok_or_else(|| format_err!("could not get API auth log file names"))?; if logrotate.rotate(max_size, None, Some(max_files))? { + println!("rotated auth log, telling daemons to re-open log file"); + pbs_runtime::block_on(command_reopen_auth_logfiles())?; worker.log("API authentication log was rotated".to_string()); } else { worker.log("API authentication log was not rotated".to_string()); @@ -794,7 +803,7 @@ async fn schedule_task_log_rotate() { } -async fn command_reopen_logfiles() -> Result<(), Error> { +async fn command_reopen_access_logfiles() -> Result<(), Error> { // only care about the most recent daemon instance for each, proxy & api, as other older ones // should not respond to new requests anyway, but only finish their current one and then exit. let sock = crate::server::our_ctrl_sock(); @@ -812,6 +821,24 @@ async fn command_reopen_logfiles() -> Result<(), Error> { } } +async fn command_reopen_auth_logfiles() -> Result<(), Error> { + // only care about the most recent daemon instance for each, proxy & api, as other older ones + // should not respond to new requests anyway, but only finish their current one and then exit. + let sock = crate::server::our_ctrl_sock(); + let f1 = pbs_server::send_command(sock, "{\"command\":\"api-auth-log-reopen\"}\n"); + + let pid = crate::server::read_pid(pbs_buildcfg::PROXMOX_BACKUP_API_PID_FN)?; + let sock = crate::server::ctrl_sock_from_pid(pid); + let f2 = pbs_server::send_command(sock, "{\"command\":\"api-auth-log-reopen\"}\n"); + + match futures::join!(f1, f2) { + (Err(e1), Err(e2)) => Err(format_err!("reopen commands failed, proxy: {}; api: {}", e1, e2)), + (Err(e1), Ok(_)) => Err(format_err!("reopen commands failed, proxy: {}", e1)), + (Ok(_), Err(e2)) => Err(format_err!("reopen commands failed, api: {}", e2)), + _ => Ok(()), + } +} + async fn run_stat_generator() { let mut count = 0; diff --git a/src/server/rest.rs b/src/server/rest.rs index f0187a67..0f367a48 100644 --- a/src/server/rest.rs +++ b/src/server/rest.rs @@ -29,12 +29,11 @@ use proxmox::api::{ RpcEnvironmentType, UserInformation, }; use proxmox::http_err; -use proxmox::tools::fs::CreateOptions; use pbs_tools::compression::{DeflateEncoder, Level}; use pbs_tools::stream::AsyncReaderStream; use pbs_server::{ - ApiConfig, FileLogger, FileLogOptions, AuthError, RestEnvironment, CompressionMethod, + ApiConfig, FileLogger, AuthError, RestEnvironment, CompressionMethod, extract_cookie, normalize_uri_path, }; use pbs_server::formatter::*; @@ -200,22 +199,6 @@ fn log_response( } } -pub fn auth_logger() -> Result { - let backup_user = pbs_config::backup_user()?; - - let file_opts = CreateOptions::new() - .owner(backup_user.uid) - .group(backup_user.gid); - - let logger_options = FileLogOptions { - append: true, - prefix_time: true, - file_opts, - ..Default::default() - }; - FileLogger::new(pbs_buildcfg::API_AUTH_LOG_FN, logger_options) -} - fn get_proxied_peer(headers: &HeaderMap) -> Option { lazy_static! { static ref RE: Regex = Regex::new(r#"for="([^"]+)""#).unwrap(); @@ -272,7 +255,7 @@ impl tower_service::Service> for ApiService { .body(err.into())? } }; - let logger = config.get_file_log(); + let logger = config.get_access_log(); log_response(logger, &peer, method, &path, &response, user_agent); Ok(response) } @@ -631,7 +614,7 @@ async fn handle_request( } let env_type = api.env_type(); - let mut rpcenv = RestEnvironment::new(env_type); + let mut rpcenv = RestEnvironment::new(env_type, Arc::clone(&api)); rpcenv.set_client_ip(Some(*peer)); @@ -675,11 +658,8 @@ async fn handle_request( format_err!("no authentication credentials provided.") } }; - let peer = peer.ip(); - auth_logger()?.log(format!( - "authentication failure; rhost={} msg={}", - peer, err - )); + // fixme: log Username?? + rpcenv.log_failed_auth(None, &err.to_string()); // always delay unauthorized calls by 3 seconds (from start of request) let err = http_err!(UNAUTHORIZED, "authentication failed - {}", err); -- 2.30.2