Skip to content

Commit 070b456

Browse files
romainreignierromainreignier
committed
Add once, throttle and throttle_identical log variants
Should close adnanademovic#30
1 parent 2b75da0 commit 070b456

File tree

6 files changed

+354
-1
lines changed

6 files changed

+354
-1
lines changed

‎rosrust/src/api/ros.rs‎

Lines changed: 72 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -11,13 +11,16 @@ use crate::api::ShutdownManager;
1111
use crate::msg::rosgraph_msgs::{Clock as ClockMsg, Log};
1212
use crate::msg::std_msgs::Header;
1313
use crate::tcpros::{Client, Message, ServicePair, ServiceResult};
14+
use crate::util::FAILED_TO_LOCK;
1415
use crate::{RawMessage, RawMessageDescription};
1516
use error_chain::bail;
17+
use lazy_static::lazy_static;
1618
use log::error;
1719
use ros_message::{Duration, Time};
1820
use serde::{Deserialize, Serialize};
19-
use std::collections::HashMap;
21+
use std::collections::{HashMap, HashSet};
2022
use std::sync::Arc;
23+
use std::sync::Mutex;
2124
use std::thread::sleep;
2225
use std::time::Instant;
2326
use xml_rpc;
@@ -383,6 +386,74 @@ impl Ros {
383386
error!("Logging error: {}", err);
384387
}
385388
}
389+
390+
pub fn log_once(&self, level: i8, msg: String, file: &str, line: u32) {
391+
lazy_static! {
392+
static ref UNIQUE_LOGS: Mutex<HashSet<String>> = Mutex::new(HashSet::new());
393+
}
394+
let key = format!("{}:{}", file, line);
395+
let mut unique_logs = UNIQUE_LOGS.lock().expect(FAILED_TO_LOCK);
396+
if !unique_logs.contains(&key) {
397+
unique_logs.insert(key);
398+
self.log(level, msg, file, line);
399+
}
400+
}
401+
402+
pub fn log_throttle(&self, period: f64, level: i8, msg: String, file: &str, line: u32) {
403+
lazy_static! {
404+
static ref PERIODIC_LOGS: Mutex<HashMap<String, Time>> = Mutex::new(HashMap::new());
405+
}
406+
let now = self.now();
407+
let key = format!("{}:{}", file, line);
408+
let get_next_log_time = |now, period| now + Duration::from_nanos((period * 1e9) as i64);
409+
let mut period_logs = PERIODIC_LOGS.lock().expect(FAILED_TO_LOCK);
410+
match period_logs.get_mut(&key) {
411+
Some(next_log_time) => {
412+
if now >= *next_log_time {
413+
*next_log_time = get_next_log_time(*next_log_time, period);
414+
self.log(level, msg, file, line);
415+
}
416+
}
417+
None => {
418+
period_logs.insert(key, get_next_log_time(now, period));
419+
self.log(level, msg, file, line);
420+
}
421+
}
422+
}
423+
424+
pub fn log_throttle_identical(
425+
&self,
426+
period: f64,
427+
level: i8,
428+
msg: String,
429+
file: &str,
430+
line: u32,
431+
) {
432+
lazy_static! {
433+
static ref IDENTICAL_LOGS: Mutex<HashMap<String, (Time, String)>> =
434+
Mutex::new(HashMap::new());
435+
}
436+
let now = self.now();
437+
let key = format!("{}:{}", file, line);
438+
let get_next_log_time = |now, period| now + Duration::from_nanos((period * 1e9) as i64);
439+
let mut identical_logs = IDENTICAL_LOGS.lock().expect(FAILED_TO_LOCK);
440+
match identical_logs.get_mut(&key) {
441+
Some((next_log_time, previous_msg)) => {
442+
if &msg != previous_msg {
443+
*previous_msg = msg.clone();
444+
*next_log_time = get_next_log_time(now, period);
445+
self.log(level, msg, file, line);
446+
} else if now >= *next_log_time {
447+
*next_log_time = get_next_log_time(*next_log_time, period);
448+
self.log(level, msg, file, line);
449+
}
450+
}
451+
None => {
452+
identical_logs.insert(key, (get_next_log_time(now, period), msg.clone()));
453+
self.log(level, msg, file, line);
454+
}
455+
}
456+
}
386457
}
387458

