Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SCP: Add'l memory sanitization fixes (was: SCP: Initialize de-dup'ed debug line buffer.) #327

Merged
merged 1 commit into from
Feb 1, 2024

Conversation

bscottm
Copy link
Contributor

@bscottm bscottm commented Nov 29, 2023

realloc(NULL, size) == malloc(size), which results in an uninitialized debug line buffer and will fail memory sanitizer checks. Ensure that the buffers are memset() to zero when initially allocated.

@markpizz
Copy link
Contributor

This change exists to accommodate a weakness in your analyzer tool and not a bug in the code. The contents of these buffers are only referenced based on other variables which manage the state of the buffer.

@bscottm
Copy link
Contributor Author

bscottm commented Nov 29, 2023

Mark -- I cordially invite you to tell Google and Apple that their memory sanitizer tester sucks eggs. Must be something in the bcmp where the uninitialized memory error gets triggered.

@markpizz
Copy link
Contributor

I didn't say it sucks eggs, you did. I'll leave any reporting up to you.

By an equivalent logic, those buffers are growing as needed, and using precisely the same "precise analysis", why isn't it complaining about the region of those buffers that have grown, which is equally uninitialized.

@bscottm
Copy link
Contributor Author

bscottm commented Nov 30, 2023

The sanitizer trips on the first realloc(NULL, size), which is simply a call to malloc(size). It's considered a best practice to initialize malloc()-ed memory, so why not initialize it? I look at the output of the Google-developed, Apple-funded Clang/LLVM-integrated memory sanitizer as a strong hint that initialization is a very good idea, even if it shouldn't happen in practice.

@bscottm bscottm changed the title SCP: Initialized de-dup'ed debug line buffer. SCP: Initialize de-dup'ed debug line buffer. Dec 4, 2023
@bscottm
Copy link
Contributor Author

bscottm commented Dec 4, 2023

Squashed the two commits and re-pushed forcefully.

