stackMonitor::getCallStacks() always return empty results

[Yukinarii]

I am trying to get the CallStack when a state fork happens. I modified ExecutionTracer::onFork() and tried to invoke stackMonitor::getCallStacks(). However, the size of the returned callStacks is always 0. Here is the code:

void ExecutionTracer::onFork(S2EExecutionState *state, const std::vector<S2EExecutionState *> &newStates,
                             const std::vector<klee::ref<klee::Expr>> &newConditions) {
...
StackMonitor::CallStacks callStacks;
    if (!m_stMonitor->getCallStacks(state, callStacks)) {
        getInfoStream(state) << "fail to get CallStack\n";
    }
    getInfoStream(state) << callStacks.size() << "\n";
...
}

I digged into the code base to try understanding what happened under the hood. I realized that m_stacks in StackMonitorState is always empty. The reason is that whenever StackMonitorState::update() is invoked, it failed to get the stack base and size from BaseLInuxMonitor::getCurrentStack(). And it fails to get this because it does not find any memory region information for the interested pid and stack pointer. One of the log messages I got is as follow:

195 [State 0] StackMonitor: could not get current stack
195 [State 0] StackMonitor: update pid=0x7f0 tid=0x7f0000007f0 pc=0x7f7ed5e37839 sp=0x7ffdbc7fa530 newFrame=0
195 [State 0] LinuxMonitor: cannot find corresponding memory region, m_map of 0x7f0
195 [State 0] MemoryMap: Dumping memory map for pid 2032
pid=0x7f0 [0x5600ac3ea000, 0x5600ac3eafff] R--
pid=0x7f0 [0x5600ac3eb000, 0x5600ac3ebfff] R-X
pid=0x7f0 [0x5600ac3ec000, 0x5600ac3edfff] R--
pid=0x7f0 [0x5600ac3ee000, 0x5600ac3eefff] RW-
pid=0x7f0 [0x7f7ed5d66000, 0x7f7ed5d69fff] RW-
pid=0x7f0 [0x7f7ed5d6a000, 0x7f7ed5d6bfff] R--
pid=0x7f0 [0x7f7ed5d6c000, 0x7f7ed5d7cfff] R-X
pid=0x7f0 [0x7f7ed5d7d000, 0x7f7ed5d82fff] R--
pid=0x7f0 [0x7f7ed5d83000, 0x7f7ed5d83fff] ---
pid=0x7f0 [0x7f7ed5d84000, 0x7f7ed5d84fff] R--
pid=0x7f0 [0x7f7ed5d85000, 0x7f7ed5d85fff] RW-
pid=0x7f0 [0x7f7ed5d86000, 0x7f7ed5d88fff] R--
pid=0x7f0 [0x7f7ed5d89000, 0x7f7ed5d9cfff] R-X
pid=0x7f0 [0x7f7ed5d9d000, 0x7f7ed5da0fff] R--
pid=0x7f0 [0x7f7ed5da1000, 0x7f7ed5da1fff] ---
pid=0x7f0 [0x7f7ed5da2000, 0x7f7ed5da2fff] R--
pid=0x7f0 [0x7f7ed5da3000, 0x7f7ed5da3fff] RW-
pid=0x7f0 [0x7f7ed5da4000, 0x7f7ed5da4fff] R--
pid=0x7f0 [0x7f7ed5da5000, 0x7f7ed5da5fff] R-X
pid=0x7f0 [0x7f7ed5da6000, 0x7f7ed5da7fff] R--
pid=0x7f0 [0x7f7ed5da8000, 0x7f7ed5da8fff] RW-
pid=0x7f0 [0x7f7ed5da9000, 0x7f7ed5dd0fff] R--
pid=0x7f0 [0x7f7ed5dd1000, 0x7f7ed5f65fff] R-X
pid=0x7f0 [0x7f7ed5f66000, 0x7f7ed5fc1fff] R--
pid=0x7f0 [0x7f7ed5fc2000, 0x7f7ed5fd0fff] RW-
pid=0x7f0 [0x7f7ed5fd9000, 0x7f7ed5fdafff] R--
pid=0x7f0 [0x7f7ed5fdb000, 0x7f7ed5fdefff] R-X
pid=0x7f0 [0x7f7ed5fdf000, 0x7f7ed5fdffff] R--
pid=0x7f0 [0x7f7ed5fe0000, 0x7f7ed5fe0fff] ---
pid=0x7f0 [0x7f7ed5fe1000, 0x7f7ed5fe1fff] R--
pid=0x7f0 [0x7f7ed5fe2000, 0x7f7ed5fe4fff] RW-
pid=0x7f0 [0x7f7ed5fe5000, 0x7f7ed5fe6fff] R--
pid=0x7f0 [0x7f7ed5fe7000, 0x7f7ed6010fff] R-X
pid=0x7f0 [0x7f7ed6011000, 0x7f7ed601bfff] R--
pid=0x7f0 [0x7f7ed601d000, 0x7f7ed601efff] R--
pid=0x7f0 [0x7f7ed601f000, 0x7f7ed6020fff] RW-