388459
pub struct Parameter {

‎rosrust/src/log_macros.rs‎

Lines changed: 128 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -40,3 +40,131 @@ macro_rules! ros_fatal {
4040
$crate::ros_log!($crate::msg::rosgraph_msgs::Log::FATAL, $($arg)*);
4141
}
4242
}
43+
44+
#[macro_export]
45+
macro_rules! ros_log_once {
46+
($level:expr, $($arg:tt)+) => {
47+
let msg = format!($($arg)*);
48+
$crate::log_once($level, msg, file!(), line!());
49+
}
50+
}
51+
52+
#[macro_export]
53+
macro_rules! ros_debug_once {
54+
($($arg:tt)*) => {
55+
$crate::ros_log_once!($crate::msg::rosgraph_msgs::Log::DEBUG, $($arg)*);
56+
}
57+
}
58+
59+
#[macro_export]
60+
macro_rules! ros_info_once {
61+
($($arg:tt)*) => {
62+
$crate::ros_log_once!($crate::msg::rosgraph_msgs::Log::INFO, $($arg)*);
63+
}
64+
}
65+
66+
#[macro_export]
67+
macro_rules! ros_warn_once {
68+
($($arg:tt)*) => {
69+
$crate::ros_log_once!($crate::msg::rosgraph_msgs::Log::WARN, $($arg)*);
70+
}
71+
}
72+
73+
#[macro_export]
74+
macro_rules! ros_err_once {
75+
($($arg:tt)*) => {
76+
$crate::ros_log_once!($crate::msg::rosgraph_msgs::Log::ERROR, $($arg)*);
77+
}
78+
}
79+
80+
#[macro_export]
81+
macro_rules! ros_fatal_once {
82+
($($arg:tt)*) => {
83+
$crate::ros_log_once!($crate::msg::rosgraph_msgs::Log::FATAL, $($arg)*);
84+
}
85+
}
86+
87+
#[macro_export]
88+
macro_rules! ros_log_throttle {
89+
($period:expr, $level:expr, $($arg:tt)+) => {
90+
let msg = format!($($arg)*);
91+
$crate::log_throttle($period, $level, msg, file!(), line!());
92+
}
93+
}
94+
95+
#[macro_export]
96+
macro_rules! ros_debug_throttle {
97+
($period:expr, $($arg:tt)*) => {
98+
$crate::ros_log_throttle!($period, $crate::msg::rosgraph_msgs::Log::DEBUG, $($arg)*);
99+
}
100+
}
101+
102+
#[macro_export]
103+
macro_rules! ros_info_throttle {
104+
($period:expr, $($arg:tt)*) => {
105+
$crate::ros_log_throttle!($period, $crate::msg::rosgraph_msgs::Log::INFO, $($arg)*);
106+
}
107+
}
108+
109+
#[macro_export]
110+
macro_rules! ros_warn_throttle {
111+
($period:expr, $($arg:tt)*) => {
112+
$crate::ros_log_throttle!($period, $crate::msg::rosgraph_msgs::Log::WARN, $($arg)*);
113+
}
114+
}
115+
116+
#[macro_export]
117+
macro_rules! ros_err_throttle {
118+
($period:expr, $($arg:tt)*) => {
119+
$crate::ros_log_throttle!($period, $crate::msg::rosgraph_msgs::Log::ERROR, $($arg)*);
120+
}
121+
}
122+
123+
#[macro_export]
124+
macro_rules! ros_fatal_throttle {
125+
($period:expr, $($arg:tt)*) => {
126+
$crate::ros_log_throttle!($period, $crate::msg::rosgraph_msgs::Log::FATAL, $($arg)*);
127+
}
128+
}
129+
#[macro_export]
130+
macro_rules! ros_log_throttle_identical {
131+
($period:expr, $level:expr, $($arg:tt)+) => {
132+
let msg = format!($($arg)*);
133+
$crate::log_throttle_identical($period, $level, msg, file!(), line!());
134+
}
135+
}
136+
137+
#[macro_export]
138+
macro_rules! ros_debug_throttle_identical {
139+
($period:expr, $($arg:tt)*) => {
140+
$crate::ros_log_throttle_identical!($period, $crate::msg::rosgraph_msgs::Log::DEBUG, $($arg)*);
141+
}
142+
}
143+
144+
#[macro_export]
145+
macro_rules! ros_info_throttle_identical {
146+
($period:expr, $($arg:tt)*) => {
147+
$crate::ros_log_throttle_identical!($period, $crate::msg::rosgraph_msgs::Log::INFO, $($arg)*);
148+
}
149+
}
150+
151+
#[macro_export]
152+
macro_rules! ros_warn_throttle_identical {
153+
($period:expr, $($arg:tt)*) => {
154+
$crate::ros_log_throttle_identical!($period, $crate::msg::rosgraph_msgs::Log::WARN, $($arg)*);
155+
}
156+
}
157+
158+
#[macro_export]
159+
macro_rules! ros_err_throttle_identical {
160+
($period:expr, $($arg:tt)*) => {
161+
$crate::ros_log_throttle_identical!($period, $crate::msg::rosgraph_msgs::Log::ERROR, $($arg)*);
162+
}
163+
}
164+
165+
#[macro_export]
166+
macro_rules! ros_fatal_throttle_identical {
167+
($period:expr, $($arg:tt)*) => {
168+
$crate::ros_log_throttle_identical!($period, $crate::msg::rosgraph_msgs::Log::FATAL, $($arg)*);
169+
}
170+
}

