blob: bc4fa615e7e4f9fb9932aaab3fd3a5cbf5453b89 [file] [log] [blame] [edit]
// Copyright 2016 The android_logger Developers
//
// Licensed under the Apache License, Version 2.0, <LICENSE-APACHE or
// http://apache.org/licenses/LICENSE-2.0> or the MIT license <LICENSE-MIT or
// http://opensource.org/licenses/MIT>, at your option. This file may not be
// copied, modified, or distributed except according to those terms.
//! A logger which writes to android output.
//!
//! ## Example
//!
//! ```
//! #[macro_use] extern crate log;
//! extern crate android_logger;
//!
//! use log::Level;
//! use android_logger::Config;
//!
//! /// Android code may not have obvious "main", this is just an example.
//! fn main() {
//! android_logger::init_once(
//! Config::default().with_min_level(Level::Trace),
//! );
//!
//! debug!("this is a debug {}", "message");
//! error!("this is printed by default");
//! }
//! ```
//!
//! ## Example with module path filter
//!
//! It is possible to limit log messages to output from a specific crate,
//! and override the logcat tag name (by default, the crate name is used):
//!
//! ```
//! #[macro_use] extern crate log;
//! extern crate android_logger;
//!
//! use log::Level;
//! use android_logger::{Config,FilterBuilder};
//!
//! fn main() {
//! android_logger::init_once(
//! Config::default()
//! .with_min_level(Level::Trace)
//! .with_tag("mytag")
//! .with_filter(FilterBuilder::new().parse("debug,hello::crate=trace").build()),
//! );
//!
//! // ..
//! }
//! ```
//!
//! ## Example with a custom log formatter
//!
//! ```
//! use android_logger::Config;
//!
//! android_logger::init_once(
//! Config::default()
//! .with_min_level(log::Level::Trace)
//! .format(|f, record| write!(f, "my_app: {}", record.args()))
//! )
//! ```
#[cfg(target_os = "android")]
extern crate android_log_sys as log_ffi;
#[macro_use]
extern crate lazy_static;
#[macro_use]
extern crate log;
extern crate env_logger;
use std::sync::RwLock;
#[cfg(target_os = "android")]
use log_ffi::LogPriority;
use log::{Level, Log, Metadata, Record};
use std::ffi::{CStr, CString};
use std::mem;
use std::fmt;
use std::ptr;
pub use env_logger::filter::{Filter, Builder as FilterBuilder};
pub use env_logger::fmt::Formatter;
pub(crate) type FormatFn = Box<dyn Fn(&mut dyn fmt::Write, &Record) -> fmt::Result + Sync + Send>;
#[derive(Copy, Clone, Eq, PartialEq, Debug)]
pub enum LogId {
Main,
Radio,
Events,
System,
Crash
}
impl LogId {
#[cfg(target_os = "android")]
fn to_native(log_id: Option<Self>) -> log_ffi::log_id_t {
match log_id {
Some(LogId::Main) => log_ffi::log_id_t::MAIN,
Some(LogId::Radio) => log_ffi::log_id_t::RADIO,
Some(LogId::Events) => log_ffi::log_id_t::EVENTS,
Some(LogId::System) => log_ffi::log_id_t::SYSTEM,
Some(LogId::Crash) => log_ffi::log_id_t::CRASH,
None => log_ffi::log_id_t::DEFAULT,
}
}
}
/// Output log to android system.
#[cfg(target_os = "android")]
fn android_log(log_id: log_ffi::log_id_t, prio: log_ffi::LogPriority, tag: &CStr, msg: &CStr) {
unsafe {
log_ffi::__android_log_buf_write(log_id as i32,
prio as i32,
tag.as_ptr() as *const log_ffi::c_char,
msg.as_ptr() as *const log_ffi::c_char);
};
}
/// Dummy output placeholder for tests.
#[cfg(not(target_os = "android"))]
fn android_log(_log_id: Option<LogId>, _priority: Level, _tag: &CStr, _msg: &CStr) {}
/// Underlying android logger backend
pub struct AndroidLogger {
config: RwLock<Config>,
}
impl AndroidLogger {
/// Create new logger instance from config
pub fn new(config: Config) -> AndroidLogger {
AndroidLogger {
config: RwLock::new(config),
}
}
}
lazy_static! {
static ref ANDROID_LOGGER: AndroidLogger = AndroidLogger::default();
}
const LOGGING_TAG_MAX_LEN: usize = 23;
const LOGGING_MSG_MAX_LEN: usize = 4000;
impl Default for AndroidLogger {
/// Create a new logger with default config
fn default() -> AndroidLogger {
AndroidLogger {
config: RwLock::new(Config::default()),
}
}
}
impl Log for AndroidLogger {
fn enabled(&self, _: &Metadata) -> bool {
true
}
fn log(&self, record: &Record) {
let config = self.config
.read()
.expect("failed to acquire android_log filter lock for read");
if !config.filter_matches(record) {
return;
}
// tag must not exceed LOGGING_TAG_MAX_LEN
#[allow(deprecated)] // created an issue #35 for this
let mut tag_bytes: [u8; LOGGING_TAG_MAX_LEN + 1] = unsafe { mem::uninitialized() };
let module_path = record.module_path().unwrap_or_default().to_owned();
// If no tag was specified, use module name
let custom_tag = &config.tag;
let tag = custom_tag.as_ref().map(|s| s.as_bytes()).unwrap_or(module_path.as_bytes());
// truncate the tag here to fit into LOGGING_TAG_MAX_LEN
self.fill_tag_bytes(&mut tag_bytes, tag);
// use stack array as C string
let tag: &CStr = unsafe { CStr::from_ptr(mem::transmute(tag_bytes.as_ptr())) };
// message must not exceed LOGGING_MSG_MAX_LEN
// therefore split log message into multiple log calls
let mut writer = PlatformLogWriter::new(config.log_id, record.level(), tag);
// If a custom tag is used, add the module path to the message.
// Use PlatformLogWriter to output chunks if they exceed max size.
let _ = match (custom_tag, &config.custom_format) {
(_, Some(format)) => format(&mut writer, record),
(Some(_), _) => fmt::write(
&mut writer,
format_args!("{}: {}", module_path, *record.args()),
),
_ => fmt::write(&mut writer, *record.args()),
};
// output the remaining message (this would usually be the most common case)
writer.flush();
}
fn flush(&self) {}
}
impl AndroidLogger {
fn fill_tag_bytes(&self, array: &mut [u8], tag: &[u8]) {
if tag.len() > LOGGING_TAG_MAX_LEN {
for (input, output) in tag.iter()
.take(LOGGING_TAG_MAX_LEN - 2)
.chain(b"..\0".iter())
.zip(array.iter_mut())
{
*output = *input;
}
} else {
for (input, output) in tag.iter()
.chain(b"\0".iter())
.zip(array.iter_mut())
{
*output = *input;
}
}
}
}
/// Filter for android logger.
pub struct Config {
log_level: Option<Level>,
log_id: Option<LogId>,
filter: Option<env_logger::filter::Filter>,
tag: Option<CString>,
custom_format: Option<FormatFn>,
}
impl Default for Config {
fn default() -> Self {
Config {
log_level: None,
log_id: None,
filter: None,
tag: None,
custom_format: None,
}
}
}
impl Config {
/// Change the minimum log level.
///
/// All values above the set level are logged. For example, if
/// `Warn` is set, the `Error` is logged too, but `Info` isn't.
pub fn with_min_level(mut self, level: Level) -> Self {
self.log_level = Some(level);
self
}
/// Change which log buffer is used
///
/// By default, logs are sent to the `Main` log. Other logging buffers may only be accessible
/// to certain processes.
pub fn with_log_id(mut self, log_id: LogId) -> Self {
self.log_id = Some(log_id);
self
}
fn filter_matches(&self, record: &Record) -> bool {
if let Some(ref filter) = self.filter {
filter.matches(&record)
} else {
true
}
}
pub fn with_filter(mut self, filter: env_logger::filter::Filter) -> Self {
self.filter = Some(filter);
self
}
pub fn with_tag<S: Into<Vec<u8>>>(mut self, tag: S) -> Self {
self.tag = Some(CString::new(tag).expect("Can't convert tag to CString"));
self
}
/// Sets the format function for formatting the log output.
/// ```
/// # use android_logger::Config;
/// android_logger::init_once(
/// Config::default()
/// .with_min_level(log::Level::Trace)
/// .format(|f, record| write!(f, "my_app: {}", record.args()))
/// )
/// ```
pub fn format<F>(mut self, format: F) -> Self
where
F: Fn(&mut dyn fmt::Write, &Record) -> fmt::Result + Sync + Send + 'static,
{
self.custom_format = Some(Box::new(format));
self
}
}
struct PlatformLogWriter<'a> {
#[cfg(target_os = "android")] priority: LogPriority,
#[cfg(not(target_os = "android"))] priority: Level,
#[cfg(target_os = "android")] log_id: log_ffi::log_id_t,
#[cfg(not(target_os = "android"))] log_id: Option<LogId>,
len: usize,
last_newline_index: usize,
tag: &'a CStr,
buffer: [u8; LOGGING_MSG_MAX_LEN + 1],
}
impl<'a> PlatformLogWriter<'a> {
#[cfg(target_os = "android")]
pub fn new(log_id: Option<LogId>, level: Level, tag: &CStr) -> PlatformLogWriter {
#[allow(deprecated)] // created an issue #35 for this
PlatformLogWriter {
priority: match level {
Level::Warn => LogPriority::WARN,
Level::Info => LogPriority::INFO,
Level::Debug => LogPriority::DEBUG,
Level::Error => LogPriority::ERROR,
Level::Trace => LogPriority::VERBOSE,
},
log_id: LogId::to_native(log_id),
len: 0,
last_newline_index: 0,
tag,
buffer: unsafe { mem::uninitialized() },
}
}
#[cfg(not(target_os = "android"))]
pub fn new(log_id: Option<LogId>, level: Level, tag: &CStr) -> PlatformLogWriter {
#[allow(deprecated)] // created an issue #35 for this
PlatformLogWriter {
priority: level,
log_id,
len: 0,
last_newline_index: 0,
tag,
buffer: unsafe { mem::uninitialized() },
}
}
/// Flush some bytes to android logger.
///
/// If there is a newline, flush up to it.
/// If ther was no newline, flush all.
///
/// Not guaranteed to flush everything.
fn temporal_flush(&mut self) {
let total_len = self.len;
if total_len == 0 {
return;
}
if self.last_newline_index > 0 {
let copy_from_index = self.last_newline_index;
let remaining_chunk_len = total_len - copy_from_index;
self.output_specified_len(copy_from_index);
self.copy_bytes_to_start(copy_from_index, remaining_chunk_len);
self.len = remaining_chunk_len;
} else {
self.output_specified_len(total_len);
self.len = 0;
}
self.last_newline_index = 0;
}
/// Flush everything remaining to android logger.
fn flush(&mut self) {
let total_len = self.len;
if total_len == 0 {
return;
}
self.output_specified_len(total_len);
self.len = 0;
self.last_newline_index = 0;
}
/// Output buffer up until the \0 which will be placed at `len` position.
fn output_specified_len(&mut self, len: usize) {
let mut last_byte: u8 = b'\0';
mem::swap(&mut last_byte, unsafe {
self.buffer.get_unchecked_mut(len)
});
let msg: &CStr = unsafe { CStr::from_ptr(mem::transmute(self.buffer.as_ptr())) };
android_log(self.log_id, self.priority, self.tag, msg);
*unsafe { self.buffer.get_unchecked_mut(len) } = last_byte;
}
/// Copy `len` bytes from `index` position to starting position.
fn copy_bytes_to_start(&mut self, index: usize, len: usize) {
let src = unsafe { self.buffer.as_ptr().offset(index as isize) };
let dst = self.buffer.as_mut_ptr();
unsafe { ptr::copy(src, dst, len) };
}
}
impl<'a> fmt::Write for PlatformLogWriter<'a> {
fn write_str(&mut self, s: &str) -> fmt::Result {
let mut incomming_bytes = s.as_bytes();
while !incomming_bytes.is_empty() {
let len = self.len;
// write everything possible to buffer and mark last \n
let new_len = len + incomming_bytes.len();
let last_newline = self.buffer[len..LOGGING_MSG_MAX_LEN]
.iter_mut()
.zip(incomming_bytes)
.enumerate()
.fold(None, |acc, (i, (output, input))| {
*output = *input;
if *input == b'\n' {
Some(i)
} else {
acc
}
});
// update last \n index
if let Some(newline) = last_newline {
self.last_newline_index = len + newline;
}
// calculate how many bytes were written
let written_len = if new_len <= LOGGING_MSG_MAX_LEN {
// if the len was not exceeded
self.len = new_len;
new_len - len // written len
} else {
// if new length was exceeded
self.len = LOGGING_MSG_MAX_LEN;
self.temporal_flush();
LOGGING_MSG_MAX_LEN - len // written len
};
incomming_bytes = &incomming_bytes[written_len..];
}
Ok(())
}
}
/// Send a log record to Android logging backend.
///
/// This action does not require initialization. However, without initialization it
/// will use the default filter, which allows all logs.
pub fn log(record: &Record) {
ANDROID_LOGGER.log(record)
}
/// Initializes the global logger with an android logger.
///
/// This can be called many times, but will only initialize logging once,
/// and will not replace any other previously initialized logger.
///
/// It is ok to call this at the activity creation, and it will be
/// repeatedly called on every lifecycle restart (i.e. screen rotation).
pub fn init_once(config: Config) {
if let Err(err) = log::set_logger(&*ANDROID_LOGGER) {
debug!("android_logger: log::set_logger failed: {}", err);
} else {
if let Some(level) = config.log_level {
log::set_max_level(level.to_level_filter());
}
*ANDROID_LOGGER
.config
.write()
.expect("failed to acquire android_log filter lock for write") = config;
}
}
#[cfg(test)]
mod tests {
use super::*;
use std::fmt::Write;
use std::sync::atomic::{AtomicBool, Ordering};
#[test]
fn check_config_values() {
// Filter is checked in config_filter_match below.
let config = Config::default()
.with_min_level(Level::Trace)
.with_log_id(LogId::System)
.with_tag("my_app");
assert_eq!(config.log_level, Some(Level::Trace));
assert_eq!(config.log_id, Some(LogId::System));
assert_eq!(config.tag, Some(CString::new("my_app").unwrap()));
}
#[test]
fn log_calls_formatter() {
static FORMAT_FN_WAS_CALLED: AtomicBool = AtomicBool::new(false);
let config = Config::default()
.with_min_level(Level::Info)
.format(|_, _| {
FORMAT_FN_WAS_CALLED.store(true, Ordering::SeqCst);
Ok(())
});
let logger = AndroidLogger::new(config);
logger.log(&Record::builder().level(Level::Info).build());
assert!(FORMAT_FN_WAS_CALLED.load(Ordering::SeqCst));
}
#[test]
fn logger_always_enabled() {
let logger = AndroidLogger::new(Config::default());
assert!(logger.enabled(&log::MetadataBuilder::new().build()));
}
// Test whether the filter gets called correctly. Not meant to be exhaustive for all filter
// options, as these are handled directly by the filter itself.
#[test]
fn config_filter_match() {
let info_record = Record::builder().level(Level::Info).build();
let debug_record = Record::builder().level(Level::Debug).build();
let info_all_filter = env_logger::filter::Builder::new().parse("info").build();
let info_all_config = Config::default().with_filter(info_all_filter);
assert!(info_all_config.filter_matches(&info_record));
assert!(!info_all_config.filter_matches(&debug_record));
}
#[test]
fn fill_tag_bytes_truncates_long_tag() {
let logger = AndroidLogger::new(Config::default());
let too_long_tag: [u8; LOGGING_TAG_MAX_LEN + 20] = [b'a'; LOGGING_TAG_MAX_LEN + 20];
let mut result: [u8; LOGGING_TAG_MAX_LEN + 1] = Default::default();
logger.fill_tag_bytes(&mut result, &too_long_tag);
let mut expected_result = [b'a'; LOGGING_TAG_MAX_LEN - 2].to_vec();
expected_result.extend("..\0".as_bytes());
assert_eq!(result.to_vec(), expected_result);
}
#[test]
fn fill_tag_bytes_keeps_short_tag() {
let logger = AndroidLogger::new(Config::default());
let short_tag: [u8; 3] = [b'a'; 3];
let mut result: [u8; LOGGING_TAG_MAX_LEN + 1] = Default::default();
logger.fill_tag_bytes(&mut result, &short_tag);
let mut expected_result = short_tag.to_vec();
expected_result.push(0);
assert_eq!(result.to_vec()[..4], expected_result);
}
#[test]
fn platform_log_writer_init_values() {
let tag = CStr::from_bytes_with_nul(b"tag\0").unwrap();
let writer = PlatformLogWriter::new(None, Level::Warn, &tag);
assert_eq!(writer.tag, tag);
// Android uses LogPriority instead, which doesn't implement equality checks
#[cfg(not(target_os = "android"))]
assert_eq!(writer.priority, Level::Warn);
}
#[test]
fn temporal_flush() {
let mut writer = get_tag_writer();
writer
.write_str("12\n\n567\n90")
.expect("Unable to write to PlatformLogWriter");
assert_eq!(writer.len, 10);
writer.temporal_flush();
// Should have flushed up until the last newline.
assert_eq!(writer.len, 3);
assert_eq!(writer.last_newline_index, 0);
assert_eq!(&writer.buffer.to_vec()[..writer.len], "\n90".as_bytes());
writer.temporal_flush();
// Should have flushed all remaining bytes.
assert_eq!(writer.len, 0);
assert_eq!(writer.last_newline_index, 0);
}
#[test]
fn flush() {
let mut writer = get_tag_writer();
writer
.write_str("abcdefghij\n\nklm\nnopqr\nstuvwxyz")
.expect("Unable to write to PlatformLogWriter");
writer.flush();
assert_eq!(writer.last_newline_index, 0);
assert_eq!(writer.len, 0);
}
#[test]
fn last_newline_index() {
let mut writer = get_tag_writer();
writer
.write_str("12\n\n567\n90")
.expect("Unable to write to PlatformLogWriter");
assert_eq!(writer.last_newline_index, 7);
}
#[test]
fn output_specified_len_leaves_buffer_unchanged() {
let mut writer = get_tag_writer();
let log_string = "abcdefghij\n\nklm\nnopqr\nstuvwxyz";
writer
.write_str(log_string)
.expect("Unable to write to PlatformLogWriter");
writer.output_specified_len(5);
assert_eq!(
writer.buffer[..log_string.len()].to_vec(),
log_string.as_bytes()
);
}
#[test]
fn copy_bytes_to_start() {
let mut writer = get_tag_writer();
writer
.write_str("0123456789")
.expect("Unable to write to PlatformLogWriter");
writer.copy_bytes_to_start(3, 2);
assert_eq!(writer.buffer[..10].to_vec(), "3423456789".as_bytes());
}
#[test]
fn copy_bytes_to_start_nop() {
let test_string = "Test_string_with\n\n\n\nnewlines\n";
let mut writer = get_tag_writer();
writer
.write_str(test_string)
.expect("Unable to write to PlatformLogWriter");
writer.copy_bytes_to_start(0, 20);
writer.copy_bytes_to_start(10, 0);
assert_eq!(
writer.buffer[..test_string.len()].to_vec(),
test_string.as_bytes()
);
}
fn get_tag_writer() -> PlatformLogWriter<'static> {
PlatformLogWriter::new(None, Level::Warn, &CStr::from_bytes_with_nul(b"tag\0").unwrap())
}
}