1 // Copyright (c) 2024 Huawei Technologies Co.,Ltd. All rights reserved.
2 //
3 // StratoVirt is licensed under Mulan PSL v2.
4 // You can use this software according to the terms and conditions of the Mulan
5 // PSL v2.
6 // You may obtain a copy of Mulan PSL v2 at:
7 //         http://license.coscl.org.cn/MulanPSL2
8 // THIS SOFTWARE IS PROVIDED ON AN "AS IS" BASIS, WITHOUT WARRANTIES OF ANY
9 // KIND, EITHER EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO
10 // NON-INFRINGEMENT, MERCHANTABILITY OR FIT FOR A PARTICULAR PURPOSE.
11 // See the Mulan PSL v2 for more details.
12 
13 use std::{
14     fs::{remove_file, rename, File, OpenOptions},
15     io::{stderr, Write},
16     num::Wrapping,
17     os::unix::fs::OpenOptionsExt,
18     path::{Path, PathBuf},
19     sync::Mutex,
20     time::UNIX_EPOCH,
21 };
22 
23 use anyhow::{Context, Result};
24 use log::{set_boxed_logger, set_max_level, Level, LevelFilter, Log, Metadata, Record};
25 use nix::unistd::{getpid, gettid};
26 
27 use super::OzonecErr;
28 
29 // Maximum size of log file is 100MB.
30 const LOG_ROTATE_SIZE_MAX: usize = 100 * 1024 * 1024;
31 // Logs are retained for seven days at most.
32 const LOG_ROTATE_CNT_MAX: u8 = 7;
33 
34 struct LogRotate {
35     handler: Box<dyn Write + Send>,
36     path: String,
37     size: Wrapping<usize>,
38     created_day: i32,
39 }
40 
41 impl LogRotate {
rotate(&mut self, inc_size: usize) -> Result<()>42     fn rotate(&mut self, inc_size: usize) -> Result<()> {
43         if self.path.is_empty() {
44             return Ok(());
45         }
46 
47         self.size += Wrapping(inc_size);
48         let seconds = wall_time().0;
49         let today = formatted_time(seconds)[2];
50         if self.size < Wrapping(LOG_ROTATE_SIZE_MAX) && self.created_day == today {
51             return Ok(());
52         }
53 
54         // Delete oldest log file.
55         let mut rotate_cnt = LOG_ROTATE_CNT_MAX - 1;
56         let olddest = format!("{}{}", self.path, rotate_cnt);
57         if Path::new(&olddest).exists() {
58             remove_file(&olddest).with_context(|| "Failed to delete olddest log")?;
59         }
60 
61         // Rename remaining logs.
62         let mut new_log = olddest;
63         while rotate_cnt != 0 {
64             let mut old_log = self.path.clone();
65 
66             rotate_cnt -= 1;
67             if rotate_cnt != 0 {
68                 old_log += &rotate_cnt.to_string();
69             }
70 
71             if Path::new(&old_log).exists() {
72                 rename(&old_log, &new_log)
73                     .with_context(|| format!("Failed to rename {} to {}", old_log, new_log))?;
74             }
75             new_log = old_log;
76         }
77 
78         self.handler = Box::new(
79             open_log_file(&PathBuf::from(self.path.clone()))
80                 .with_context(|| format!("Failed to convert {}", self.path))?,
81         );
82         self.size = Wrapping(0);
83         self.created_day = today;
84         Ok(())
85     }
86 }
87 
open_log_file(path: &PathBuf) -> Result<File>88 fn open_log_file(path: &PathBuf) -> Result<File> {
89     OpenOptions::new()
90         .read(false)
91         .append(true)
92         .create(true)
93         .mode(0o640)
94         .open(path)
95         .with_context(|| OzonecErr::OpenFile(path.to_string_lossy().to_string()))
96 }
97 
formatted_time(seconds: i64) -> [i32; 6]98 fn formatted_time(seconds: i64) -> [i32; 6] {
99     // SAFETY: an all-zero value is valid for libc::tm.
100     let mut ti: libc::tm = unsafe { std::mem::zeroed() };
101     // SAFETY: seconds and ti are both local variables and valid.
102     unsafe {
103         libc::localtime_r(&seconds, &mut ti);
104     }
105     [
106         ti.tm_year + 1900,
107         ti.tm_mon + 1,
108         ti.tm_mday,
109         ti.tm_hour,
110         ti.tm_min,
111         ti.tm_sec,
112     ]
113 }
114 
wall_time() -> (i64, i64)115 fn wall_time() -> (i64, i64) {
116     let mut ts = libc::timespec {
117         tv_sec: 0,
118         tv_nsec: 0,
119     };
120     // SAFETY: ts is a local variable and valid.
121     unsafe {
122         libc::clock_gettime(libc::CLOCK_REALTIME, &mut ts);
123     }
124     (ts.tv_sec, ts.tv_nsec)
125 }
126 
formatted_now() -> String127 fn formatted_now() -> String {
128     let (sec, nsec) = wall_time();
129     let formatted_time = formatted_time(sec);
130 
131     format!(
132         "{:04}-{:02}-{:02}T{:02}:{:02}:{:02}:{:09}",
133         formatted_time[0],
134         formatted_time[1],
135         formatted_time[2],
136         formatted_time[3],
137         formatted_time[4],
138         formatted_time[5],
139         nsec
140     )
141 }
142 
143 struct Logger {
144     rotate: Mutex<LogRotate>,
145     level: Level,
146 }
147 
148 impl Logger {
new(path: &Option<PathBuf>, level: Level) -> Result<Self>149     fn new(path: &Option<PathBuf>, level: Level) -> Result<Self> {
150         let (log_file, log_size, created_day) = match path {
151             Some(p) => {
152                 let file = Box::new(open_log_file(p)?);
153                 let metadata = file.metadata().with_context(|| "Failed to get metadata")?;
154                 let mod_time = metadata
155                     .modified()
156                     .with_context(|| "Failed to get modify time")?;
157                 let seconds = mod_time
158                     .duration_since(UNIX_EPOCH)
159                     .with_context(|| "Failed to get duration time")?
160                     .as_secs();
161                 let log_size = Wrapping(metadata.len() as usize);
162                 let created_day = formatted_time(seconds as i64)[2];
163                 (file as Box<dyn Write + Send>, log_size, created_day)
164             }
165             None => (Box::new(stderr()) as Box<dyn Write + Send>, Wrapping(0), 0),
166         };
167 
168         let rotate = Mutex::new(LogRotate {
169             handler: log_file,
170             path: path
171                 .as_ref()
172                 .unwrap_or(&PathBuf::new())
173                 .to_string_lossy()
174                 .to_string(),
175             size: log_size,
176             created_day,
177         });
178         Ok(Self { rotate, level })
179     }
180 }
181 
182 impl Log for Logger {
enabled(&self, metadata: &Metadata) -> bool183     fn enabled(&self, metadata: &Metadata) -> bool {
184         metadata.level() <= self.level
185     }
186 
log(&self, record: &Record)187     fn log(&self, record: &Record) {
188         if !self.enabled(record.metadata()) {
189             return;
190         }
191 
192         let fmt_msg = format_args!(
193             "{:<5}: [{}][{}][{}: {}]:{}: {}\n",
194             formatted_now(),
195             getpid(),
196             gettid(),
197             record.file().unwrap_or(""),
198             record.line().unwrap_or(0),
199             record.level(),
200             record.args()
201         )
202         .to_string();
203 
204         let mut log_rotate = self.rotate.lock().unwrap();
205         if let Err(e) = log_rotate.handler.write_all(fmt_msg.as_bytes()) {
206             eprintln!("Failed to log message: {:?}", e);
207             return;
208         }
209         if let Err(e) = log_rotate.rotate(fmt_msg.as_bytes().len()) {
210             eprintln!("Failed to rotate log files: {:?}", e);
211         }
212     }
213 
flush(&self)214     fn flush(&self) {}
215 }
216 
init(path: &Option<PathBuf>, debug: bool) -> Result<()>217 pub fn init(path: &Option<PathBuf>, debug: bool) -> Result<()> {
218     let log_level = if debug {
219         Level::Debug
220     } else {
221         match std::env::var("OZONEC_LOG_LEVEL") {
222             Ok(level) => match level.to_lowercase().as_str() {
223                 "error" => Level::Error,
224                 "warn" => Level::Warn,
225                 "info" => Level::Info,
226                 "debug" => Level::Debug,
227                 "trace" => Level::Trace,
228                 _ => Level::Info,
229             },
230             _ => Level::Info,
231         }
232     };
233 
234     let logger = Box::new(Logger::new(path, log_level)?);
235     set_boxed_logger(logger)
236         .map(|_| set_max_level(LevelFilter::Trace))
237         .with_context(|| "Logger has been already set")?;
238     Ok(())
239 }
240 
241 #[cfg(test)]
242 mod tests {
243     use std::{fs, os::unix::fs::MetadataExt};
244 
245     use super::*;
246 
247     #[test]
test_logger_init()248     fn test_logger_init() {
249         assert!(init(&Some(PathBuf::from("/tmp/ozonec.log")), false).is_ok());
250         remove_file(Path::new("/tmp/ozonec.log")).unwrap();
251     }
252 
253     #[test]
test_logger_rotate()254     fn test_logger_rotate() {
255         let log_file = PathBuf::from("/tmp/ozonec.log");
256         let logger = Logger::new(&Some(log_file.clone()), Level::Debug).unwrap();
257         let mut locked_rotate = logger.rotate.lock().unwrap();
258         // Time in metadata are not changed as the file descriptor is still opened.
259         let inode = fs::metadata(&log_file).unwrap().ino();
260         for i in 1..LOG_ROTATE_CNT_MAX {
261             let file = format!("{}{}", locked_rotate.path, i);
262             let path = Path::new(&file);
263             File::create(path).unwrap();
264         }
265 
266         locked_rotate.size = Wrapping(0);
267         assert!(locked_rotate.rotate(1024).is_ok());
268         let mut new_inode = fs::metadata(&log_file).unwrap().ino();
269         assert_eq!(inode, new_inode);
270 
271         locked_rotate.size = Wrapping(LOG_ROTATE_SIZE_MAX);
272         assert!(locked_rotate.rotate(1024).is_ok());
273         new_inode = fs::metadata(&log_file).unwrap().ino();
274         assert_ne!(inode, new_inode);
275         assert_eq!(locked_rotate.size, Wrapping(0));
276 
277         locked_rotate.size = Wrapping(0);
278         locked_rotate.created_day = formatted_time(wall_time().0)[2] - 1;
279         assert!(locked_rotate.rotate(1024).is_ok());
280         new_inode = fs::metadata(&log_file).unwrap().ino();
281         assert_ne!(inode, new_inode);
282         assert_eq!(locked_rotate.size, Wrapping(0));
283 
284         for i in 1..LOG_ROTATE_CNT_MAX {
285             let file = format!("{}{}", locked_rotate.path, i);
286             let path = Path::new(&file);
287             remove_file(path).unwrap();
288         }
289         remove_file(Path::new("/tmp/ozonec.log")).unwrap();
290     }
291 }
292