‎rosrust/src/singleton.rs‎

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -223,4 +223,19 @@ pub fn log(level: i8, msg: String, file: &str, line: u32) {
223223
ros!().log(level, msg, file, line)
224224
}
225225

226+
#[inline]
227+
pub fn log_once(level: i8, msg: String, file: &str, line: u32) {
228+
ros!().log_once(level, msg, file, line)
229+
}
230+
231+
#[inline]
232+
pub fn log_throttle(period: f64, level: i8, msg: String, file: &str, line: u32) {
233+
ros!().log_throttle(period, level, msg, file, line)
234+
}
235+
236+
#[inline]
237+
pub fn log_throttle_identical(period: f64, level: i8, msg: String, file: &str, line: u32) {
238+
ros!().log_throttle_identical(period, level, msg, file, line)
239+
}
240+
226241
static UNINITIALIZED: &str = "ROS uninitialized. Please run ros::init(name) first!";

‎rosrust/tests/can_log_once.rs‎

Lines changed: 47 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,47 @@
1+
use crossbeam::channel::unbounded;
2+
use ros_message::Duration;
3+
4+
mod util;
5+
6+
mod msg {
7+
rosrust::rosmsg_include!(rosgraph_msgs / Log);
8+
}
9+
10+
#[test]
11+
fn can_log_once() {
12+
let _roscore = util::run_roscore_for(util::Language::None, util::Feature::Log);
13+
14+
rosrust::init("rosout_agg_listener");
15+
16+
let (tx, rx) = unbounded();
17+
18+
let _subscriber =
19+
rosrust::subscribe::<msg::rosgraph_msgs::Log, _>("/rosout_agg", 100, move |data| {
20+
tx.send((data.level, data.msg)).unwrap();
21+
})
22+
.unwrap();
23+
24+
rosrust::sleep(Duration::from_seconds(1));
25+
26+
let mut received_messages_counter = 0;
27+
28+
let rate = rosrust::rate(1.0);
29+
for _ in 0..10 {
30+
for item in rx.try_iter() {
31+
println!("Received message at level {}: {}", item.0, item.1);
32+
received_messages_counter += 1;
33+
}
34+
35+
rosrust::ros_info_once!("info message");
36+
rate.sleep();
37+
}
38+
39+
if received_messages_counter == 0 {
40+
panic!("Failed to receive data on /rosout_agg");
41+
} else if received_messages_counter > 1 {
42+
panic!(
43+
"Received {} messages, not printed once",
44+
received_messages_counter
45+
);
46+
}
47+
}

