Add a funtion to forge Android logd entry (#13)

* Add a funtion to forge Android logd entry

* Remove chrono dependency and use SystemTime

Remove the additional heavy dependency `chrono` by using
`std::time::SystemTime` instead of secs and subsecs.

* Reuse formatting for non android systems

* Use SystemTime in Record

---------

Co-authored-by: Dmytrii Vitman <dmytrii.vitman@accenture.com>
Co-authored-by: Felix Obenhuber <felix.obenhuber@esrlabs.com>

Cargo.toml

@@ -23,7 +23,7 @@ lazy_static = { version = "1.4", optional = true }
 log = { version = "0.4", features = ["std"] }
 parking_lot = "0.12"
 thiserror = "1"
-time = { version = "0.3", features = ["formatting"] }
+time = { version = "0.3", features = ["formatting", "macros"] }
 
 [target.'cfg(unix)'.dependencies]
 libc = "0.2.139"

src/lib.rs

@@ -63,6 +63,15 @@
 //! android_logd_logger::write_event_now(1, "test").unwrap();
 //! ```
 //!
+//! To forge android logd entry:
+//!
+//! ```
+//! # use android_logd_logger::{Buffer, Priority};
+//! # use std::time::SystemTime;
+//!
+//! android_logd_logger::log(SystemTime::now(), Buffer::Main, Priority::Info, 0, 0, "tag", "message").unwrap();
+//! ```
+//!
 //! # Configuration
 //!
 //! Writing to the logd socket is a single point of synchronization for threads.
@@ -84,7 +93,7 @@ use env_logger::filter::Builder as FilterBuilder;
 use log::{set_boxed_logger, LevelFilter, SetLoggerError};
 use logger::Configuration;
 use parking_lot::RwLock;
-use std::{fmt, io, sync::Arc};
+use std::{fmt, io, sync::Arc, time::SystemTime};
 use thiserror::Error;
 
 mod events;
@@ -115,20 +124,40 @@ pub enum Error {
     /// The supplied event data exceed the maximum length
     #[error("Event exceeds maximum size")]
     EventSize,
+    /// Timestamp error
+    #[error("Timestamp error: {0}")]
+    Timestamp(String),
 }
 
 /// Log priority as defined by logd
 #[derive(Clone, Copy, Debug)]
 #[repr(u8)]
-enum Priority {
+pub enum Priority {
+    /// For internal logd use only
     _Unknown = 0,
+
+    /// For internal logd use only
     _Default = 1,
+
+    /// Android verbose log level
     Verbose = 2,
+
+    /// Android debug log level
     Debug = 3,
+
+    /// Android info log level
     Info = 4,
+
+    /// Android warning log level
     Warn = 5,
+
+    /// Android error log level
     Error = 6,
+
+    /// Android fatal log level
     _Fatal = 7,
+
+    /// For internal logd use only
     _Silent = 8,
 }
 
@@ -217,11 +246,8 @@ enum TagMode {
 /// consistent timestamps and other information to both the `logd` and the
 /// `pmsg` device without paying the price for system calls twice.
 struct Record<'tag, 'msg> {
-    timestamp_secs: u32,
-    timestamp_subsec_nanos: u32,
-    #[allow(unused)]
+    timestamp: SystemTime,
     pid: u16,
-    #[allow(unused)]
     thread_id: u16,
     buffer_id: Buffer,
     tag: &'tag str,
@@ -490,3 +516,110 @@ impl Builder {
             .expect("Builder::init should not be called after logger initialized")
     }
 }
+
+/// Construct a log entry and send it to the logd writer socket
+///
+/// This can be used to forge an android logd entry
+///
+/// # Example
+///
+/// ```
+/// # use android_logd_logger::{Buffer, Priority};
+/// # use std::time::SystemTime;
+///
+/// android_logd_logger::log(SystemTime::now(), Buffer::Main, Priority::Info, 0, 0, "tag", "message").unwrap();
+/// ```
+#[cfg(target_os = "android")]
+pub fn log(
+    timestamp: SystemTime,
+    buffer_id: Buffer,
+    priority: Priority,
+    pid: u16,
+    thread_id: u16,
+    tag: &str,
+    message: &str,
+) -> Result<(), Error> {
+    let record = Record {
+        timestamp,
+        pid,
+        thread_id,
+        buffer_id,
+        tag,
+        priority,
+        message,
+    };
+
+    logd::log(&record);
+
+    Ok(())
+}
+
+/// Construct a log entry
+///
+/// This can be used to forge an android logd entry
+///
+/// # Example
+///
+/// ```
+/// # use android_logd_logger::{Buffer, Priority};
+/// # use std::time::SystemTime;
+///
+/// android_logd_logger::log(SystemTime::now(), Buffer::Main, Priority::Info, 0, 0, "tag", "message").unwrap();
+/// ```
+#[cfg(not(target_os = "android"))]
+pub fn log(
+    timestamp: SystemTime,
+    buffer_id: Buffer,
+    priority: Priority,
+    pid: u16,
+    thread_id: u16,
+    tag: &str,
+    message: &str,
+) -> Result<(), Error> {
+    let record = Record {
+        timestamp,
+        pid,
+        thread_id,
+        buffer_id,
+        tag,
+        priority,
+        message,
+    };
+
+    log_record(&record)
+}
+
+#[cfg(target_os = "android")]
+fn log_record(record: &Record) -> Result<(), Error> {
+    logd::log(record);
+    Ok(())
+}
+
+#[cfg(not(target_os = "android"))]
+fn log_record(record: &Record) -> Result<(), Error> {
+    use std::time::UNIX_EPOCH;
+
+    const DATE_TIME_FORMAT: &[time::format_description::FormatItem<'_>] =
+        time::macros::format_description!("[year]-[month]-[day] [hour]:[minute]:[second].[subsecond digits:3]");
+
+    let Record {
+        timestamp,
+        tag,
+        priority,
+        message,
+        thread_id,
+        pid,
+        ..
+    } = record;
+
+    let timestamp = timestamp
+        .duration_since(UNIX_EPOCH)
+        .map_err(|e| Error::Timestamp(e.to_string()))
+        .and_then(|ts| {
+            time::OffsetDateTime::from_unix_timestamp_nanos(ts.as_nanos() as i128).map_err(|e| Error::Timestamp(e.to_string()))
+        })
+        .and_then(|ts| ts.format(&DATE_TIME_FORMAT).map_err(|e| Error::Timestamp(e.to_string())))?;
+
+    println!("{} {} {} {} {}: {}", timestamp, pid, thread_id, priority, tag, message);
+    Ok(())
+}

src/logd.rs

@@ -2,6 +2,7 @@ use std::{
     io::{self, ErrorKind},
     os::unix::net::UnixDatagram,
     path::Path,
+    time::UNIX_EPOCH,
 };
 
 use bytes::BufMut;
@@ -76,13 +77,13 @@ pub(crate) fn log(record: &Record) {
     // Tag and message len with null terminator.
     let tag_len = record.tag.bytes().len() + 1;
     let message_len = record.message.bytes().len() + 1;
-
     let mut buffer = bytes::BytesMut::with_capacity(12 + tag_len + message_len);
+    let timestamp = record.timestamp.duration_since(UNIX_EPOCH).unwrap();
 
     buffer.put_u8(record.buffer_id.into());
     buffer.put_u16_le(thread::id() as u16);
-    buffer.put_u32_le(record.timestamp_secs);
-    buffer.put_u32_le(record.timestamp_subsec_nanos);
+    buffer.put_u32_le(timestamp.as_secs() as u32);
+    buffer.put_u32_le(timestamp.subsec_nanos());
     buffer.put_u8(record.priority as u8);
     buffer.put(record.tag.as_bytes());
     buffer.put_u8(0);
@@ -98,7 +99,7 @@ pub(crate) fn log(record: &Record) {
 /// Send a log event to logd
 pub(crate) fn write_event(log_buffer: Buffer, event: &Event) {
     let mut buffer = bytes::BytesMut::with_capacity(LOGGER_ENTRY_MAX_LEN);
-    let timestamp = event.timestamp.duration_since(std::time::UNIX_EPOCH).unwrap();
+    let timestamp = event.timestamp.duration_since(UNIX_EPOCH).unwrap();
 
     buffer.put_u8(log_buffer.into());
     buffer.put_u16_le(thread::id() as u16);
@@ -130,19 +131,16 @@ fn smoke() {
 
     let start = std::time::Instant::now();
     while start.elapsed() < std::time::Duration::from_secs(5) {
-        let timestamp = SystemTime::now()
-            .duration_since(std::time::UNIX_EPOCH)
-            .expect("failed to acquire time");
-        let log_record = Record {
-            timestamp_secs: timestamp.as_secs() as u32,
-            timestamp_subsec_nanos: timestamp.subsec_nanos() as u32,
+        let timestamp = SystemTime::now();
+        let record = Record {
+            timestamp,
             pid: std::process::id() as u16,
             thread_id: thread::id() as u16,
             buffer_id: Buffer::Main,
             tag: "test",
             priority: Priority::Info,
             message: "test",
         };
-        log(&log_record);
+        log(&record);
     }
 }

src/logger.rs

@@ -1,12 +1,8 @@
-#[cfg(target_os = "android")]
-use crate::{thread, Record};
-use crate::{Buffer, Priority, TagMode};
+use crate::{thread, Buffer, Priority, Record, TagMode};
 use env_logger::filter::{Builder, Filter};
 use log::{LevelFilter, Log, Metadata};
 use parking_lot::RwLock;
-#[cfg(target_os = "android")]
-use std::time::SystemTime;
-use std::{io, sync::Arc};
+use std::{io, process, sync::Arc, time::SystemTime};
 
 /// Logger configuration.
 pub(crate) struct Configuration {
@@ -199,20 +195,11 @@ impl Logger {
 /// Logger implementation.
 pub(crate) struct LoggerImpl {
     configuration: Arc<RwLock<Configuration>>,
-    #[cfg(not(target_os = "android"))]
-    timestamp_format: Vec<time::format_description::FormatItem<'static>>,
 }
 
 impl LoggerImpl {
     pub fn new(configuration: Arc<RwLock<Configuration>>) -> Result<LoggerImpl, io::Error> {
-        Ok(LoggerImpl {
-            configuration,
-            #[cfg(not(target_os = "android"))]
-            timestamp_format: time::format_description::parse(
-                "[year]-[month]-[day] [hour]:[minute]:[second].[subsecond digits:3]",
-            )
-            .unwrap(),
-        })
+        Ok(LoggerImpl { configuration })
     }
 }
 
@@ -250,41 +237,25 @@ impl Log for LoggerImpl {
             TagMode::Custom(tag) => tag.as_str(),
         };
 
+        let timestamp = SystemTime::now();
+        let record = Record {
+            timestamp,
+            pid: process::id() as u16,
+            thread_id: thread::id() as u16,
+            buffer_id: configuration.buffer_id,
+            tag,
+            priority,
+            message: &message,
+        };
+
+        crate::log_record(&record).ok();
+
         #[cfg(target_os = "android")]
         {
-            let timestamp = SystemTime::now()
-                .duration_since(std::time::UNIX_EPOCH)
-                .expect("failed to acquire time");
-            let log_record = Record {
-                timestamp_secs: timestamp.as_secs() as u32,
-                timestamp_subsec_nanos: timestamp.subsec_nanos() as u32,
-                pid: std::process::id() as u16,
-                thread_id: thread::id() as u16,
-                buffer_id: configuration.buffer_id,
-                tag,
-                priority,
-                message: &message,
-            };
-            crate::logd::log(&log_record);
             if configuration.pstore {
-                crate::pmsg::log(&log_record);
+                crate::pmsg::log(&record);
             }
         }
-
-        #[cfg(not(target_os = "android"))]
-        {
-            let now = ::time::OffsetDateTime::now_utc();
-            let timestamp = now.format(&self.timestamp_format).unwrap();
-            println!(
-                "{} {} {} {} {}: {}",
-                timestamp,
-                std::process::id(),
-                crate::thread::id(),
-                priority,
-                tag,
-                message
-            );
-        }
     }
 
     #[cfg(not(target_os = "android"))]

src/pmsg.rs

@@ -3,6 +3,7 @@ use bytes::{BufMut, BytesMut};
 use std::{
     fs::{File, OpenOptions},
     io::{self, Write},
+    time::UNIX_EPOCH,
 };
 
 /// Persistent message charater device
@@ -60,14 +61,15 @@ fn log_pmsg_packet(record: &Record, msg_part: &str) {
 
     let packet_len = PMSG_HEADER_LEN + LOG_HEADER_LEN + payload_len;
     let mut buffer = bytes::BytesMut::with_capacity(packet_len as usize);
+    let timestamp = record.timestamp.duration_since(UNIX_EPOCH).unwrap();
 
     write_pmsg_header(&mut buffer, packet_len, DUMMY_UID, record.pid);
     write_log_header(
         &mut buffer,
         record.buffer_id,
         record.thread_id,
-        record.timestamp_secs,
-        record.timestamp_subsec_nanos,
+        timestamp.as_secs() as u32,
+        timestamp.subsec_nanos(),
     );
     write_payload(&mut buffer, record.priority, record.tag, msg_part);