fix(connlib): Don't roll log files (#4390)

Fixes #4377 
Closes #3910 

If we decide to implement diagnostic log collection in the future it
will be opt-in and use something like Sentry.
This commit is contained in:
Jamil
2024-03-28 21:24:24 -07:00
committed by GitHub
parent fe1a627f4b
commit 1cfa80399e
13 changed files with 19 additions and 217 deletions

View File

@@ -271,6 +271,7 @@ defmodule API.Client.Channel do
end
# This message sent by the client to create a GSC signed url for uploading logs and debug artifacts
# TODO: This has been disabled on clients. Remove this when no more clients are requesting log sinks.
@impl true
def handle_in("create_log_sink", _attrs, socket) do
OpenTelemetry.Ctx.attach(socket.assigns.opentelemetry_ctx)

View File

@@ -477,6 +477,7 @@ defmodule API.Client.ChannelTest do
end
end
# TODO: This has been disabled on clients. Remove this when no more clients are requesting log sinks.
describe "handle_in/3 create_log_sink" do
test "returns error when feature is disabled", %{socket: socket} do
Domain.Config.put_env_override(Domain.Instrumentation, client_logs_enabled: false)

View File

@@ -2,6 +2,7 @@ defmodule Domain.Instrumentation do
alias Domain.Clients
alias Domain.GoogleCloudPlatform
# TODO: Remove this when clients aren't requesting log sinks
def create_remote_log_sink(%Clients.Client{} = client, actor_name, account_slug) do
config = config!()
enabled? = Keyword.fetch!(config, :client_logs_enabled)

View File

@@ -3,6 +3,7 @@ defmodule Domain.InstrumentationTest do
import Domain.Instrumentation
alias Domain.Mocks.GoogleCloudPlatform
# TODO: Remove this when clients aren't requesting log sinks
describe "create_remote_log_sink/1" do
test "returns an error if feature is disabled" do
client = Fixtures.Clients.create_client()

View File

@@ -103,7 +103,6 @@ ENV REFRESHED_AT=2023-10-23 \
LANG=C.UTF-8 \
TERM=xterm \
RUST_BACKTRACE=1 \
CONNLIB_LOG_UPLOAD_INTERVAL_SECS=300 \
RUST_LOG=str0m=warn,info
WORKDIR /bin

View File