‎rosrust/tests/can_throttle_identical_logs.rs‎

Lines changed: 48 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,48 @@
1+
use crossbeam::channel::unbounded;
2+
use ros_message::Duration;
3+
4+
mod util;
5+
6+
mod msg {
7+
rosrust::rosmsg_include!(rosgraph_msgs / Log);
8+
}
9+
10+
#[test]
11+
fn can_throttle_identical_logs() {
12+
let _roscore = util::run_roscore_for(util::Language::None, util::Feature::Log);
13+
14+
rosrust::init("rosout_agg_listener");
15+
16+
let (tx, rx) = unbounded();
17+
18+
let _subscriber =
19+
rosrust::subscribe::<msg::rosgraph_msgs::Log, _>("/rosout_agg", 100, move |data| {
20+
tx.send((data.level, data.msg)).unwrap();
21+
})
22+
.unwrap();
23+
24+
rosrust::sleep(Duration::from_seconds(1));
25+
26+
let mut received_messages_counter = 0;
27+
28+
let rate = rosrust::rate(2.0);
29+
for i in 0..20 {
30+
for item in rx.try_iter() {
31+
println!("Received message at level {}: {}", item.0, item.1);
32+
received_messages_counter += 1;
33+
}
34+
35+
let prefix = if i == 4 { "second" } else { "first" };
36+
rosrust::ros_info_throttle_identical!(3.0, "{} message", prefix);
37+
rate.sleep();
38+
}
39+
40+
if received_messages_counter == 0 {
41+
panic!("Failed to receive data on /rosout_agg");
42+
} else if received_messages_counter != 5 {
43+
panic!(
44+
"Received {} messages, but should be 5",
45+
received_messages_counter
46+
);
47+
}
48+
}

‎rosrust/tests/can_throttle_logs.rs‎

Lines changed: 44 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,44 @@
1+
use crossbeam::channel::unbounded;
2+
3+
mod util;
4+
5+
mod msg {
6+
rosrust::rosmsg_include!(rosgraph_msgs / Log);
7+
}
8+
9+
#[test]
10+
fn can_throttle_logs() {
11+
let _roscore = util::run_roscore_for(util::Language::None, util::Feature::Log);
12+
13+
rosrust::init("rosout_agg_listener");
14+
15+
let (tx, rx) = unbounded();
16+
17+
let _subscriber =
18+
rosrust::subscribe::<msg::rosgraph_msgs::Log, _>("/rosout_agg", 100, move |data| {
19+
tx.send((data.level, data.msg)).unwrap();
20+
})
21+
.unwrap();
22+
23+
let mut received_messages_counter = 0;
24+
25+
let rate = rosrust::rate(1.0);
26+
for _ in 0..10 {
27+
for item in rx.try_iter() {
28+
println!("Received message at level {}: {}", item.0, item.1);
29+
received_messages_counter += 1;
30+
}
31+
32+
rosrust::ros_info_throttle!(5.0, "info message");
33+
rate.sleep();
34+
}
35+
36+
if received_messages_counter == 0 {
37+
panic!("Failed to receive data on /rosout_agg");
38+
} else if received_messages_counter > 2 {
39+
panic!(
40+
"Received {} messages, not throttled",
41+
received_messages_counter
42+
);
43+
}
44+
}

0 commit comments

Comments
 (0)