A lot of potential Index Out Of Bounds

[jrouaix]

Hello,

We had an ios 18.0 beta 4 sysdiag that made this lib panic! (@ReturnRei will perhaps provide more details)

I quick fixed it in this commit : https://github.com/shindan-io/macos-UnifiedLogs/commit/fc30ecfb8b19ef7bf07e1242ca634ba70f24df2e

But I find my fix just ugly, i'm far from confident in the existing code.

The code heavy rely on array[index] indexers, which can panic!. On other way could be to forget about indexers and use the array.get(index) that returns an Option and let us all the semantics to handle the missing case properly.

Same goes with subslicing, slice[x..] could be replaced by get(x..) too.

let array = &vec![1, 2, 3, 4, 5];
let _will_panic = array[42]; // will panic
let _ok = array.get(42); // returns Option::None
let _will_panic = &array[42..]; // will panic
let _ok = array.get(42..); // returns Option::None

Are you aware if this ? Do you think it's a flaw and that needs some fixing effort ? Can we help ?

(I can submit a PR with my quick fix, but as said, I think it's a far more general problem and perhaps we should fix it for good)

[puffyCid]

thanks for reporting the issue! it sounds like something changed in log format in iOS 18/macOS Sequoia. I have not had time to setup a beta instance of macOS Sequioa yet.

Can you share the logarchive? Can you post the panic error?

There is a check early on to make sure index is not larger than the array https://github.com/mandiant/macos-UnifiedLogs/blob/main/src/message.rs#L83

If you cannot share the entire logarchive, if you share a single .tracev3 file that triggers the panic that migit be sufficient. The example, folder contains basic parser that might helpful figuring out what .tracev3 file is trigger the panic

./unifiedlog_parser -i <logarchive> -o out.csv
Starting Unified Log parser...
Parsing: /private/var/db/diagnostics/Persist/0000000000000ed9.tracev3

Otherwise, i will need to setup a beta version of macOS to test. I would like to figure out whats causing the panic first, then switching over to .get() may make sense to make sure this does not happen in the future

[puffyCid]

I was able to setup a macOS Sequoia beta instance and reproduce the crash.

The log format has been updated a little in the new release. I was able to confirm the format changed a bit by copying the Sequoia logarchive to a macOS system running Sonoma. Both log and Console tools showed different log results on each OS. Sonoma could not display the same data as Sequoia. Likely because of the format change.

I have already updated the parser locally to support the changes. No more crashes 😸 . I also see what caused the index out of bounds and that has also been fixed.

I will merge ur PR first and i would like to continue to test the changes and also add tests. Will aim to have merged probably Sunday.

If you could share the logarchive that would useful to help validate the changes

[jrouaix]

Found another : https://github.com/shindan-io/macos-UnifiedLogs/commit/d276842fd24985b3fe7fcbad34d19f8e877fbb44

We cannot share the logarchive. But we are gathering the exact message dump that is crashing it all.

[ReturnRei]

We added some debug statements to see what was causing the crashes. We can scan the logarchive ourselves and provide feedback if needed.

[shared/macos-UnifiedLogs/src/message.rs:289:9] &full_message = "[%.*hhx-%{public}s] [{%.*hx}-%{sensitive,mask.mailbox}s] %ld messages have flag changes after copy"
[shared/macos-UnifiedLogs/src/message.rs:290:9] &formatter = "%ld"
[shared/macos-UnifiedLogs/src/message.rs:291:9] index = 7
[shared/macos-UnifiedLogs/src/message.rs:292:9] &message_value = [
    FirehoseItemInfo {
        message_strings: "",
        item_type: 18,
        item_size: 0,
    },
    FirehoseItemInfo {
        message_strings: "9",
        item_type: 0,
        item_size: 0,
    },
    FirehoseItemInfo {
        message_strings: "\0\0\0\u{8}\0\0\0\0\0\0\0\0Upload",
        item_type: 34,
        item_size: 18,
    },
    FirehoseItemInfo {
        message_strings: "",
        item_type: 18,
        item_size: 0,
    },
    FirehoseItemInfo {
        message_strings: "0",
        item_type: 0,
        item_size: 0,
    },
    FirehoseItemInfo {
        message_strings: "",
        item_type: 241,
        item_size: 0,
    },
    FirehoseItemInfo {
        message_strings: "",
        item_type: 18,
        item_size: 0,
    },
]

[shared/macos-UnifiedLogs/src/decoders/decoder.rs:50:9] &full_message = "# RECEIVED advertisement, %{public}@ type=%{private}@ -> %{private}@, %{public}@, from %{private}@/%{private}@ options=%{public}@"
[shared/macos-UnifiedLogs/src/decoders/decoder.rs:51:9] &item_type = 18
[shared/macos-UnifiedLogs/src/decoders/decoder.rs:52:9] &format_string = "%{public"
[shared/macos-UnifiedLogs/src/decoders/decoder.rs:53:9] index = 7
[shared/macos-UnifiedLogs/src/decoders/decoder.rs:54:9] message_values = [
    FirehoseItemInfo {
        message_strings: "B\u{4}\u{13}\0%\0A\u{4}\0\0\0\0A\u{4}\0\0\0\0B",
        item_type: 66,
        item_size: 19,
    },
    FirehoseItemInfo {
        message_strings: "",
        item_type: 129,
        item_size: 0,
    },
    FirehoseItemInfo {
        message_strings: "-9999",
        item_type: 0,
        item_size: 0,
    },
    FirehoseItemInfo {
        message_strings: "",
        item_type: 35,
        item_size: 0,
    },
    FirehoseItemInfo {
        message_strings: "",
        item_type: 129,
        item_size: 0,
    },
    FirehoseItemInfo {
        message_strings: "",
        item_type: 35,
        item_size: 0,
    },
    FirehoseItemInfo {
        message_strings: "",
        item_type: 18,
        item_size: 0,
    },
]

[puffyCid]

Thank you for the debug output. The errors are similar to what I got as well. New item_type values were added to the log format. I have opened a PR to fix the issue.

If you have a chance to test it that would be great thanks!

[ReturnRei]

Just tested on the item_type-update branch with the binary ./unifiedlog_parser_json and an ios 18 beta 5 logarchive.

The entries that make the program panic on main now result in Index now greater than messages array. This should not have happened.

No more panics as of now! 👍

[puffyCid]

Just tested on the item_type-update branch with the binary ./unifiedlog_parser_json and an ios 18 beta 5 logarchive.

The entries that make the program panic on main now result in Index now greater than messages array. This should not have happened.

No more panics as of now! 👍

Im glad the panics are gone. However, the error message Index now greater than messages array. This should not have happened. should ideally not happen.

I am wondering if there are still new changes introduced in the latest versions of macOS/iOS. Do u still see the same debug messages mentioned above? https://github.com/mandiant/macos-UnifiedLogs/issues/19#issuecomment-2278082074

[ReturnRei]

Just tested on the item_type-update branch with the binary ./unifiedlog_parser_json and an ios 18 beta 5 logarchive. The entries that make the program panic on main now result in Index now greater than messages array. This should not have happened. No more panics as of now! 👍

Im glad the panics are gone. However, the error message Index now greater than messages array. This should not have happened. should ideally not happen.

I am wondering if there are still new changes introduced in the latest versions of macOS/iOS. Do u still see the same debug messages mentioned above? #19 (comment)

I collected this list of log messages that cause index out ouf bound. It's a partial list as there are most likely more, I'm wondering about how to get an exhaustive one. I included only the log_message variable for brevity.

"[%.*hhx-%{public}s] [%{sensitive,mask.mailbox}s] %ld messages have flag changes after copy"
"[%.*hhx-%{public}s] [%{sensitive,mask.mailbox}s] Marking step %s as complete."
"[%.*hhx-%{public}s] [%{sensitive,mask.mailbox}s] Received local flag changes for %ld messages."
"[%.*hhx-%{public}s] [{%.*hx}-%{sensitive,mask.mailbox}s] %ld messages have flag changes after copy"
"[%.*hhx-%{public}s] [{%.*hx}-%{sensitive,mask.mailbox}s] Did upload flags for %ld messages"
"[%.*hhx-%{public}s] [{%.*hx}-%{sensitive,mask.mailbox}s] Marking step %s as complete."
"[%.*hhx-%{public}s] [{%.*hx}-%{sensitive,mask.mailbox}s] Received local flag changes for %ld messages.

[puffyCid]

thanks @ReturnRei that is helpful. It looks like the entries are all related to <private> strings. {sensitive} flags were rare when this parser was created. However, now it looks like Apple may be using them more often now.

It looks like these logs are related to email possibly. I will try to setup an email on my beta system to see if I can trigger the message.

Another option that could be done, if you have access to a macOS system (if you don't no worries):

1. Identify the tracev3 file that contains one or more of the messages above
2. Run log raw-dump -H -f <path to tracev3>. This command should dump the contents of the log as hex
3. Provide the hex dump of the log message

The hexdump should contain the flags associated with the log and can be used to determine what flag/type is associated with {sensitive}

[ReturnRei]

Here's one @puffyCid In the parsed messages [0a-UploadFlagChanges] [{01}-<private>] Received local flag changes for 0 messages. The number {01} before private varies, I don't know if that's already accounted for

tp 3504 + 91:       log default (shared_cache, has_subsystem)
pubdata:
00000000: 04 00 04 02 30 0c 28 28 4a c8 0d 00 00 00 00 00 ....0.((J.......
00000010: 0e 8d 34 00 10 00 43 00 50 03 e2 27 1a 01 23 07 ..4...C.P..'..#.
00000020: 12 04 02 00 00 00 00 01 0a 22 04 00 00 12 00 12 ........."......
00000030: 04 02 00 00 00 00 02 01 00 f1 04 12 00 00 00 00 ................
00000040: 08 00 00 00 00 00 00 00 00 55 70 6c 6f 61 64 46 .........UploadF
00000050: 6c 61 67 43 68 61 6e 67 65 73 00                lagChanges.         thread:         00000000000dc84a
    time:           +2,863.455s
    walltime:       1724061458 - 2024-08-19 11:57:38 (Monday)
    location:       pc:0x27e20350 fmt:0x28280c30
    image uuid:     759C7760-AB15-3838-BAAE-25ED90E25555
    image path:     /System/Library/PrivateFrameworks/Message.framework/Message
    format:         [%.*hhx-%{public}s] [{%.*hx}-%{sensitive,mask.mailbox}s] Received local flag changes for %ld me
ssages.
    subsystem:      282 com.apple.IMAP.Task
[0a-UploadFlagChanges] [{01}-<private>] Received local flag changes for 0 messages.

[puffyCid]

Thanks @ReturnRei that was helpful. I pushed another update to the PR fix. If u could run/test again. Hopefully there will be no more Index now greater than messages array. This should not have happened messages.

[ReturnRei]

@puffyCid Just tested, all good!