Strip confidential information from logs on "error" level

[mkow]

Description of the changes

As officially added to the docs in #2454, running with log_level = "error" should be secure in production. This PR fixes the places where log_error() calls leaked potentially sensitive information.

Things I skipped from censoring:

• error codes: I assume they are not confidential, especially in log_error paths,
• non-SGX Linux PAL altogether,
• paths: they are not encrypted and visible from the host anyways,
• memory page addresses: same as with paths.

---

This change is 

[boryspoplawski]

Reviewed 1 of 12 files at r1.
Reviewable status: 1 of 12 files reviewed, 1 unresolved discussion, not enough approvals from maintainers (2 more required), not enough approvals from different teams (1 more required, approved so far: ITL) (waiting on @mkow)

a discussion (no related file):
Two substantial notes:

• imo both addresses and error codes should be stripped. E.g. addresses are way more sensitive information than, let's say, vmid (which you did strip). As far as general memory layout (basically range of available addresses) is known by malicious host, each object addresses are not (we do have some form of ASLR).
• I very much dislike the current version of splitting 1 message into 2 parts. In debug mode they will be printed in separate lines and mixed between different threads/processes. Note that currently we don't have any way not to flush after each log_*.

---

---

common/include/spinlock.h, line 187 at r1 (raw file):

    unsigned int owner = __atomic_load_n(&lock->owner, __ATOMIC_RELAXED);
    if (owner != get_cur_tid()) {
        log_error("Unexpected lock ownership: owned by: %d, checked in: %d", owner, get_cur_tid());

FYI: this is only run in DEBUG mode, but let's keep it for uniformity.

[mkow]

Reviewable status: 1 of 12 files reviewed, 1 unresolved discussion, not enough approvals from maintainers (2 more required), not enough approvals from different teams (1 more required, approved so far: ITL) (waiting on @boryspoplawski)

a discussion (no related file):

imo both addresses and error codes should be stripped. E.g. addresses are way more sensitive information than, let's say, vmid (which you did strip). As far as general memory layout (basically range of available addresses) is known by malicious host, each object addresses are not (we do have some form of ASLR).

Any idea how to strip them in practice? Having two prints at literally every error in our codebase sounds like an overkill.

I very much dislike the current version of splitting 1 message into 2 parts. In debug mode they will be printed in separate lines and mixed between different threads/processes. Note that currently we don't have any way not to flush after each log_*.

Yeah, I know and also dislike it, but I don't have any better ideas how to implement this.

---

[boryspoplawski]

Reviewable status: 1 of 12 files reviewed, 1 unresolved discussion, not enough approvals from maintainers (2 more required), not enough approvals from different teams (1 more required, approved so far: ITL) (waiting on @mkow)

a discussion (no related file):

Previously, mkow (Michał Kowalczyk) wrote…

imo both addresses and error codes should be stripped. E.g. addresses are way more sensitive information than, let's say, vmid (which you did strip). As far as general memory layout (basically range of available addresses) is known by malicious host, each object addresses are not (we do have some form of ASLR).

Any idea how to strip them in practice? Having two prints at literally every error in our codebase sounds like an overkill.

I very much dislike the current version of splitting 1 message into 2 parts. In debug mode they will be printed in separate lines and mixed between different threads/processes. Note that currently we don't have any way not to flush after each log_*.

Yeah, I know and also dislike it, but I don't have any better ideas how to implement this.

Maybe just turn all messages into debug/warning? Error log would be used just for fatal messages (just before dying) which would only point to a place in the code without printing any dynamic info.

---

[dimakuv]

Reviewable status: 1 of 12 files reviewed, 1 unresolved discussion, not enough approvals from maintainers (1 more required), not enough approvals from different teams (1 more required, approved so far: ITL) (waiting on @boryspoplawski)

a discussion (no related file):

Previously, boryspoplawski (Borys Popławski) wrote…

Maybe just turn all messages into debug/warning? Error log would be used just for fatal messages (just before dying) which would only point to a place in the code without printing any dynamic info.

Maybe we should change log_error() signature? E.g. log_error(msg, debug_details, msg_suffix, ...), and use it like this:

log_error("Unexpected lock ownership", "(owned by: %d, checked in: %d)", "\n", owner, get_cur_tid());

This format can support all our current error messages, doesn't split messages into two, and has a benefit of making log_error usage really special (making it hard for new developers to inadvertently leak secret data while adding logs).

---

[boryspoplawski]

Reviewable status: 1 of 12 files reviewed, 1 unresolved discussion, not enough approvals from maintainers (1 more required), not enough approvals from different teams (1 more required, approved so far: ITL) (waiting on @dimakuv and @mkow)

a discussion (no related file):

Previously, dimakuv (Dmitrii Kuvaiskii) wrote…

Maybe we should change log_error() signature? E.g. log_error(msg, debug_details, msg_suffix, ...), and use it like this:

log_error("Unexpected lock ownership", "(owned by: %d, checked in: %d)", "\n", owner, get_cur_tid());

This format can support all our current error messages, doesn't split messages into two, and has a benefit of making log_error usage really special (making it hard for new developers to inadvertently leak secret data while adding logs).

On one hand I like the idea, sounds neat and would solve the problem, but on the other logging is supposed to be dead simple...

---

[mkow]

Reviewable status: 1 of 12 files reviewed, 1 unresolved discussion, not enough approvals from maintainers (1 more required), not enough approvals from different teams (1 more required, approved so far: ITL) (waiting on @pwmarcz)

a discussion (no related file):

Previously, boryspoplawski (Borys Popławski) wrote…

On one hand I like the idea, sounds neat and would solve the problem, but on the other logging is supposed to be dead simple...

I like @dimakuv's idea and also talked with @pwmarcz, he also likes it (modulo some printing format details, but this we can review after it's implemented).

---

[mkow]

Reviewable status: 1 of 12 files reviewed, 1 unresolved discussion, not enough approvals from maintainers (1 more required), not enough approvals from different teams (1 more required, approved so far: ITL) (waiting on @pwmarcz)

a discussion (no related file):

Previously, mkow (Michał Kowalczyk) wrote…

I like @dimakuv's idea and also talked with @pwmarcz, he also likes it (modulo some printing format details, but this we can review after it's implemented).

Ok, I'll will implement it in a separate PR, but let's start with dropping these explicit newlines from the messages finally and make them implicit.

---