Apparently, the stack pointer 0x7ffdbc7fa530 does not fall into any of the memory regions in the memory map. I am not sure if I miss anything to make this problem. So my question is: How can I get the correct callStacks with stackMonitor::getCallStacks()?

Here is the simple program I am trying to symbolic execute:

#include <stdio.h>
#include <string.h>
#include <s2e/s2e.h>

void test() {

    char str[3] = { 0 };
    s2e_make_symbolic(str, 2, "str");

    if (str[0] == '\n' || str[1] == '\n') {
        printf("Not enough characters\n");
    } else {
        if (str[0] >= 'a' && str[0] <= 'z') {
            printf("First char is lowercase\n");
        } else {
            printf("First char is not lowercase\n");
        }

        if (str[0] >= '0' && str[0] <= '9') {
            printf("First char is a digit\n");
        } else {
            printf("First char is not a digit\n");
        }

        if (str[0] == str[1]) {
            printf("First and second chars are the same\n");
        } else {
            printf("First and second chars are not the same\n");
        }
    }

    s2e_get_example(str, 2);
    printf("'%c%c' %02x %02x\n", str[0], str[1],
           (unsigned char) str[0], (unsigned char) str[1]);
}

int main(void) {
	test();
	return 0;
}

[vitalych]

I wonder why LinuxMonitor::handleMemMap is not called.
Here's where it's called in the guest: https://github.com/S2E/s2e-linux-kernel/blob/2a62845de82979cb8e7240ca51503dd7ffbb5efb/linux-4.9.3/mm/util.c#L318

Perhaps we are missing other places where Linux is allocating memory.

[Yukinarii]

Thanks for the response! May I know what you mean by "not called" with LinuxMonitor::handleMemMap? We actually found it is called. Here is the part of the error message which has handleMemMap (sorry we didn't put the whole message since it's quite huge.)

3 [State 0] LinuxMonitor: Process ./test loaded pid=0x7f0
3 [State 0] ProcessExecutionDetector: starting to track: test (pid: 0x7f0 as: 0xbe95000)
3 [State 0] LinuxMonitor: mmap pid=0x7f0 addr=0x556b3a3b7000 size=0x5000 prot=0x1 flag=0x1802 pgoff=0x0
MemoryMap: adding region: pid=0x7f0 [0x556b3a3b7000, 0x556b3a3bc000]
3 [State 0] LinuxMonitor: munmap pid=0x7f0 start=0x556b3a3b8000 end=0x556b3a3bc000
MemoryMap: removing region:  pid=0x7f0[0x556b3a3b8000, 0x556b3a3bc000]
3 [State 0] LinuxMonitor: mmap pid=0x7f0 addr=0x556b3a3b8000 size=0x1000 prot=0x5 flag=0x1812 pgoff=0x1
MemoryMap: adding region: pid=0x7f0 [0x556b3a3b8000, 0x556b3a3b9000]
3 [State 0] LinuxMonitor: mmap pid=0x7f0 addr=0x556b3a3b9000 size=0x1000 prot=0x1 flag=0x1812 pgoff=0x2
MemoryMap: adding region: pid=0x7f0 [0x556b3a3b9000, 0x556b3a3ba000]
3 [State 0] LinuxMonitor: mmap pid=0x7f0 addr=0x556b3a3ba000 size=0x2000 prot=0x3 flag=0x1812 pgoff=0x2
MemoryMap: adding region: pid=0x7f0 [0x556b3a3ba000, 0x556b3a3bc000]
3 [State 0] LinuxMonitor: mmap pid=0x7f0 addr=0x7f47006a4000 size=0x3c000 prot=0x1 flag=0x802 pgoff=0x0
MemoryMap: adding region: pid=0x7f0 [0x7f47006a4000, 0x7f47006e0000]
3 [State 0] LinuxMonitor: munmap pid=0x7f0 start=0x7f47006a6000 end=0x7f47006e0000
MemoryMap: removing region:  pid=0x7f0[0x7f47006a6000, 0x7f47006e0000]
3 [State 0] LinuxMonitor: mmap pid=0x7f0 addr=0x7f47006a6000 size=0x2a000 prot=0x5 flag=0x812 pgoff=0x2
MemoryMap: adding region: pid=0x7f0 [0x7f47006a6000, 0x7f47006d0000]
3 [State 0] LinuxMonitor: mmap pid=0x7f0 addr=0x7f47006d0000 size=0xb000 prot=0x1 flag=0x812 pgoff=0x2c
MemoryMap: adding region: pid=0x7f0 [0x7f47006d0000, 0x7f47006db000]
3 [State 0] LinuxMonitor: mmap pid=0x7f0 addr=0x7f47006dc000 size=0x4000 prot=0x3 flag=0x812 pgoff=0x37
MemoryMap: adding region: pid=0x7f0 [0x7f47006dc000, 0x7f47006e0000]
3 [State 0] BaseInstructions: Message from guest (0xffffc90001b23a30): elf_interpreter=/lib64/ld-linux-x86-64.so.2 interp_map_addr=7f47006a4000 elf_entry=0x7f47006a4000 interp_load_addr=0x7f47006a4000
3 [State 0] LinuxMonitor: ModuleDescriptor Name=ld-linux-x86-64.so.2 Path=/lib64/ld-linux-x86-64.so.2 Size=0x38859 AddressSpace=0x9175000 Pid=0x7f0 EntryPoint=0x202b0 Checksum=0x0
3 [State 0] LinuxMonitor: ModuleDescriptor Name=test Path=./test Size=0x103d AddressSpace=0x9175000 Pid=0x7f0 EntryPoint=0x556b3a3b80a0 Checksum=0x0
3 [State 0] ModuleExecutionDetector: loading id mod_0
3 [State 0] StackMonitor: update pid=0x7f0 tid=0x7f0000007f0 pc=0x7f47006c5054 sp=0x7ffdc17c1b90 newFrame=0
3 [State 0] StackMonitor: could not get current stack
3 [State 0] StackMonitor: update pid=0x7f0 tid=0x7f0000007f0 pc=0x7f47006c5058 sp=0x7ffdc17c1b88 newFrame=0
3 [State 0] StackMonitor: could not get current stack
3 [State 0] StackMonitor: update pid=0x7f0 tid=0x7f0000007f0 pc=0x7f47006c505a sp=0x7ffdc17c1b80 newFrame=0

Despite the fact that it is called , the log message shows that it does not match stack pointers. Maybe it should be called on additional locations?

[vitalych]

Was handleMemMap called with the stack region?

[Yukinarii]

Sorry for the late response. I think it was not called with the stack region since the stack pointers in the log messages never falls into the range allocated in early mmap log messages.

However in my understanding of the linux kernel, it does allocate stack memory for a process/thread with mmap, which will trigger handleMemMap. If my understanding is correct and assume the value of stack pointers is always correct, I think we are missing some places in the linux kernel for triggering handleMemMap. If it's correct, where should I put this trigger function?

[Yukinarii]

Hello, I just checked the source code of linux kernel again. My understanding is that every function call involves a mmap call, but I am still confused about why we can't get the correct callStacks. Is it possible for me to get some information about the potential missing part of this handleMemMap function?