@@ -265,14 +265,6 @@ impl Callbacks for CallbackHandler {
})
.expect("onDisconnect callback failed")
}
fn roll_log_file(&self) -> Option<PathBuf> {
self.handle.roll_to_new_file().unwrap_or_else(|e| {
tracing::debug!("Failed to roll over to new file: {e}");
None
})
}
}
fn throw(env: &mut JNIEnv, class: &str, msg: impl Into<JNIString>) {

View File

@@ -83,6 +83,9 @@ pub struct WrappedSession {
#[allow(dead_code)]
runtime: Runtime,
#[allow(dead_code)]
logger: file_logger::Handle,
}
// SAFETY: `CallbackHandler.swift` promises to be thread-safe.
@@ -96,7 +99,6 @@ pub struct CallbackHandler {
// refcount, but there's no way to generate a `Clone` impl that increments the
// recount. Instead, we just wrap it in an `Arc`.
inner: Arc<ffi::CallbackHandler>,
handle: file_logger::Handle,
}
impl Callbacks for CallbackHandler {
@@ -139,13 +141,6 @@ impl Callbacks for CallbackHandler {
fn on_disconnect(&self, error: &Error) {
self.inner.on_disconnect(error.to_string());
}
fn roll_log_file(&self) -> Option<PathBuf> {
self.handle.roll_to_new_file().unwrap_or_else(|e| {
tracing::error!("Failed to roll over to new log file: {e}");
None
})
}
}
fn init_logging(log_dir: PathBuf, log_filter: String) -> Result<file_logger::Handle, TryInitError> {
@@ -176,7 +171,7 @@ impl WrappedSession {
log_filter: String,
callback_handler: ffi::CallbackHandler,
) -> Result<Self, String> {
let handle = init_logging(log_dir.into(), log_filter).map_err(|e| e.to_string())?;
let logger = init_logging(log_dir.into(), log_filter).map_err(|e| e.to_string())?;
let secret = SecretString::from(token);
let (private_key, public_key) = keypair();
@@ -203,7 +198,6 @@ impl WrappedSession {
os_version_override,
CallbackHandler {
inner: Arc::new(callback_handler),
handle,
},
Some(MAX_PARTITION_TIME),
runtime.handle().clone(),
@@ -212,6 +206,7 @@ impl WrappedSession {
Ok(Self {
inner: session,
runtime,
logger,
})
}

View File

@@ -1,29 +0,0 @@
use connlib_client_shared::file_logger;
use std::path::Path;
use std::time::Duration;
use tracing_subscriber::layer::SubscriberExt;
use tracing_subscriber::util::SubscriberInitExt;
use tracing_subscriber::{EnvFilter, Layer};
#[allow(clippy::print_stdout)]
fn main() {
let log_dir = Path::new("./target");
println!("Logging to {}", log_dir.canonicalize().unwrap().display());
let (file_layer, handle) = file_logger::layer(log_dir);
tracing_subscriber::registry()
.with(file_layer.with_filter(EnvFilter::new("info")))
.init();
tracing::info!("First log");
tracing::info!("Second log");
std::thread::sleep(Duration::from_secs(1)); // Make sure we don't use the same filename.
handle.roll_to_new_file().unwrap().unwrap();
tracing::info!("Third log");
tracing::info!("Fourth log");
}

View File

@@ -14,14 +14,9 @@ use firezone_tunnel::ClientTunnel;
use phoenix_channel::{ErrorReply, OutboundRequestId, PhoenixChannel};
use std::{
collections::HashMap,
io,
net::IpAddr,
path::PathBuf,
task::{Context, Poll},
time::Duration,
};
use tokio::time::{Interval, MissedTickBehavior};
use url::Url;
pub struct Eventloop<C: Callbacks> {
tunnel: ClientTunnel<C>,
@@ -30,7 +25,6 @@ pub struct Eventloop<C: Callbacks> {
rx: tokio::sync::mpsc::UnboundedReceiver<Command>,
connection_intents: SentConnectionIntents,
log_upload_interval: tokio::time::Interval,
}
/// Commands that can be sent to the [`Eventloop`].
@@ -50,7 +44,6 @@ impl<C: Callbacks> Eventloop<C> {
tunnel,
portal,
connection_intents: SentConnectionIntents::default(),
log_upload_interval: upload_interval(),
rx,
}
}
@@ -100,12 +93,6 @@ where
Poll::Pending => {}
}
if self.log_upload_interval.poll_tick(cx).is_ready() {
self.portal
.send(PHOENIX_TOPIC, EgressMessages::CreateLogSink {});
continue;
}
return Poll::Pending;
}
}
@@ -281,20 +268,6 @@ where
}
};
}
ReplyMessages::SignedLogUrl(url) => {
let Some(path) = self.tunnel.callbacks.roll_log_file() else {
return;
};
tokio::spawn(async move {
if let Err(e) = upload(path.clone(), url).await {
tracing::warn!(
"Failed to upload log file at path {path_display}: {e}. Not retrying.",
path_display = path.display()
);
}
});
}
}
}
@@ -326,81 +299,6 @@ where
}
}
async fn upload(_path: PathBuf, _url: Url) -> io::Result<()> {
// TODO: Log uploads are disabled by default for GA until we expose a way to opt in
// to the user. See https://github.com/firezone/firezone/issues/3910
// tracing::info!(path = %path.display(), %url, "Uploading log file");
// let file = tokio::fs::File::open(&path).await?;
// let response = reqwest::Client::new()
// .put(url)
// .header(CONTENT_TYPE, "text/plain")
// .header(CONTENT_ENCODING, "gzip")
// .body(reqwest::Body::wrap_stream(FramedRead::new(
// GzipEncoder::new(BufReader::new(file)),
// BytesCodec::default(),
// )))
// .send()
// .await
// .map_err(|e| io::Error::new(io::ErrorKind::Other, e))?;
// let status_code = response.status();
// if !status_code.is_success() {
// let body = response
// .text()
// .await
// .map_err(|e| io::Error::new(io::ErrorKind::Other, e))?;
// tracing::warn!(%body, %status_code, "Failed to upload logs");
// return Err(io::Error::new(
// io::ErrorKind::Other,
// "portal returned non-successful exit code",
// ));
// }
Ok(())
}
fn upload_interval() -> Interval {
let duration = upload_interval_duration_from_env_or_default();
let mut interval = tokio::time::interval_at(tokio::time::Instant::now() + duration, duration);
interval.set_missed_tick_behavior(MissedTickBehavior::Skip);
interval
}
/// Parses an interval from the _compile-time_ env variable `CONNLIB_LOG_UPLOAD_INTERVAL_SECS`.
///
/// If not present or parsing as u64 fails, we fall back to a default interval of 5 minutes.
fn upload_interval_duration_from_env_or_default() -> Duration {
const DEFAULT: Duration = Duration::from_secs(60 * 5);
let Some(interval) = option_env!("CONNLIB_LOG_UPLOAD_INTERVAL_SECS") else {
tracing::warn!(interval = ?DEFAULT, "Env variable `CONNLIB_LOG_UPLOAD_INTERVAL_SECS` was not set during compile-time, falling back to default");
return DEFAULT;
};
let interval = match interval.parse() {
Ok(i) => i,
Err(e) => {
tracing::warn!(interval = ?DEFAULT, "Failed to parse `CONNLIB_LOG_UPLOAD_INTERVAL_SECS` as u64: {e}");
return DEFAULT;
}
};
tracing::info!(
?interval,
"Using upload interval specified at compile-time via `CONNLIB_LOG_UPLOAD_INTERVAL_SECS`"
);
Duration::from_secs(interval)
}
#[derive(Default)]
struct SentConnectionIntents {
inner: HashMap<OutboundRequestId, ResourceId>,

View File

@@ -2,7 +2,9 @@
//!
//! This module implements a file-based logger for connlib using tracing-appender.
//!
//! The log files are rotated hourly.
//! The log files are never rotated for the duration of the process; this prevents
//! tracing_appender from trying to prune old log files which triggers privacy
//! alerts in Apple app store submissions.
//!
//! Since these will be leaving the user's device, these logs should contain *only*
//! the necessary debugging information, and **not** any sensitive information,
@@ -49,7 +51,6 @@ fn new_appender(directory: PathBuf) -> (NonBlocking, Handle) {
let (non_blocking, guard) = tracing_appender::non_blocking(appender);
let handle = Handle {
inner,
_guard: Arc::new(guard),
};
@@ -58,30 +59,13 @@ fn new_appender(directory: PathBuf) -> (NonBlocking, Handle) {
/// A handle to our file-logger.
///
/// This handle allows to roll over logging to a new file via [`Handle::roll_to_new_file`]. It also houses the [`WorkerGuard`] of the underlying non-blocking appender.
/// This handle houses the [`WorkerGuard`] of the underlying non-blocking appender.
/// Thus, you MUST NOT drop this handle for as long as you want messages to arrive at the log file.
#[derive(Clone, Debug)]
pub struct Handle {
inner: Arc<Mutex<Inner>>,
_guard: Arc<WorkerGuard>,
}
impl Handle {
/// Rolls over to a new file.
///
/// Returns the path to the now unused, previous log file.
/// If we don't have a log-file yet, `Ok(None)` is returned.
pub fn roll_to_new_file(&self) -> io::Result<Option<PathBuf>> {
let mut inner = try_unlock(&self.inner);
let new_writer = inner.create_new_writer()?;
let Some((_, name)) = inner.current.replace(new_writer) else {
return Ok(None);
};
Ok(Some(inner.directory.join(name)))
}
}
#[derive(Debug)]
struct Appender {
inner: Arc<Mutex<Inner>>,

View File

@@ -6,7 +6,6 @@ use connlib_shared::messages::{
GatewayId, GatewayResponse, Interface, Key, Relay, RequestConnection, ResourceDescription,
ResourceId, ReuseConnection,
};
use url::Url;
#[derive(Debug, PartialEq, Eq, Deserialize, Serialize, Clone)]
pub struct InitClient {
@@ -89,8 +88,6 @@ pub struct GatewayIceCandidates {
pub enum ReplyMessages {
ConnectionDetails(ConnectionDetails),
Connect(Connect),
/// Response for [`EgressMessages::CreateLogSink`].
SignedLogUrl(Url),
}
/// The totality of all messages (might have a macro in the future to derive the other types)
@@ -100,7 +97,6 @@ pub enum Messages {
Init(InitClient),
ConnectionDetails(ConnectionDetails),
Connect(Connect),
SignedLogUrl(Url),
// Resources: arrive in an orderly fashion
ResourceCreatedOrUpdated(ResourceDescription),
@@ -128,7 +124,6 @@ impl From<ReplyMessages> for Messages {
match value {
ReplyMessages::ConnectionDetails(m) => Self::ConnectionDetails(m),
ReplyMessages::Connect(m) => Self::Connect(m),
ReplyMessages::SignedLogUrl(url) => Self::SignedLogUrl(url),
}
}
}
@@ -142,7 +137,6 @@ pub enum EgressMessages {
resource_id: ResourceId,
connected_gateway_ids: HashSet<GatewayId>,
},
CreateLogSink {},
RequestConnection(RequestConnection),
ReuseConnection(ReuseConnection),
BroadcastIceCandidates(BroadcastGatewayIceCandidates),
@@ -156,7 +150,7 @@ mod test {
DnsServer, Interface, IpDnsServer, Relay, ResourceDescription, ResourceDescriptionCidr,
ResourceDescriptionDns, Stun, Turn,
};
use phoenix_channel::{OutboundRequestId, PhoenixMessage};
use phoenix_channel::PhoenixMessage;
use chrono::DateTime;
@@ -586,19 +580,4 @@ mod test {
let reply_message = serde_json::from_str(message).unwrap();
assert_eq!(m, reply_message);
}
#[test]
fn create_log_sink_ok_response() {
let json = r#"{"event":"phx_reply","ref":2,"topic":"client","payload":{"status":"ok","response":"https://storage.googleapis.com/foo/bar"}}"#;
let actual =
serde_json::from_str::<PhoenixMessage<EgressMessages, ReplyMessages>>(json).unwrap();
let expected = PhoenixMessage::new_ok_reply(
"client",
ReplyMessages::SignedLogUrl("https://storage.googleapis.com/foo/bar".parse().unwrap()),
Some(OutboundRequestId::for_test(2)),
);
assert_eq!(actual, expected)
}
}

View File

@@ -465,7 +465,7 @@ pub(crate) enum ControllerRequest {
#[derive(Clone)]
struct CallbackHandler {
logger: file_logger::Handle,
_logger: file_logger::Handle,
notify_controller: Arc<Notify>,
ctlr_tx: CtlrTx,
resources: Arc<ArcSwap<Vec<ResourceDescription>>>,
@@ -493,14 +493,6 @@ impl connlib_client_shared::Callbacks for CallbackHandler {
self.resources.store(resources.into());
self.notify_controller.notify_one();
}
fn roll_log_file(&self) -> Option<PathBuf> {
self.logger.roll_to_new_file().unwrap_or_else(|e| {
tracing::debug!("Failed to roll over to new file: {e}");
None
})
}
}
struct Controller {
@@ -535,7 +527,7 @@ impl Controller {
let callback_handler = CallbackHandler {
ctlr_tx: self.ctlr_tx.clone(),
logger: self.logging_handles.logger.clone(),
_logger: self.logging_handles.logger.clone(),
notify_controller: Arc::clone(&self.notify_controller),
resources: Default::default(),
};

View File

@@ -16,10 +16,10 @@ async fn main() -> Result<()> {
let cli = Cli::parse();
let max_partition_time = cli.max_partition_time.map(|d| d.into());
let (layer, handle) = cli.log_dir.as_deref().map(file_logger::layer).unzip();
let (layer, _handle) = cli.log_dir.as_deref().map(file_logger::layer).unzip();
setup_global_subscriber(layer);
let callbacks = CallbackHandler { handle };
let callbacks = CallbackHandler;
// AKA "Device ID", not the Firezone slug
let firezone_id = match cli.firezone_id {
@@ -96,9 +96,7 @@ fn system_resolvers(dns_control_method: Option<DnsControlMethod>) -> Result<Vec<
}
#[derive(Clone)]
struct CallbackHandler {
handle: Option<file_logger::Handle>,
}
struct CallbackHandler;
impl Callbacks for CallbackHandler {
fn on_disconnect(&self, error: &connlib_client_shared::Error) {
@@ -106,16 +104,6 @@ impl Callbacks for CallbackHandler {
std::process::exit(1);
}
fn roll_log_file(&self) -> Option<PathBuf> {
self.handle
.as_ref()?
.roll_to_new_file()
.unwrap_or_else(|e| {
tracing::debug!("Failed to roll over to new file: {e}");
None
})
}
}
fn get_system_default_resolvers_resolv_conf() -> Result<Vec<IpAddr>> {