@bscottm bscottm changed the title SCP: Initialize de-dup'ed debug line buffer. SCP: Add'l memory sanitization fixes (was: SCP: Initialize de-dup'ed debug line buffer.) Dec 4, 2023
@pkoning2
Copy link
Member

pkoning2 commented Dec 4, 2023

So do the "sanitizer" complain about realloc with null input pointer, but not when the input pointer is non-null? In either case, any newly allocated space is uninitialized.
What precisely does it say when it complains? Is there a way to say "don't complain, this is a false positive"? There's merit in Mark's comment that adding superfluous code to work around buggy "checkers" is not the best answer. If it's clearly a false positive, reporting it to the authors would be logical. They may well fix it. I don't know what sanitizer you're referring to here, but my experience with Coverity -- which aims to do this sort of thing -- is that they were quite responsive to false positive reports. If all else fails, we can document "don't use this tool".

@bscottm
Copy link
Contributor Author

bscottm commented Dec 5, 2023

@pkoning2: The sanitizers (address, memory, thread) all produce a traceback that tells you where the issue occurred. The sanitizer builds use -O2 -g so that the tracebacks include file and line number.

My basic point: Clang's sanitizers have a good provenance, why not address the traceback outputs? I strongly doubt that Google's sanitizers produce many false positives, given the number of developers who use them. (Note: I didn't say "can't", "won't", or "don't".) The sanitizers have been part and parcel of Clang for a while (ca. 2012 for address) and there's a kernel address sanitizer that's regularly used on the Linux kernel. Wikipedia page here.

Here's the culprit exercized (exorcised?) in the i650 simulator:

14/78 Test #14: simh-i650 ........................***Failed    0.98 sec
 Running internal register sanity checks on IBM 650 simulator.
*** Good Registers in IBM 650 simulator.

IBM 650 simulator Open SIMH V4.1-0 Current        git commit id: 2c269988
Logging to file "console.txt"


** IBM 650: Basic Instruction Test: 
Uninitialized bytes in MemcmpInterceptorCommon at offset 46 inside [0x7[180](https://github.com/bscottm/open-simh/actions/runs/7094768306/job/19310605741#step:6:181)00000405, 108)
==7743==WARNING: MemorySanitizer: use-of-uninitialized-value
    #0 0x55bf7173141e in bcmp (/home/runner/work/open-simh/open-simh/BIN/i650+0x6541e) (BuildId: f0af08782834[184](https://github.com/bscottm/open-simh/actions/runs/7094768306/job/19310605741#step:6:185)2eb26d8ad2d22d3328e3be3f6)
    #1 0x55bf7[186](https://github.com/bscottm/open-simh/actions/runs/7094768306/job/19310605741#step:6:187)b092 in _sim_debug_write_flush /home/runner/work/open-simh/open-simh/scp.c:13672:22
    #2 0x55bf7186030e in _sim_debug_write /home/runner/work/open-simh/open-simh/scp.c:13705:1
    #3 0x55bf7186030e in _sim_vdebug /home/runner/work/open-simh/open-simh/scp.c:14096:21
    #4 0x55bf717d6121 in _sim_debug_device /home/runner/work/open-simh/open-simh/scp.c:14143:5
    #5 0x55bf717a39e9 in cdr_cmd /home/runner/work/open-simh/open-simh/I650/i650_cdr.c:1161:5
    #6 0x55bf71783591 in ExecOpcode /home/runner/work/open-simh/open-simh/I650/i650_cpu.c:1205:26
    #7 0x55bf71792437 in sim_instr /home/runner/work/open-simh/open-simh/I650/i650_cpu.c:[195](https://github.com/bscottm/open-simh/actions/runs/7094768306/job/19310605741#step:6:196)8:22
    #8 0x55bf718480f4 in run_cmd /home/runner/work/open-simh/open-simh/scp.c:9325:13
    #9 0x55bf717ff3a7 in do_cmd_label /home/runner/work/open-simh/open-simh/scp.c
    #10 0x55bf717fd7b8 in do_cmd /home/runner/work/open-simh/open-simh/scp.c:4040:8
    #11 0x55bf717ff3a7 in do_cmd_label /home/runner/work/open-simh/open-simh/scp.c
    #12 0x55bf717fd7b8 in do_cmd /home/runner/work/open-simh/open-simh/scp.c:4040:8
    #13 0x55bf717da215 in main /home/runner/work/open-simh/open-simh/scp.c:2944:16
    #14 0x7fb90de29d8f  (/lib/x86_64-linux-gnu/libc.so.6+0x29d8f) (BuildId: a43bfc8428df6623cd498c9c0caeb91aec9be4f9)
    #15 0x7fb90de29e3f in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x29e3f) (BuildId: a43bfc8428df6623cd498c9c0caeb91aec9be4f9)
    #16 0x55bf716f8804 in _start (/home/runner/work/open-simh/open-simh/BIN/i650+0x2c804) (BuildId: f0af087828341842eb26d8ad2d22d3328e3be3f6)

SUMMARY: MemorySanitizer: use-of-uninitialized-value (/home/runner/work/open-simh/open-simh/BIN/i650+0x6541e) (BuildId: f0af087828341842eb26d8ad2d22d3328e3be3f6) in bcmp
Exiting

The code, where I've intentionally set do_init to 0 to trip the memory sanitizer traceback. Look for /* Line 13672 ===> */ (Looking at the code, the issue could also be the + 1 in (eol - endprefix)+ 1. Either way, it's not likely a false positive.)

static void _sim_debug_write_flush (const char *buf, size_t len, t_bool flush)
{
char *eol;

if (sim_deb_switches & SWMASK ('F')) {              /* filtering disabled? */
    if (len > 0)
        _debug_fwrite (buf, len);                   /* output now. */
    return;                                         /* done */
    }
AIO_LOCK;
if (debug_line_offset + len + 1 > debug_line_bufsize) {
    /* realloc(NULL, size) == malloc(size). Really. It is. Initialize
     * the malloc()-ed space. */
    int do_init = 0; /*(NULL == debug_line_buf) || (NULL == debug_line_buf_last);*/

    debug_line_bufsize += MAX(1024, debug_line_offset + len + 1);
    debug_line_buf = (char *)realloc (debug_line_buf, debug_line_bufsize);
    debug_line_buf_last = (char *)realloc (debug_line_buf_last, debug_line_bufsize);

    if (do_init) {
        memset(debug_line_buf, 0, debug_line_bufsize);
        memset(debug_line_buf_last, 0, debug_line_bufsize);
        }
    }
memcpy (&debug_line_buf[debug_line_offset], buf, len);
debug_line_buf[debug_line_offset + len] = '\0';
debug_line_offset += len;
while ((eol = strchr (debug_line_buf, '\n')) || flush) {
    char *endprefix = strstr (debug_line_buf, ")> ");
    size_t linesize = (eol - debug_line_buf) + 1;

    if ((0 != memcmp ("DBG(", debug_line_buf, 4)) || (endprefix == NULL)) {
        if (debug_line_count > 0)
            _debug_fwrite (debug_line_buf_last, strlen (debug_line_buf_last));
        if (debug_line_count > 1) {
            char countstr[40];

            sprintf (countstr, "same as above (%d time%s)\r\n", (int)(debug_line_count - 1), ((debug_line_count - 1) != 1) ? "s" : "");
            _debug_fwrite (debug_line_last_prefix, strlen (debug_line_last_prefix));
            _debug_fwrite (countstr, strlen (countstr));
            }
        if (flush) {
            linesize = debug_line_offset;
            flush = FALSE;              /* already flushed */
            }
        if (linesize)
            _debug_fwrite  (debug_line_buf, linesize);
        debug_line_count = 0;
        }
    else {
        linesize = debug_line_offset;
        if (debug_line_count == 0) {
            debug_line_buf_last_endprefix_offset = endprefix - debug_line_buf;
            memcpy (debug_line_buf_last, debug_line_buf, linesize);
            debug_line_buf_last[linesize] = '\0';
            debug_line_count = 1;
            }
        else {
            /* Line 13672 ===> */ if (0 == memcmp (&debug_line_buf[endprefix - debug_line_buf], 
                             &debug_line_buf_last[debug_line_buf_last_endprefix_offset], 
                             (eol - endprefix)+ 1)) {
                ++debug_line_count;
                memcpy (debug_line_last_prefix, debug_line_buf, (endprefix - debug_line_buf) + 3);
                debug_line_last_prefix[(endprefix - debug_line_buf) + 3] = '\0';
                }
            else {
                _debug_fwrite (debug_line_buf_last, strlen (debug_line_buf_last));
                if (debug_line_count > 1) {
                    char countstr[40];

                    sprintf (countstr, "same as above (%d time%s)\r\n", (int)(debug_line_count - 1), ((debug_line_count - 1) != 1) ? "s" : "");
                    _debug_fwrite (debug_line_last_prefix, strlen (debug_line_last_prefix));
                    _debug_fwrite (countstr, strlen (countstr));
                    }
                debug_line_buf_last_endprefix_offset = endprefix - debug_line_buf;
                memcpy (debug_line_buf_last, debug_line_buf, linesize);
                debug_line_buf_last[linesize] = '\0';
                debug_line_count = 1;
                }
            }
        }
    debug_line_offset -= linesize;
    if ((debug_line_offset > 0) && (!flush))
        memmove (debug_line_buf, eol + 1, debug_line_offset);
    debug_line_buf[debug_line_offset] = '\0';
    }
AIO_UNLOCK;
}

@bscottm
Copy link
Contributor Author

bscottm commented Dec 5, 2023

No, it's not the "+ 1".

@markpizz
Copy link
Contributor

markpizz commented Dec 5, 2023

The comparison that is happening there "might in theory" compare against uninitialized data if a second line being considered was longer than the first, BUT such a comparison would fail when the EOL character in the earlier line was compared against the character at the same offset in the new buffer and since the new line is longer than the prior line, the comparison would fail on that EOL compare against a non EOL character and nothing beyond the original line's EOL in the buffer would be referenced. The +1 in the comparison and in the buffer copy assure that the EOL gets compared and moved. Here the failure "theory" that could trigger the fault being raised is that all of the data in the memcmp() may not be initialized, but the logic in the code knows that the compare will stop without referencing uninitialized memory.

@pkoning2
Copy link
Member

pkoning2 commented Dec 5, 2023

I think the error in the memcmp is that it is comparing what is actually two strings, but as memory blocks using the length of the second string as the length to compare. One wonders why strcmp isn't used there, that should avoid the problem entirely.

@bscottm
Copy link
Contributor Author

bscottm commented Dec 5, 2023

memcmp fails the first time it's called, comparing 108 bytes in debug_line_buf vs, a much smaller debug_line_buf_last:

debug_line_buf
0x7ff4b03400 "DBG(1)> CPU DETAIL: Read Card: G0195119026919521951691954195369195619556919581957691960195910800119653500011966\r\n"
debug_line_buf_last
0x7ff4b03000 "DBG(1)> CPU CMD: Exec 8000: 70 RD     1901 9999 \r\n"

The Clang memory sanitizer detected the uninitialized space in debug_line_buf_last before making the comparison. It's not done byte-by-byte; it's answering the question, "Are we about to compare against uninitialized space?" In this particular instance, technically, no, we won't because memcmp() will return non-zero at the 4th byte in the comparison. In the more general case, we'd really like to avoid potentially comparing uninitialized space to begin with, which could happen if end - endprefix + 1 goes past the end of debug_line_buf_last.

Four solutions to the problem:

  1. Use the current patch that memset()-s the malloc()-ed space. Ensures that the space is initialized so that memcmp() is guaranteed to fail the comparison (which it should anyway.)
  2. Keep track of the last message's comparison length, debug_line_buf_last_linelen, and only execute memcmp() when end - endprefix + 1 == debug_line_buf_last_linelen.
  3. Do (1) and (2).
  4. Insert a preprocessor forest or Clang-specific compiler annotations when compiled with sanitizers. This is really undesirable because it's a maintenance nightmare and confuses the code's original intent with too many potential execution paths to read through.

My preference is (3). It avoids the weird case of traipsing past debug_line_buf_last in the general case (graceful memcmp fail, if ever), puts stricter bound checking on the memcmp().

@markpizz
Copy link
Contributor

markpizz commented Dec 6, 2023

memcmp fails the first time it's called, comparing 108 bytes in debug_line_buf vs, a much smaller debug_line_buf_last:

Actually, it DOES NOT fail, it merely is flagged by the sanitizer you are trying to accommodate.

As I said previously in precisely this case, the much smaller debug_line_buf_last has a newline at the end of that smaller range, while the current debug_line_buf doesn't have a newline until some 108 bytes out. The comparison will correctly return a non-zero value after touching at most the size of the previous data before (and including) the newline.

Feel free to make any change you want so that the sanitizer is happy. The unmodified code is correct without any of your various changes that might make the sanitizer happy.

@pkoning2
Copy link
Member

pkoning2 commented Dec 6, 2023

What about my suggestion -- which is that strcmp is the obvious correct answer since we're comparing null-terminated strings.

@markpizz
Copy link
Contributor

markpizz commented Dec 6, 2023

The current logic is precisely equivalent to strcmp() with a newline as the string terminator. The data in question is in a buffer that may be presented in a larger piece with multiple lines of data to be processed. Trying to use strcmp(), you'd have to modify the contents of the buffer to NUL terminate the strings and restore it after the test.

As I said, since you're deciding on what's good to commit, feel free to make any changes needed to make the tool which triggers on a false positive here happy. Has this tool revealed any other actual issues in any simulator?

@pkoning2
Copy link
Member

pkoning2 commented Dec 6, 2023

But there is a null terminator in the buffer, too, right?

                debug_line_buf_last[linesize] = '\0';

Still, I can see the point about this being a false positive, since memcmp should not read beyond the first difference. Perhaps the argument is that this isn't actually stated explicitly? If not, then approach (2) seems like a good one.

@markpizz
Copy link
Contributor

markpizz commented Dec 6, 2023

But there is a null terminator in the buffer, too, right?

The whole buffer may indeed be null terminated, but the relevant comparison in the memcmp that is relevant is the from the point specified up to and including the newline.

Point 2's info is precisely determined by the newline in the buffer. Keeping track of that fact separately is at best a work around to accommodate the false positive in the tool, and that alone may not satisfy the tool's analysis since the buffer in question has may have uninitialized data beyond the useful data.

I ask again: Has this tool reported any other actual problems?

@rcornwell
Copy link
Member

I can see why this code is failing, however I don't like the solution. The buffer will be initialized the first time it is used. Since there will be nothing in the original buffer. I would recommend an if (buffer == NULL) { buffer = (char *)malloc(size); *buffer = '\0'; } else { buffer = realloc(buffer, newsize); }

@Rhialto
Copy link
Contributor

Rhialto commented Dec 6, 2023 via email

@bscottm
Copy link
Contributor Author

bscottm commented Dec 6, 2023

Updated commit:

  • memset()-ing the debug line buffers to 0 (only when realloc(NULL, size) == malloc(size).)
  • Keep track of the comparison lengths and only call memcmp() if the lengths are equal.
  • Added a test to "testlib" to make sure that deduplication works
  • Fixed CIDR ACL parsing off-by-one bug

@Rhialto, @rcornwell: I took a quick look at the memcmp implementation in LLVM/Clang. @Rhialto is correct about vector instructions, specifically Clang's libc implementation uses them for 32 and 64 byte lengths. So, it's absolutely conceivable that uninitialized memory could be read in the general case.

@bscottm
Copy link
Contributor Author

bscottm commented Dec 6, 2023

For reference, the inline memcmp() implementation for Clang's libc on x86_64

Initialize de-dup'ed debug line buffer:

  realloc(NULL, size) == malloc(size), which is uninitialized space.
  This causes the Clang memory sanitizer to detect an attempt to read
  uninitialized memory when debug_line_buf and debug_line_buf_last are
  different lengths. While the uninitialized space may never actually be
  compared, the memory sanitizer emits a strong hint to not do stupid.

  The sanitizer trips in the i650 simulator on the first memcmp(),
  debug_line_buf has 108 characters, debug_line_buf_last has 56
  characters (uninitialized space follows the 56 characters, tripping
  the sanitizer.)

  - memset() debug_line_buf and debug_line_buf_last to zero so that
    memcmp() will always gracefully return non-zero if somehow memcmp()
    ends up going past the end of either buffer.  Should never happen in
    practice, but theory always gets mugged by reality.

  - Keep track of debug_line_buf_last's comparison length (i.e., up to
    the '\r') and only execute memcmp() when this length equals the
    current debug_line_buf comparison length (end - endprefix + 1).

  - Added a log deduplication test to "testlib" command to ensure that
    nothing broke as a result of this fix.

Network ACL check in sim_addr_acl_check:

  The memory sanitizer found an off-by-one bug in sim_addr_acl_check
  while executing "testlib". This makes CIDR network ACLs functional,
  e.g., "127.0.0.1/32" is interpreted properly and the associated
  "testlib" test passes.
@pkoning2 pkoning2 merged commit f4c39a3 into open-simh:master Feb 1, 2024
18 checks passed
@bscottm bscottm deleted the log-realloc-null branch February 23, 2024 23:04
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants