use std::collections::VecDeque;
use std::future::Future;
use std::io::{Read, Write};
use std::os::unix::net::UnixStream;
use std::pin::Pin;
use std::sync::Arc;
use std::sync::atomic::{AtomicBool, AtomicUsize, Ordering};
use std::task::{Context, Poll};
use std::time::Duration;
use shiguredo_http11::{BodyProgress, ResponseDecoder};
use tokio::io::{AsyncBufRead, AsyncBufReadExt, ReadBuf};
use crate::core::logs::{LogFrame, consumer::LogConsumer};
const DEFAULT_BUFFER_LIMIT: usize = 8 * 1024 * 1024;
const FRAME_HEADER_LEN: usize = 8;
const READ_CHUNK: usize = 8192;
const LOG_SESSION_TIMEOUT: Option<Duration> = Some(Duration::from_secs(30));
fn io_other(msg: impl Into<Box<dyn std::error::Error + Send + Sync>>) -> std::io::Error {
std::io::Error::other(msg)
}
fn log_stream_decoder() -> ResponseDecoder {
ResponseDecoder::with_limits(shiguredo_http11::DecoderLimits {
max_body_size: u64::MAX,
..shiguredo_http11::DecoderLimits::default()
})
}
pub(crate) struct LogStream {
buffer: std::sync::Mutex<SharedLogBuffer>,
notify: tokio::sync::Notify,
terminated: AtomicBool,
}
impl LogStream {
fn new(limit: usize) -> Arc<Self> {
Arc::new(Self {
buffer: std::sync::Mutex::new(SharedLogBuffer::new(limit)),
notify: tokio::sync::Notify::new(),
terminated: AtomicBool::new(false),
})
}
fn terminate(&self) {
self.terminated.store(true, Ordering::SeqCst);
self.notify.notify_waiters();
}
}
pub(crate) struct SharedLogBuffer {
buf: VecDeque<u8>,
head: u64,
limit: usize,
strict: bool,
}
impl SharedLogBuffer {
fn new(limit: usize) -> Self {
Self::with_mode(limit, false)
}
fn new_strict(limit: usize) -> Self {
Self::with_mode(limit, true)
}
fn with_mode(limit: usize, strict: bool) -> Self {
Self {
buf: VecDeque::new(),
head: 0,
limit,
strict,
}
}
fn append(&mut self, data: &[u8]) -> bool {
if data.is_empty() {
return true;
}
if self.strict {
if data.len() > self.limit || self.buf.len() + data.len() > self.limit {
return false;
}
self.buf.extend(data.iter().copied());
return true;
}
let keep = if data.len() > self.limit {
&data[data.len() - self.limit..]
} else {
data
};
self.buf.extend(keep.iter().copied());
while self.buf.len() > self.limit {
self.buf.pop_front();
self.head += 1;
}
true
}
fn read_at(&self, reader_offset: u64, buf: &mut [u8]) -> (usize, u64, bool) {
let tail = self.head + self.buf.len() as u64;
let (mut offset, skipped) = if reader_offset < self.head {
(self.head, true)
} else {
(reader_offset, false)
};
if offset >= tail || buf.is_empty() {
return (0, offset, skipped);
}
let start = (offset - self.head) as usize;
let n = (self.buf.len() - start).min(buf.len());
for (i, &b) in self.buf.range(start..start + n).enumerate() {
buf[i] = b;
}
offset += n as u64;
(n, offset, skipped)
}
}
struct FrameDemuxer {
in_payload: bool,
header: [u8; FRAME_HEADER_LEN],
header_pos: usize,
stream_type: u8,
payload_remaining: usize,
}
impl FrameDemuxer {
fn new() -> Self {
Self {
in_payload: false,
header: [0; FRAME_HEADER_LEN],
header_pos: 0,
stream_type: 0,
payload_remaining: 0,
}
}
fn reset_header(&mut self) {
self.in_payload = false;
self.header_pos = 0;
self.stream_type = 0;
self.payload_remaining = 0;
}
fn feed(
&mut self,
mut data: &[u8],
stdout: &mut SharedLogBuffer,
stderr: &mut SharedLogBuffer,
) -> std::io::Result<(bool, bool)> {
let mut wrote_out = false;
let mut wrote_err = false;
while !data.is_empty() {
if !self.in_payload {
let need = FRAME_HEADER_LEN - self.header_pos;
let take = need.min(data.len());
self.header[self.header_pos..self.header_pos + take].copy_from_slice(&data[..take]);
self.header_pos += take;
data = &data[take..];
if self.header_pos == FRAME_HEADER_LEN {
self.stream_type = self.header[0];
self.payload_remaining = u32::from_be_bytes([
self.header[4],
self.header[5],
self.header[6],
self.header[7],
]) as usize;
self.in_payload = true;
if self.payload_remaining == 0 {
self.reset_header();
}
}
} else {
let take = self.payload_remaining.min(data.len());
let chunk = &data[..take];
match self.stream_type {
1 => {
if !stdout.append(chunk) {
return Err(io_other(format!(
"stdout output exceeds {} bytes limit",
stdout.limit
)));
}
wrote_out |= !chunk.is_empty();
}
2 => {
if !stderr.append(chunk) {
return Err(io_other(format!(
"stderr output exceeds {} bytes limit",
stderr.limit
)));
}
wrote_err |= !chunk.is_empty();
}
_ => {}
}
self.payload_remaining -= take;
data = &data[take..];
if self.payload_remaining == 0 {
self.reset_header();
}
}
}
Ok((wrote_out, wrote_err))
}
}
pub(crate) struct DockerLogsHandle {
socket_path: String,
id: String,
stdout: Arc<LogStream>,
stderr: Arc<LogStream>,
log_stop: Arc<AtomicBool>,
shutdown_socket: std::sync::Mutex<Option<UnixStream>>,
demux_done: Arc<AtomicBool>,
active_consumers: Arc<AtomicUsize>,
}
impl DockerLogsHandle {
fn new(socket_path: String, id: String) -> Arc<Self> {
Arc::new(Self {
socket_path,
id,
stdout: LogStream::new(DEFAULT_BUFFER_LIMIT),
stderr: LogStream::new(DEFAULT_BUFFER_LIMIT),
log_stop: Arc::new(AtomicBool::new(false)),
shutdown_socket: std::sync::Mutex::new(None),
demux_done: Arc::new(AtomicBool::new(false)),
active_consumers: Arc::new(AtomicUsize::new(0)),
})
}
pub(crate) fn stop(&self) {
self.log_stop.store(true, Ordering::SeqCst);
let socket = self
.shutdown_socket
.lock()
.expect("shutdown socket mutex must not be poisoned while stopping log stream")
.take();
if let Some(socket) = socket {
let _ = socket.shutdown(std::net::Shutdown::Both);
}
}
fn terminate_all(&self) {
self.stdout.terminate();
self.stderr.terminate();
self.demux_done.store(true, Ordering::SeqCst);
}
pub(crate) fn logs_terminated(&self) -> bool {
self.demux_done.load(Ordering::SeqCst)
}
pub(crate) fn stdout_reader(&self) -> LogReader {
LogReader::new(self.stdout.clone())
}
pub(crate) fn stdout_stream(&self) -> Arc<LogStream> {
self.stdout.clone()
}
pub(crate) fn stderr_stream(&self) -> Arc<LogStream> {
self.stderr.clone()
}
pub(crate) fn stderr_reader(&self) -> LogReader {
LogReader::new(self.stderr.clone())
}
pub(crate) fn stdout_sync_reader(&self) -> SyncLogReader {
SyncLogReader::new(self.stdout.clone())
}
pub(crate) fn stderr_sync_reader(&self) -> SyncLogReader {
SyncLogReader::new(self.stderr.clone())
}
pub(crate) fn stdout_oneshot(&self) -> OneshotReader {
OneshotReader::new(self.socket_path.clone(), self.id.clone(), true)
}
pub(crate) fn stderr_oneshot(&self) -> OneshotReader {
OneshotReader::new(self.socket_path.clone(), self.id.clone(), false)
}
pub(crate) fn stdout_sync_oneshot(&self) -> SyncOneshotReader {
SyncOneshotReader::new(self.socket_path.clone(), self.id.clone(), true)
}
pub(crate) fn stderr_sync_oneshot(&self) -> SyncOneshotReader {
SyncOneshotReader::new(self.socket_path.clone(), self.id.clone(), false)
}
fn register_consumer(&self) {
self.active_consumers.fetch_add(1, Ordering::SeqCst);
}
fn consumer_finished(&self) {
self.active_consumers.fetch_sub(1, Ordering::SeqCst);
}
pub(crate) fn all_done(&self) -> bool {
self.demux_done.load(Ordering::SeqCst) && self.active_consumers.load(Ordering::SeqCst) == 0
}
}
pub(crate) async fn spawn_log_session(
socket_path: String,
id: String,
) -> crate::core::error::Result<Arc<DockerLogsHandle>> {
let handle = DockerLogsHandle::new(socket_path.clone(), id.clone());
let (started_tx, started_rx) = tokio::sync::oneshot::channel();
let session_handle = handle.clone();
tokio::task::spawn_blocking(move || {
run_log_session(&socket_path, &id, &session_handle, started_tx);
});
started_rx
.await
.map_err(|_| crate::Error::other("log session task exited before startup completed"))??;
Ok(handle)
}
struct TerminateOnDrop<'a> {
handle: &'a DockerLogsHandle,
}
impl Drop for TerminateOnDrop<'_> {
fn drop(&mut self) {
self.handle.terminate_all();
}
}
struct ConsumerFinishedOnDrop {
handle: Arc<DockerLogsHandle>,
}
impl Drop for ConsumerFinishedOnDrop {
fn drop(&mut self) {
self.handle.consumer_finished();
}
}
fn run_log_session(
socket_path: &str,
id: &str,
handle: &DockerLogsHandle,
started_tx: tokio::sync::oneshot::Sender<crate::core::error::Result<()>>,
) {
let _guard = TerminateOnDrop { handle };
let mut started = Some(started_tx);
let result = start_and_demux(socket_path, id, handle, &mut started);
if let Some(tx) = started.take() {
let err = match result {
Err(e) => e,
Ok(()) => crate::Error::other("log session failed before startup completed"),
};
let _ = tx.send(Err(err));
} else if let Err(e) = result {
tracing::warn!("log stream demux terminated with error: {e}");
}
}
fn start_and_demux(
socket_path: &str,
id: &str,
handle: &DockerLogsHandle,
started: &mut Option<tokio::sync::oneshot::Sender<crate::core::error::Result<()>>>,
) -> crate::core::error::Result<()> {
let mut stream = UnixStream::connect(socket_path)?;
stream
.set_read_timeout(LOG_SESSION_TIMEOUT)
.map_err(|e| crate::core::error::Error::other(e.to_string()))?;
stream
.set_write_timeout(LOG_SESSION_TIMEOUT)
.map_err(|e| crate::core::error::Error::other(e.to_string()))?;
if let Ok(clone) = stream.try_clone() {
*handle
.shutdown_socket
.lock()
.expect("shutdown socket mutex must not be poisoned while starting log stream") =
Some(clone);
}
let path = format!(
"/containers/{}/logs?stdout=1&stderr=1&follow=true&tail=all",
crate::core::client::docker_client::percent_encode_path_segment(id)
);
let request_bytes =
crate::core::client::docker_client::encode_docker_api_request("GET", &path, None)?;
stream.write_all(&request_bytes)?;
let mut decoder = log_stream_decoder();
decoder.set_request_method("GET");
read_and_validate_head(&mut stream, &mut decoder)?;
if let Some(tx) = started.take()
&& tx.send(Ok(())).is_err()
{
return Ok(());
}
stream
.set_read_timeout(None)
.map_err(|e| crate::core::error::Error::other(e.to_string()))?;
stream
.set_write_timeout(None)
.map_err(|e| crate::core::error::Error::other(e.to_string()))?;
demux_loop(&mut stream, &mut decoder, handle)
}
fn read_and_validate_head(
stream: &mut UnixStream,
decoder: &mut ResponseDecoder,
) -> crate::core::error::Result<()> {
let head = loop {
let want = decoder.available_buf().min(READ_CHUNK);
if want == 0 {
return Err(io_other("decoder buffer full while reading log head").into());
}
let buf = decoder
.mut_buf(want)
.map_err(|e| crate::Error::other(io_other(e.to_string())))?;
let n = stream.read(buf)?;
decoder.advance_buf(n);
if n == 0 {
decoder.mark_eof();
}
match decoder
.decode_headers()
.map_err(|e| crate::Error::other(io_other(e.to_string())))?
{
Some((head, _body_kind)) => break head,
None => {
if n == 0 {
return Err(io_other("connection closed before log head complete").into());
}
}
}
};
let status = head.status_code();
if status != 200 {
return Err(io_other(format!("logs request failed with status {status}")).into());
}
let content_type = head
.headers()
.iter()
.find(|(name, _)| name.as_str().eq_ignore_ascii_case("content-type"))
.map(|(_, value)| value.as_str());
if !is_multiplex_content_type(content_type) {
return Err(io_other(format!(
"unsupported log stream content type: {}",
content_type.unwrap_or("<absent>")
))
.into());
}
Ok(())
}
fn is_multiplex_content_type(content_type: Option<&str>) -> bool {
match content_type {
None => true,
Some(ct) => {
let media = ct.split(';').next().unwrap_or(ct).trim();
media.is_empty()
|| media.eq_ignore_ascii_case("application/vnd.docker.multiplexed-stream")
|| media.eq_ignore_ascii_case("application/octet-stream")
}
}
}
fn drain_decoded(
decoder: &mut ResponseDecoder,
demuxer: &mut FrameDemuxer,
handle: &DockerLogsHandle,
) -> crate::core::error::Result<()> {
loop {
let peeked = decoder.peek_body().map(|data| data.len());
if let Some(len) = peeked {
let (wrote_out, wrote_err) = {
let data = decoder
.peek_body()
.expect("peek_body must return data right after measuring length");
let mut stdout = handle
.stdout
.buffer
.lock()
.expect("stdout buffer mutex must not be poisoned while demuxing logs");
let mut stderr = handle
.stderr
.buffer
.lock()
.expect("stderr buffer mutex must not be poisoned while demuxing logs");
demuxer
.feed(data, &mut stdout, &mut stderr)
.map_err(crate::Error::other)?
};
decoder
.consume_body(len)
.map_err(|e| crate::Error::other(io_other(e.to_string())))?;
if wrote_out {
handle.stdout.notify.notify_waiters();
}
if wrote_err {
handle.stderr.notify.notify_waiters();
}
continue;
}
match decoder
.progress()
.map_err(|e| crate::Error::other(io_other(e.to_string())))?
{
BodyProgress::Complete { .. } => return Ok(()),
BodyProgress::Advanced => continue,
BodyProgress::NeedData => return Ok(()),
}
}
}
fn demux_loop(
stream: &mut UnixStream,
decoder: &mut ResponseDecoder,
handle: &DockerLogsHandle,
) -> crate::core::error::Result<()> {
let mut demuxer = FrameDemuxer::new();
loop {
if handle.log_stop.load(Ordering::SeqCst) {
return Ok(());
}
drain_decoded(decoder, &mut demuxer, handle)?;
let want = decoder.available_buf().min(READ_CHUNK);
if want == 0 {
return Err(io_other("decoder buffer full while streaming logs").into());
}
let buf = decoder
.mut_buf(want)
.map_err(|e| crate::Error::other(io_other(e.to_string())))?;
let n = stream.read(buf)?;
decoder.advance_buf(n);
if n == 0 {
decoder.mark_eof();
drain_decoded(decoder, &mut demuxer, handle)?;
return Ok(());
}
}
}
fn fetch_logs_oneshot_blocking(socket_path: &str, id: &str) -> std::io::Result<(Vec<u8>, Vec<u8>)> {
fetch_logs_oneshot_blocking_with_limit(
socket_path,
id,
crate::core::client::docker_client::DOCKER_RESPONSE_BODY_LIMIT,
)
}
fn fetch_logs_oneshot_blocking_with_limit(
socket_path: &str,
id: &str,
limit: usize,
) -> std::io::Result<(Vec<u8>, Vec<u8>)> {
let mut stream = UnixStream::connect(socket_path)?;
stream.set_read_timeout(LOG_SESSION_TIMEOUT)?;
stream.set_write_timeout(LOG_SESSION_TIMEOUT)?;
let path = format!(
"/containers/{}/logs?stdout=1&stderr=1&follow=false&tail=all",
crate::core::client::docker_client::percent_encode_path_segment(id)
);
let request_bytes =
crate::core::client::docker_client::encode_docker_api_request("GET", &path, None)
.map_err(|e| io_other(e.to_string()))?;
stream.write_all(&request_bytes)?;
let mut decoder = log_stream_decoder();
decoder.set_request_method("GET");
let mut demuxer = FrameDemuxer::new();
let mut stdout = SharedLogBuffer::new_strict(limit);
let mut stderr = SharedLogBuffer::new_strict(limit);
let mut head_done = false;
loop {
if !head_done {
let want = decoder.available_buf().min(READ_CHUNK);
if want == 0 {
return Err(io_other("decoder buffer full while reading oneshot head"));
}
let buf = decoder.mut_buf(want).map_err(|e| io_other(e.to_string()))?;
let n = stream.read(buf)?;
decoder.advance_buf(n);
if n == 0 {
decoder.mark_eof();
}
match decoder
.decode_headers()
.map_err(|e| io_other(e.to_string()))?
{
Some((head, _body_kind)) => {
if head.status_code() != 200 {
return Err(io_other(format!(
"logs request failed with status {}",
head.status_code()
)));
}
let content_type = head
.headers()
.iter()
.find(|(name, _)| name.as_str().eq_ignore_ascii_case("content-type"))
.map(|(_, value)| value.as_str());
if !is_multiplex_content_type(content_type) {
return Err(io_other(format!(
"unsupported log stream content type: {}",
content_type.unwrap_or("<absent>")
)));
}
head_done = true;
}
None => {
if n == 0 {
return Err(io_other("connection closed before oneshot head complete"));
}
continue;
}
}
}
if drain_oneshot_body(&mut decoder, &mut demuxer, &mut stdout, &mut stderr)? {
break;
}
let want = decoder.available_buf().min(READ_CHUNK);
if want == 0 {
return Err(io_other("decoder buffer full while reading oneshot body"));
}
let buf = decoder.mut_buf(want).map_err(|e| io_other(e.to_string()))?;
let n = stream.read(buf)?;
decoder.advance_buf(n);
if n == 0 {
decoder.mark_eof();
drain_oneshot_body(&mut decoder, &mut demuxer, &mut stdout, &mut stderr)?;
break;
}
}
let out = drain_buffer(&stdout);
let err = drain_buffer(&stderr);
Ok((out, err))
}
fn drain_oneshot_body(
decoder: &mut ResponseDecoder,
demuxer: &mut FrameDemuxer,
stdout: &mut SharedLogBuffer,
stderr: &mut SharedLogBuffer,
) -> std::io::Result<bool> {
loop {
let peeked = decoder.peek_body().map(|data| data.len());
if let Some(len) = peeked {
let data = decoder
.peek_body()
.expect("peek_body must return data right after measuring length");
demuxer.feed(data, stdout, stderr)?;
decoder
.consume_body(len)
.map_err(|e| io_other(e.to_string()))?;
continue;
}
return Ok(
match decoder.progress().map_err(|e| io_other(e.to_string()))? {
BodyProgress::Complete { .. } => true,
BodyProgress::Advanced => continue,
BodyProgress::NeedData => false,
},
);
}
}
fn drain_buffer(buffer: &SharedLogBuffer) -> Vec<u8> {
let mut out = Vec::new();
let mut chunk = [0u8; READ_CHUNK];
let mut offset = buffer.head;
loop {
let (n, next, _) = buffer.read_at(offset, &mut chunk);
if n == 0 {
break;
}
out.extend_from_slice(&chunk[..n]);
offset = next;
}
out
}
pub(crate) struct LogReader {
stream: Arc<LogStream>,
offset: u64,
warned_skip: bool,
buf: Vec<u8>,
pos: usize,
wait: Option<Pin<Box<dyn Future<Output = ()> + Send>>>,
}
impl LogReader {
fn new(stream: Arc<LogStream>) -> Self {
Self {
stream,
offset: 0,
warned_skip: false,
buf: Vec::new(),
pos: 0,
wait: None,
}
}
fn poll_fill(&mut self, cx: &mut Context<'_>) -> Poll<std::io::Result<&[u8]>> {
loop {
if self.pos < self.buf.len() {
return Poll::Ready(Ok(&self.buf[self.pos..]));
}
let wait = self.wait.get_or_insert_with(|| {
let stream = self.stream.clone();
Box::pin(async move { stream.notify.notified().await })
});
if wait.as_mut().poll(cx).is_ready() {
self.wait = None;
continue;
}
self.buf.clear();
self.pos = 0;
self.buf.resize(READ_CHUNK, 0);
let (n, next, skipped) = {
let guard = self
.stream
.buffer
.lock()
.expect("log buffer mutex must not be poisoned while reading logs");
guard.read_at(self.offset, &mut self.buf)
};
self.offset = next;
self.buf.truncate(n);
if skipped && !self.warned_skip {
tracing::warn!("log buffer overflow detected; skipping dropped bytes");
self.warned_skip = true;
}
if n > 0 {
self.wait = None;
return Poll::Ready(Ok(&self.buf[self.pos..]));
}
if self.stream.terminated.load(Ordering::SeqCst) {
self.wait = None;
return Poll::Ready(Ok(&[]));
}
return Poll::Pending;
}
}
}
impl AsyncBufRead for LogReader {
fn poll_fill_buf(self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll<std::io::Result<&[u8]>> {
self.get_mut().poll_fill(cx)
}
fn consume(self: Pin<&mut Self>, amt: usize) {
let this = self.get_mut();
this.pos = (this.pos + amt).min(this.buf.len());
}
}
impl tokio::io::AsyncRead for LogReader {
fn poll_read(
self: Pin<&mut Self>,
cx: &mut Context<'_>,
buf: &mut ReadBuf<'_>,
) -> Poll<std::io::Result<()>> {
let this = self.get_mut();
match this.poll_fill(cx) {
Poll::Pending => Poll::Pending,
Poll::Ready(Err(e)) => Poll::Ready(Err(e)),
Poll::Ready(Ok(data)) => {
let n = data.len().min(buf.remaining());
buf.put_slice(&data[..n]);
this.pos += n;
Poll::Ready(Ok(()))
}
}
}
}
pub(crate) struct SyncLogReader {
stream: Arc<LogStream>,
offset: u64,
warned_skip: bool,
}
impl SyncLogReader {
fn new(stream: Arc<LogStream>) -> Self {
Self {
stream,
offset: 0,
warned_skip: false,
}
}
}
impl Read for SyncLogReader {
fn read(&mut self, buf: &mut [u8]) -> std::io::Result<usize> {
loop {
let (n, next, skipped) = {
let guard = self
.stream
.buffer
.lock()
.expect("log buffer mutex must not be poisoned while reading logs");
guard.read_at(self.offset, buf)
};
self.offset = next;
if skipped && !self.warned_skip {
tracing::warn!("log buffer overflow detected; skipping dropped bytes");
self.warned_skip = true;
}
if n > 0 {
return Ok(n);
}
if self.stream.terminated.load(Ordering::SeqCst) {
return Ok(0);
}
std::thread::park_timeout(Duration::from_millis(50));
}
}
}
pub(crate) struct SyncOneshotReader {
socket_path: String,
id: String,
stdout: bool,
data: Option<Vec<u8>>,
pos: usize,
failed: bool,
}
impl SyncOneshotReader {
fn new(socket_path: String, id: String, stdout: bool) -> Self {
Self {
socket_path,
id,
stdout,
data: None,
pos: 0,
failed: false,
}
}
}
impl Read for SyncOneshotReader {
fn read(&mut self, buf: &mut [u8]) -> std::io::Result<usize> {
if self.data.is_none() && !self.failed {
match fetch_logs_oneshot_blocking(&self.socket_path, &self.id) {
Ok((out, err)) => {
self.data = Some(if self.stdout { out } else { err });
}
Err(e) => {
self.failed = true;
return Err(e);
}
}
}
if self.failed {
return Err(io_other("oneshot log reader already failed"));
}
let data = self
.data
.as_ref()
.expect("data must be fetched before reading oneshot logs");
let remaining = &data[self.pos..];
let n = remaining.len().min(buf.len());
buf[..n].copy_from_slice(&remaining[..n]);
self.pos += n;
Ok(n)
}
}
pub(crate) struct OneshotReader {
socket_path: String,
id: String,
stdout: bool,
state: OneshotState,
}
enum OneshotState {
NotStarted,
Running {
rx: tokio::sync::oneshot::Receiver<std::io::Result<(Vec<u8>, Vec<u8>)>>,
},
Done {
data: Vec<u8>,
pos: usize,
},
Failed,
}
impl OneshotReader {
fn new(socket_path: String, id: String, stdout: bool) -> Self {
Self {
socket_path,
id,
stdout,
state: OneshotState::NotStarted,
}
}
}
impl tokio::io::AsyncRead for OneshotReader {
fn poll_read(
self: Pin<&mut Self>,
cx: &mut Context<'_>,
buf: &mut ReadBuf<'_>,
) -> Poll<std::io::Result<()>> {
let this = self.get_mut();
loop {
match &mut this.state {
OneshotState::NotStarted => {
let socket_path = this.socket_path.clone();
let id = this.id.clone();
let (tx, rx) = tokio::sync::oneshot::channel();
tokio::task::spawn_blocking(move || {
let result = fetch_logs_oneshot_blocking(&socket_path, &id);
let _ = tx.send(result);
});
this.state = OneshotState::Running { rx };
}
OneshotState::Running { rx } => match Pin::new(rx).poll(cx) {
Poll::Pending => return Poll::Pending,
Poll::Ready(Ok(Ok((out, err)))) => {
let data = if this.stdout { out } else { err };
this.state = OneshotState::Done { data, pos: 0 };
}
Poll::Ready(Ok(Err(e))) => {
this.state = OneshotState::Failed;
return Poll::Ready(Err(e));
}
Poll::Ready(Err(_)) => {
this.state = OneshotState::Failed;
return Poll::Ready(Err(io_other("oneshot log fetch task cancelled")));
}
},
OneshotState::Done { data, pos } => {
let remaining = &data[*pos..];
let n = remaining.len().min(buf.remaining());
buf.put_slice(&remaining[..n]);
*pos += n;
return Poll::Ready(Ok(()));
}
OneshotState::Failed => {
return Poll::Ready(Err(io_other("oneshot log reader already failed")));
}
}
}
}
}
pub(crate) fn spawn_log_consumer_task(
handle: Arc<DockerLogsHandle>,
stream: Arc<LogStream>,
consumers: Arc<Vec<Box<dyn LogConsumer + 'static>>>,
to_frame: fn(Vec<u8>) -> LogFrame,
) {
handle.register_consumer();
tokio::spawn(async move {
let _guard = ConsumerFinishedOnDrop {
handle: handle.clone(),
};
let mut reader = tokio::io::BufReader::new(LogReader::new(stream));
let mut buf = Vec::new();
loop {
buf.clear();
match reader.read_until(b'\n', &mut buf).await {
Ok(0) => break,
Ok(_) => {
if buf.last() == Some(&b'\n') {
buf.pop();
}
if buf.last() == Some(&b'\r') {
buf.pop();
}
let frame = to_frame(std::mem::take(&mut buf));
for consumer in consumers.as_ref() {
consumer.accept(&frame).await;
}
}
Err(e) => {
tracing::warn!("log consumer read failed; stopping delivery: {e}");
break;
}
}
}
});
}
#[cfg(test)]
pub(crate) fn new_shared_log_buffer_for_test(
limit: usize,
) -> (Arc<LogStream>, LogReader, LogReader) {
let stream = LogStream::new(limit);
let r1 = LogReader::new(stream.clone());
let r2 = LogReader::new(stream.clone());
(stream, r1, r2)
}
#[cfg(test)]
mod tests {
use super::*;
fn frame(stream_type: u8, payload: &[u8]) -> Vec<u8> {
let mut out = Vec::new();
out.push(stream_type);
out.extend_from_slice(&[0, 0, 0]);
out.extend_from_slice(&(payload.len() as u32).to_be_bytes());
out.extend_from_slice(payload);
out
}
#[test]
fn demux_separates_stdout_and_stderr() {
let mut stdout = SharedLogBuffer::new(DEFAULT_BUFFER_LIMIT);
let mut stderr = SharedLogBuffer::new(DEFAULT_BUFFER_LIMIT);
let mut demuxer = FrameDemuxer::new();
let mut input = frame(1, b"out1");
input.extend(frame(2, b"err1"));
input.extend(frame(1, b"out2"));
demuxer
.feed(&input, &mut stdout, &mut stderr)
.expect("非 strict バッファでは feed は失敗しないこと");
assert_eq!(drain_buffer(&stdout), b"out1out2");
assert_eq!(drain_buffer(&stderr), b"err1");
}
#[test]
fn demux_handles_frame_split_across_chunks() {
let mut stdout = SharedLogBuffer::new(DEFAULT_BUFFER_LIMIT);
let mut stderr = SharedLogBuffer::new(DEFAULT_BUFFER_LIMIT);
let mut demuxer = FrameDemuxer::new();
let input = frame(1, b"hello world");
let split_points = [3usize, 8, 12];
let mut prev = 0;
for &sp in &split_points {
demuxer
.feed(&input[prev..sp], &mut stdout, &mut stderr)
.expect("非 strict バッファでは feed は失敗しないこと");
prev = sp;
}
demuxer
.feed(&input[prev..], &mut stdout, &mut stderr)
.expect("非 strict バッファでは feed は失敗しないこと");
assert_eq!(drain_buffer(&stdout), b"hello world");
}
#[test]
fn demux_ignores_stdin_and_empty_payload() {
let mut stdout = SharedLogBuffer::new(DEFAULT_BUFFER_LIMIT);
let mut stderr = SharedLogBuffer::new(DEFAULT_BUFFER_LIMIT);
let mut demuxer = FrameDemuxer::new();
let mut input = frame(0, b"stdin");
input.extend(frame(1, b""));
input.extend(frame(2, b"e"));
demuxer
.feed(&input, &mut stdout, &mut stderr)
.expect("非 strict バッファでは feed は失敗しないこと");
assert_eq!(drain_buffer(&stdout), b"");
assert_eq!(drain_buffer(&stderr), b"e");
}
#[test]
fn demux_ignores_unknown_stream_types() {
let mut stdout = SharedLogBuffer::new(DEFAULT_BUFFER_LIMIT);
let mut stderr = SharedLogBuffer::new(DEFAULT_BUFFER_LIMIT);
let mut demuxer = FrameDemuxer::new();
let mut input = frame(3, b"x");
input.extend(frame(255, b"y"));
input.extend(frame(1, b"ok"));
demuxer
.feed(&input, &mut stdout, &mut stderr)
.expect("非 strict バッファでは feed は失敗しないこと");
assert_eq!(drain_buffer(&stdout), b"ok");
assert_eq!(drain_buffer(&stderr), b"");
}
#[test]
fn demux_huge_payload_len_does_not_allocate_upfront() {
let mut stdout = SharedLogBuffer::new(DEFAULT_BUFFER_LIMIT);
let mut stderr = SharedLogBuffer::new(DEFAULT_BUFFER_LIMIT);
let mut demuxer = FrameDemuxer::new();
let mut input = vec![1u8, 0, 0, 0];
input.extend_from_slice(&u32::MAX.to_be_bytes());
input.extend_from_slice(b"abc");
demuxer
.feed(&input, &mut stdout, &mut stderr)
.expect("非 strict バッファでは feed は失敗しないこと");
assert_eq!(drain_buffer(&stdout), b"abc");
assert!(demuxer.in_payload, "巨大 payload 待ちの状態を維持すること");
assert_eq!(demuxer.payload_remaining, u32::MAX as usize - 3);
}
#[test]
fn shared_buffer_drops_oldest_over_limit() {
let mut buffer = SharedLogBuffer::new(8);
buffer.append(b"abcdefgh");
buffer.append(b"ijkl");
let mut out = [0u8; 16];
let (n, _, _) = buffer.read_at(0, &mut out);
assert_eq!(n, 8);
assert_eq!(&out[..n], b"efghijkl");
}
#[test]
fn strict_buffer_accepts_exactly_at_limit() {
let mut buffer = SharedLogBuffer::new_strict(8);
assert!(
buffer.append(b"abcdefgh"),
"ちょうど 8 バイトは成功すること"
);
assert_eq!(drain_buffer(&buffer), b"abcdefgh");
}
#[test]
fn strict_buffer_rejects_over_limit() {
let mut buffer = SharedLogBuffer::new_strict(8);
assert!(buffer.append(b"abcdefgh"), "先頭 8 バイトは成功すること");
assert!(!buffer.append(b"i"), "9 バイト目で上限超過を検知すること");
assert_eq!(drain_buffer(&buffer), b"abcdefgh");
}
#[test]
fn strict_buffer_rejects_single_chunk_over_limit() {
let mut buffer = SharedLogBuffer::new_strict(8);
assert!(!buffer.append(b"abcdefghi"), "9 バイト投入は検知されること");
assert_eq!(drain_buffer(&buffer), b"", "超過分は一切追記されないこと");
}
#[test]
fn strict_demux_reports_overflow_error() {
let mut stdout = SharedLogBuffer::new_strict(8);
let mut stderr = SharedLogBuffer::new_strict(8);
let mut demuxer = FrameDemuxer::new();
let ok = demuxer.feed(&frame(1, b"abcdefgh"), &mut stdout, &mut stderr);
assert!(ok.is_ok(), "ちょうど上限までは成功すること: {ok:?}");
let err = demuxer.feed(&frame(1, b"i"), &mut stdout, &mut stderr);
assert!(err.is_err(), "上限超過はエラーになること");
assert_eq!(
err.expect_err("エラーであること").to_string(),
"stdout output exceeds 8 bytes limit"
);
}
#[test]
fn strict_demux_reports_stderr_overflow_error() {
let mut stdout = SharedLogBuffer::new_strict(8);
let mut stderr = SharedLogBuffer::new_strict(8);
let mut demuxer = FrameDemuxer::new();
demuxer
.feed(&frame(2, b"abcdefgh"), &mut stdout, &mut stderr)
.expect("ちょうど上限までは成功すること");
let err = demuxer.feed(&frame(2, b"i"), &mut stdout, &mut stderr);
assert!(err.is_err(), "stderr の上限超過はエラーになること");
assert_eq!(
err.expect_err("エラーであること").to_string(),
"stderr output exceeds 8 bytes limit"
);
}
#[test]
fn shared_buffer_reader_behind_head_is_skipped() {
let mut buffer = SharedLogBuffer::new(4);
buffer.append(b"abcd");
buffer.append(b"ef");
let mut out = [0u8; 8];
let (n, next, skipped) = buffer.read_at(0, &mut out);
assert!(skipped, "先頭 drop 済みならスキップフラグが立つこと");
assert_eq!(&out[..n], b"cdef");
assert_eq!(next, 6);
}
#[tokio::test]
async fn log_reader_returns_independent_offsets() {
let (stream, mut r1, mut r2) = new_shared_log_buffer_for_test(DEFAULT_BUFFER_LIMIT);
stream
.buffer
.lock()
.expect("テストでロックが取得できること")
.append(b"first");
stream.notify.notify_waiters();
let mut buf1 = vec![0u8; 5];
tokio::io::AsyncReadExt::read_exact(&mut r1, &mut buf1)
.await
.expect("r1 の読み取りに失敗した");
assert_eq!(buf1, b"first");
stream.terminate();
let mut buf2 = Vec::new();
tokio::io::AsyncReadExt::read_to_end(&mut r2, &mut buf2)
.await
.expect("r2 の読み取りに失敗した");
assert_eq!(buf2, b"first");
}
#[tokio::test]
async fn log_reader_wakes_on_append_notify() {
let (stream, mut r, _r2) = new_shared_log_buffer_for_test(DEFAULT_BUFFER_LIMIT);
let writer = stream.clone();
tokio::spawn(async move {
tokio::time::sleep(std::time::Duration::from_millis(50)).await;
writer
.buffer
.lock()
.expect("テストでロックが取得できること")
.append(b"later");
writer.notify.notify_waiters();
});
let mut buf = vec![0u8; 5];
tokio::time::timeout(
std::time::Duration::from_secs(5),
tokio::io::AsyncReadExt::read_exact(&mut r, &mut buf),
)
.await
.expect("追記通知で起床せずタイムアウトした")
.expect("読み取りに失敗した");
assert_eq!(buf, b"later");
}
#[tokio::test]
async fn log_reader_eofs_when_terminated_and_empty() {
let (stream, mut r, _r2) = new_shared_log_buffer_for_test(DEFAULT_BUFFER_LIMIT);
stream.terminate();
let mut buf = Vec::new();
tokio::io::AsyncReadExt::read_to_end(&mut r, &mut buf)
.await
.expect("terminated 後の読み取りに失敗した");
assert_eq!(buf, b"");
}
#[test]
fn sync_log_reader_eofs_when_terminated() {
let (stream, _r1, _r2) = new_shared_log_buffer_for_test(DEFAULT_BUFFER_LIMIT);
let mut sync_reader = SyncLogReader::new(stream.clone());
stream
.buffer
.lock()
.expect("テストでロックが取得できること")
.append(b"data");
stream.terminate();
let mut out = Vec::new();
sync_reader
.read_to_end(&mut out)
.expect("同期リーダーの読み取りに失敗した");
assert_eq!(out, b"data");
}
#[test]
fn multiplex_content_type_detection() {
assert!(is_multiplex_content_type(None));
assert!(is_multiplex_content_type(Some("")));
assert!(is_multiplex_content_type(Some(
"application/vnd.docker.multiplexed-stream"
)));
assert!(is_multiplex_content_type(Some("application/octet-stream")));
assert!(is_multiplex_content_type(Some(
"application/octet-stream; charset=x"
)));
assert!(!is_multiplex_content_type(Some(
"application/vnd.docker.raw-stream"
)));
}
#[test]
fn oneshot_returns_without_hang_on_truncated_body() {
use std::io::{Read, Write};
use std::os::unix::net::UnixListener;
let path = std::env::temp_dir().join(format!(
"container-rs-log-oneshot-test-{}.sock",
std::process::id()
));
let _ = std::fs::remove_file(&path);
let listener = UnixListener::bind(&path).expect("UnixListener の bind に失敗した");
let server = std::thread::spawn(move || {
let (mut conn, _) = listener.accept().expect("accept に失敗した");
let mut req = [0u8; 1024];
let _ = conn.read(&mut req);
let mut frame = vec![1u8, 0, 0, 0];
frame.extend_from_slice(&3u32.to_be_bytes());
frame.extend_from_slice(b"abc");
let head = "HTTP/1.1 200 OK\r\n\
Content-Type: application/vnd.docker.multiplexed-stream\r\n\
Content-Length: 100\r\n\
\r\n";
conn.write_all(head.as_bytes())
.expect("ヘッダ書き込みに失敗した");
conn.write_all(&frame).expect("フレーム書き込みに失敗した");
});
let socket_path = path
.to_str()
.expect("ソケットパスが UTF-8 であること")
.to_string();
let (tx, rx) = std::sync::mpsc::channel();
std::thread::spawn(move || {
let _ = tx.send(fetch_logs_oneshot_blocking(&socket_path, "test-id"));
});
let result = rx
.recv_timeout(std::time::Duration::from_secs(10))
.expect("fetch_logs_oneshot_blocking がタイムアウトした (ビジーループの疑い)");
server.join().expect("サーバスレッドが panic した");
let _ = std::fs::remove_file(&path);
let (out, err) = result.expect("異常 EOF でもエラーにならず戻ること");
assert_eq!(out, b"abc", "受信済みの stdout フレームを demux すること");
assert_eq!(err, b"");
}
#[test]
fn oneshot_aborts_early_when_over_limit() {
use std::io::{Read, Write};
use std::os::unix::net::UnixListener;
let path = std::env::temp_dir().join(format!(
"container-rs-log-oneshot-limit-test-{}.sock",
std::process::id()
));
let _ = std::fs::remove_file(&path);
let listener = UnixListener::bind(&path).expect("UnixListener の bind に失敗した");
let server = std::thread::spawn(move || {
let (mut conn, _) = listener.accept().expect("accept に失敗した");
let mut req = [0u8; 1024];
let _ = conn.read(&mut req);
let head = "HTTP/1.1 200 OK\r\n\
Content-Type: application/vnd.docker.multiplexed-stream\r\n\
\r\n";
conn.write_all(head.as_bytes())
.expect("ヘッダ書き込みに失敗した");
let mut frame = vec![1u8, 0, 0, 0];
frame.extend_from_slice(&9u32.to_be_bytes());
frame.extend_from_slice(b"abcdefghi");
while conn.write_all(&frame).is_ok() {}
});
let socket_path = path
.to_str()
.expect("ソケットパスが UTF-8 であること")
.to_string();
let (tx, rx) = std::sync::mpsc::channel();
std::thread::spawn(move || {
let _ = tx.send(fetch_logs_oneshot_blocking_with_limit(
&socket_path,
"test-id",
8,
));
});
let result = rx
.recv_timeout(std::time::Duration::from_secs(10))
.expect("fetch_logs_oneshot_blocking がタイムアウトした (ビジーループの疑い)");
server.join().expect("サーバスレッドが panic した");
let _ = std::fs::remove_file(&path);
let err = result.expect_err("上限超過はエラーになること");
assert_eq!(
err.to_string(),
"stdout output exceeds 8 bytes limit",
"エラー文言がストリーム識別子と上限を明示すること"
);
}
#[test]
fn log_stream_decoder_has_unlimited_body_size() {
assert_eq!(log_stream_decoder().limits().max_body_size, u64::MAX);
}
fn append_line(handle: &DockerLogsHandle, line: &[u8]) {
let stream = handle.stdout_stream();
let mut buffer = stream
.buffer
.lock()
.expect("ログストリームのバッファ mutex が poison されていないこと");
buffer.append(line);
drop(buffer);
stream.notify.notify_waiters();
}
#[tokio::test]
async fn consumer_panic_still_decrements_active_consumers() {
use crate::core::logs::LogFrame;
let handle = DockerLogsHandle::new("unused-socket".to_string(), "test-id".to_string());
let consumers = Arc::new(vec![Box::new(|_: &LogFrame| -> () {
panic!("意図的な consumer の panic");
}) as Box<dyn LogConsumer + 'static>]);
spawn_log_consumer_task(
handle.clone(),
handle.stdout_stream(),
consumers,
LogFrame::StdOut,
);
assert_eq!(
handle
.active_consumers
.load(std::sync::atomic::Ordering::SeqCst),
1,
"配信タスク起動直後はカウンタが 1 であること (register_consumer が効いていること)"
);
append_line(&handle, b"hello\n");
let deadline = tokio::time::Instant::now() + std::time::Duration::from_secs(2);
loop {
if handle
.active_consumers
.load(std::sync::atomic::Ordering::SeqCst)
== 0
{
break;
}
if tokio::time::Instant::now() > deadline {
panic!("panic 後も active_consumers が 0 に戻らなかったこと");
}
tokio::time::sleep(std::time::Duration::from_millis(20)).await;
}
handle.terminate_all();
assert!(
handle.all_done(),
"panic 後も all_done() が true になること"
);
}
#[tokio::test]
async fn consumer_normal_finish_decrements_active_consumers_once() {
use std::sync::atomic::Ordering;
use crate::core::logs::LogFrame;
let handle = DockerLogsHandle::new("unused-socket".to_string(), "test-id".to_string());
let received = std::sync::Arc::new(std::sync::atomic::AtomicUsize::new(0));
let received_clone = received.clone();
let consumers = Arc::new(vec![Box::new(move |_: &LogFrame| {
received_clone.fetch_add(1, Ordering::SeqCst);
}) as Box<dyn LogConsumer + 'static>]);
spawn_log_consumer_task(
handle.clone(),
handle.stdout_stream(),
consumers,
LogFrame::StdOut,
);
assert_eq!(
handle.active_consumers.load(Ordering::SeqCst),
1,
"配信タスク起動直後はカウンタが 1 であること"
);
append_line(&handle, b"hello\n");
let received_deadline = tokio::time::Instant::now() + std::time::Duration::from_secs(2);
loop {
if received.load(Ordering::SeqCst) == 1 {
break;
}
if tokio::time::Instant::now() > received_deadline {
panic!("配信されたフレームが 1 件に達しなかったこと");
}
tokio::time::sleep(std::time::Duration::from_millis(20)).await;
}
handle.terminate_all();
let deadline = tokio::time::Instant::now() + std::time::Duration::from_secs(2);
loop {
if handle.active_consumers.load(Ordering::SeqCst) == 0 {
break;
}
if tokio::time::Instant::now() > deadline {
panic!("正常終了後も active_consumers が 0 に戻らなかったこと");
}
tokio::time::sleep(std::time::Duration::from_millis(20)).await;
}
assert!(
handle.all_done(),
"正常終了後も all_done() が true になること"
);
}
}