macos_unifiedlogs/
timesync.rs

1// Copyright 2022 Mandiant, Inc. All Rights Reserved
2// Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at
3// http://www.apache.org/licenses/LICENSE-2.0
4// Unless required by applicable law or agreed to in writing, software distributed under the License
5// is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
6// See the License for the specific language governing permissions and limitations under the License.
7
8use log::error;
9use nom::Needed;
10use nom::bytes::complete::take;
11use nom::number::complete::{be_u128, le_i64, le_u16, le_u32, le_u64};
12use serde::{Deserialize, Serialize};
13use std::collections::HashMap;
14use std::mem::size_of;
15
16#[derive(Debug, Serialize, Deserialize, Default)]
17pub struct TimesyncBoot {
18    pub signature: u16,
19    pub header_size: u16,
20    pub unknown: u32,
21    pub boot_uuid: String,
22    pub timebase_numerator: u32,
23    pub timebase_denominator: u32,
24    pub boot_time: i64, // Number of nanoseconds since UNIXEPOCH
25    pub timezone_offset_mins: u32,
26    pub daylight_savings: u32, // 0 is no DST, 1 is DST
27    pub timesync: Vec<Timesync>,
28}
29
30#[derive(Debug, Serialize, Deserialize, Default)]
31pub struct Timesync {
32    // Timestamps are in UTC
33    pub signature: u32,
34    pub unknown_flags: u32,
35    pub kernel_time: u64, // Mach continuous timestamp
36    pub walltime: i64,    // Number of nanoseconds since UNIXEPOCH
37    pub timezone: u32,
38    pub daylight_savings: u32, // 0 is no DST, 1 is DST
39}
40
41impl TimesyncBoot {
42    /// Parse the Unified Log timesync files
43    pub fn parse_timesync_data(data: &[u8]) -> nom::IResult<&[u8], HashMap<String, TimesyncBoot>> {
44        let mut timesync_data: HashMap<String, TimesyncBoot> = HashMap::new();
45        let mut input = data;
46
47        let mut timesync_boot = TimesyncBoot::default();
48
49        while !input.is_empty() {
50            let (_, signature) = take(size_of::<u32>())(input)?;
51            let (_, timesync_signature) = le_u32(signature)?;
52
53            let timesync_sig: u32 = 0x207354;
54            if timesync_signature == timesync_sig {
55                let (timesync_input, timesync) = TimesyncBoot::parse_timesync(input)?;
56                timesync_boot.timesync.push(timesync);
57                input = timesync_input;
58            } else {
59                if timesync_boot.signature != 0 {
60                    if let Some(existing_boot) = timesync_data.get_mut(&timesync_boot.boot_uuid) {
61                        existing_boot.timesync.append(&mut timesync_boot.timesync);
62                    } else {
63                        timesync_data.insert(timesync_boot.boot_uuid.clone(), timesync_boot);
64                    }
65                }
66                let (timesync_input, timesync_boot_data) =
67                    TimesyncBoot::parse_timesync_boot(input)?;
68                timesync_boot = timesync_boot_data;
69                input = timesync_input;
70            }
71        }
72        if let Some(existing_boot) = timesync_data.get_mut(&timesync_boot.boot_uuid) {
73            existing_boot.timesync.append(&mut timesync_boot.timesync);
74        } else {
75            timesync_data.insert(timesync_boot.boot_uuid.clone(), timesync_boot);
76        }
77        Ok((input, timesync_data))
78    }
79
80    fn parse_timesync_boot(data: &[u8]) -> nom::IResult<&[u8], TimesyncBoot> {
81        let (input, signature) = take(size_of::<u16>())(data)?;
82        let (_, timesync_signature) = le_u16(signature)?;
83
84        let expected_boot_signature = 0xbbb0;
85        if expected_boot_signature != timesync_signature {
86            error!(
87                "[macos-unifiedlogs] Incorrect Timesync boot header signature. Expected {expected_boot_signature}. Got: {timesync_signature}",
88            );
89            return Err(nom::Err::Incomplete(Needed::Unknown));
90        }
91
92        let (input, header_size) = take(size_of::<u16>())(input)?;
93        let (input, unknown) = take(size_of::<u32>())(input)?;
94        let (input, boot_uuid) = take(size_of::<u128>())(input)?;
95        let (input, timebase_numerator) = take(size_of::<u32>())(input)?;
96        let (input, timebase_denominator) = take(size_of::<u32>())(input)?;
97        let (input, boot_time) = take(size_of::<i64>())(input)?;
98        let (input, timezone_offset_mins) = take(size_of::<u32>())(input)?;
99        let (input, daylight_savings) = take(size_of::<u32>())(input)?;
100
101        let (_, timesync_header_size) = le_u16(header_size)?;
102        let (_, timesync_unknown) = le_u32(unknown)?;
103        let (_, timesync_boot_uuid) = be_u128(boot_uuid)?;
104        let (_, timesync_timebase_numerator) = le_u32(timebase_numerator)?;
105        let (_, timesync_timebase_denominator) = le_u32(timebase_denominator)?;
106        let (_, timesync_boot_time) = le_i64(boot_time)?;
107        let (_, timesync_timezone_offset_mins) = le_u32(timezone_offset_mins)?;
108        let (_, timesync_daylight_savings) = le_u32(daylight_savings)?;
109
110        let timesync_boot = TimesyncBoot {
111            signature: timesync_signature,
112            header_size: timesync_header_size,
113            unknown: timesync_unknown,
114            boot_uuid: format!("{timesync_boot_uuid:X}"),
115            timebase_numerator: timesync_timebase_numerator,
116            timebase_denominator: timesync_timebase_denominator,
117            boot_time: timesync_boot_time,
118            timezone_offset_mins: timesync_timezone_offset_mins,
119            daylight_savings: timesync_daylight_savings,
120            timesync: Vec::new(),
121        };
122        Ok((input, timesync_boot))
123    }
124
125    fn parse_timesync(data: &[u8]) -> nom::IResult<&[u8], Timesync> {
126        let mut timesync = Timesync {
127            signature: 0,
128            unknown_flags: 0,
129            kernel_time: 0,
130            walltime: 0,
131            timezone: 0,
132            daylight_savings: 0,
133        };
134        let (input, signature) = take(size_of::<u32>())(data)?;
135        let (_, timesync_signature) = le_u32(signature)?;
136
137        let expected_record_signature = 0x207354;
138        if expected_record_signature != timesync_signature {
139            error!(
140                "[macos-unifiedlogs] Incorrect Timesync record header signature. Expected {expected_record_signature}. Got: {timesync_signature}",
141            );
142            return Err(nom::Err::Incomplete(Needed::Unknown));
143        }
144
145        let (input, unknown_flags) = take(size_of::<u32>())(input)?;
146        let (input, kernel_time) = take(size_of::<u64>())(input)?;
147        let (input, walltime) = take(size_of::<i64>())(input)?;
148        let (input, timezone) = take(size_of::<u32>())(input)?;
149        let (input, daylight_savings) = take(size_of::<u32>())(input)?;
150
151        let (_, timesync_unknown_flags) = le_u32(unknown_flags)?;
152        let (_, timesync_kernel_time) = le_u64(kernel_time)?;
153        let (_, timesync_walltime) = le_i64(walltime)?;
154        let (_, timesync_timezone) = le_u32(timezone)?;
155        let (_, timesync_daylight_savings) = le_u32(daylight_savings)?;
156
157        timesync.signature = timesync_signature;
158        timesync.unknown_flags = timesync_unknown_flags;
159        timesync.kernel_time = timesync_kernel_time;
160        timesync.walltime = timesync_walltime;
161        timesync.timezone = timesync_timezone;
162        timesync.daylight_savings = timesync_daylight_savings;
163
164        Ok((input, timesync))
165    }
166
167    /// Calculate timestamp for firehose log entry
168    pub fn get_timestamp(
169        timesync_data: &HashMap<String, TimesyncBoot>,
170        boot_uuid: &str,
171        firehose_log_delta_time: u64,
172        firehose_preamble_time: u64,
173    ) -> f64 {
174        /*  Timestamp calculation logic:
175            Firehose Log entry timestamp is calculated by using firehose_preamble_time, firehose.continous_time_delta, and timesync timestamps
176            Firehose log header/preample contains a base timestamp
177              Ex: Firehose header base time is 2022-01-01 00:00:00
178            All log entries following the header are continous from that base. EXCEPT when the base time is zero. If the base time is zero the TimeSync boot record boot time is used (boot time)
179              Ex: Firehose log entry time is +60 seconds
180            Timestamp would be 2022-01-01 00:01:00
181
182            (firehose_log_entry_continous_time = firehose.continous_time_delta | ((firehose.continous_time_delta_upper) << 32))
183            firehose_log_delta_time = firehose_preamble_time + firehose_log_entry_continous_time
184
185            Get all timesync boot records if timesync uuid equals boot uuid in tracev3 header data
186
187            Loop through all timesync records from matching boot uuid until timesync cont_time/kernel time is greater than firehose_preamble_time
188            If firehose_header_time equals zero. Then the Timesync header walltime is used (the Timesync header cont_time/kernel time is then always zero)
189            Subtract timesync_cont_time/kernel time from firehose_log_delta_time
190            IF APPLE SILICON (ARM) is the architecture, then we need to mupltiple timesync_cont_time and firehose_log_delta_time by the timebase 125.0/3.0 to get the nanocsecond representation
191
192           Add results to timesync_walltime (unix epoch in nanoseconds)
193           Final results is unix epoch timestamp in nano seconds
194        */
195
196        let mut timesync_continous_time = 0;
197        let mut timesync_walltime = 0;
198
199        // Apple Intel uses 1/1 as the timebase
200        let mut timebase_adjustment = 1.0;
201        if let Some(timesync) = timesync_data.get(boot_uuid) {
202            if timesync.timebase_numerator == 125 && timesync.timebase_denominator == 3 {
203                // For Apple Silicon (ARM) we need to adjust the mach time by multiplying by 125.0/3.0 to get the accurate nanosecond count
204                timebase_adjustment = 125.0 / 3.0;
205            }
206
207            // A preamble time of 0 means we need to use the timesync header boot time as our minimum value.
208            // We also set the timesync_continous_time to  zero
209            if firehose_preamble_time == 0 {
210                timesync_continous_time = 0;
211                timesync_walltime = timesync.boot_time;
212            }
213            for timesync_record in &timesync.timesync {
214                if timesync_record.kernel_time > firehose_log_delta_time {
215                    if timesync_continous_time == 0 && timesync_walltime == 0 {
216                        timesync_continous_time = timesync_record.kernel_time;
217                        timesync_walltime = timesync_record.walltime;
218                    }
219                    break;
220                }
221
222                timesync_continous_time = timesync_record.kernel_time;
223                timesync_walltime = timesync_record.walltime;
224            }
225        }
226
227        let continous_time = (firehose_log_delta_time as f64).mul_add(
228            timebase_adjustment,
229            -(timesync_continous_time as f64) * timebase_adjustment,
230        );
231        continous_time + timesync_walltime as f64
232    }
233}
234
235#[cfg(test)]
236mod tests {
237    use crate::filesystem::LogarchiveProvider;
238    use crate::parser::collect_timesync;
239    use crate::timesync::TimesyncBoot;
240    use std::path::PathBuf;
241
242    #[test]
243    fn test_parse_timesync_data() {
244        let mut test_path = PathBuf::from(env!("CARGO_MANIFEST_DIR"));
245        test_path.push(
246            "tests/test_data/system_logs_big_sur.logarchive/timesync/0000000000000002.timesync",
247        );
248
249        let buffer = std::fs::read(test_path).unwrap();
250
251        let (_, timesync_data) = TimesyncBoot::parse_timesync_data(&buffer).unwrap();
252        assert_eq!(timesync_data.len(), 5);
253        assert_eq!(
254            timesync_data
255                .get("9A6A3124274A44B29ABF2BC9E4599B3B")
256                .unwrap()
257                .timesync
258                .len(),
259            5
260        );
261    }
262
263    #[test]
264    #[should_panic(expected = "Incomplete(Unknown)")]
265    fn test_timesync_bad_boot_header() {
266        let mut test_path = PathBuf::from(env!("CARGO_MANIFEST_DIR"));
267        test_path
268            .push("tests/test_data/Bad Data/Timesync/Bad_Boot_header_0000000000000002.timesync");
269
270        let buffer = std::fs::read(test_path).unwrap();
271
272        let (_, _) = TimesyncBoot::parse_timesync_data(&buffer).unwrap();
273    }
274
275    #[test]
276    #[should_panic(expected = "Incomplete(Unknown)")]
277    fn test_timesync_bad_record_header() {
278        let mut test_path = PathBuf::from(env!("CARGO_MANIFEST_DIR"));
279        test_path
280            .push("tests/test_data/Bad Data/Timesync/Bad_Record_header_0000000000000002.timesync");
281
282        let buffer = std::fs::read(test_path).unwrap();
283
284        let (_, _) = TimesyncBoot::parse_timesync_data(&buffer).unwrap();
285    }
286
287    #[test]
288    #[should_panic(expected = "Incomplete(Unknown)")]
289    fn test_timesync_bad_content() {
290        let mut test_path = PathBuf::from(env!("CARGO_MANIFEST_DIR"));
291        test_path.push("tests/test_data/Bad Data/Timesync/Bad_content_0000000000000002.timesync");
292
293        let buffer = std::fs::read(test_path).unwrap();
294
295        let (_, _) = TimesyncBoot::parse_timesync_data(&buffer).unwrap();
296    }
297
298    #[test]
299    #[should_panic(expected = "Incomplete(Unknown)")]
300    fn test_timesync_bad_file() {
301        let mut test_path = PathBuf::from(env!("CARGO_MANIFEST_DIR"));
302        test_path.push("tests/test_data/Bad Data/Timesync/BadFile.timesync");
303
304        let buffer = std::fs::read(test_path).unwrap();
305
306        let (_, _) = TimesyncBoot::parse_timesync_data(&buffer).unwrap();
307    }
308
309    #[test]
310    fn test_timesync() {
311        let test_data = [
312            84, 115, 32, 0, 0, 0, 0, 0, 165, 196, 104, 252, 1, 0, 0, 0, 216, 189, 100, 108, 116,
313            158, 131, 22, 0, 0, 0, 0, 0, 0, 0, 0,
314        ];
315        let (_, timesync) = TimesyncBoot::parse_timesync(&test_data).unwrap();
316        assert_eq!(timesync.signature, 0x207354);
317        assert_eq!(timesync.unknown_flags, 0);
318        assert_eq!(timesync.kernel_time, 8529691813);
319        assert_eq!(timesync.walltime, 1622314513655447000);
320        assert_eq!(timesync.timezone, 0);
321        assert_eq!(timesync.daylight_savings, 0);
322    }
323
324    #[test]
325    fn test_timesync_boot() {
326        let test_data = [
327            176, 187, 48, 0, 0, 0, 0, 0, 132, 91, 13, 213, 1, 96, 69, 62, 172, 224, 56, 118, 12,
328            123, 92, 29, 1, 0, 0, 0, 1, 0, 0, 0, 168, 167, 19, 176, 114, 158, 131, 22, 0, 0, 0, 0,
329            0, 0, 0, 0,
330        ];
331        let (_, timesync_boot) = TimesyncBoot::parse_timesync_boot(&test_data).unwrap();
332        assert_eq!(timesync_boot.signature, 0xbbb0);
333        assert_eq!(timesync_boot.header_size, 48);
334        assert_eq!(timesync_boot.unknown, 0);
335        assert_eq!(timesync_boot.boot_uuid, "845B0DD50160453EACE038760C7B5C1D");
336        assert_eq!(timesync_boot.timebase_numerator, 1);
337        assert_eq!(timesync_boot.timebase_denominator, 1);
338        assert_eq!(timesync_boot.boot_time, 1622314506201049000);
339        assert_eq!(timesync_boot.timezone_offset_mins, 0);
340        assert_eq!(timesync_boot.daylight_savings, 0);
341    }
342
343    #[test]
344    fn test_get_timestamp() {
345        let mut test_path = PathBuf::from(env!("CARGO_MANIFEST_DIR"));
346        test_path.push("tests/test_data/system_logs_big_sur.logarchive");
347        let provider = LogarchiveProvider::new(test_path.as_path());
348
349        let timesync_data = collect_timesync(&provider).unwrap();
350
351        let boot_uuid = "A2A9017676CF421C84DC9BBD6263FEE7";
352        let firehose_preamble_continous_time = 2818326118;
353
354        let results = TimesyncBoot::get_timestamp(
355            &timesync_data,
356            boot_uuid,
357            firehose_preamble_continous_time,
358            1,
359        );
360        assert_eq!(results, 1_642_304_803_060_379_000.0);
361    }
362
363    #[test]
364    fn test_get_arm_timestamp() {
365        let mut test_path = PathBuf::from(env!("CARGO_MANIFEST_DIR"));
366        test_path.push("tests/test_data/system_logs_monterey.logarchive");
367        let provider = LogarchiveProvider::new(test_path.as_path());
368
369        let timesync_data = collect_timesync(&provider).unwrap();
370
371        let boot_uuid = "3E12B435814B4C62918CEBC0826F06B8";
372        let firehose_preamble_continous_time = 2818326118;
373
374        let results = TimesyncBoot::get_timestamp(
375            &timesync_data,
376            boot_uuid,
377            firehose_preamble_continous_time,
378            1,
379        );
380        assert_eq!(results, 1650767519086487000.0);
381    }
382
383    #[test]
384    fn test_get_arm_timestamp_use_boot_time() {
385        let mut test_path = PathBuf::from(env!("CARGO_MANIFEST_DIR"));
386        test_path.push("tests/test_data/system_logs_monterey.logarchive/timesync");
387
388        let provider = LogarchiveProvider::new(test_path.as_path());
389
390        let timesync_data = collect_timesync(&provider).unwrap();
391
392        let boot_uuid = "3E12B435814B4C62918CEBC0826F06B8";
393        let firehose_preamble_continous_time = 9898326118;
394
395        let results = TimesyncBoot::get_timestamp(
396            &timesync_data,
397            boot_uuid,
398            firehose_preamble_continous_time,
399            0,
400        );
401        assert_eq!(results, 1_650_767_813_342_574_600.0);
402    }
403}