test failing on x84_64 (test_i386_invalid_mem_write)

anthraxx commented 9 years ago

Hi, while building and executing the test i have encountered a failing test. This only occurs on x86_64, when building and testing on i686 everything works fine.

here is the output:

make[1]: Entering directory '/build/unicorn/src/unicorn-0.9/tests/unit'
gcc -march=x86-64 -mtune=generic -O2 -pipe -fstack-protector-strong -O3 -Wall -Werror -Wno-unused-function -g -L ../../ -lcmocka -lunicorn -I ../../include -o test_sanity test_sanity.c
gcc -march=x86-64 -mtune=generic -O2 -pipe -fstack-protector-strong -O3 -Wall -Werror -Wno-unused-function -g -L ../../ -lcmocka -lunicorn -I ../../include -o test_x86 test_x86.c
gcc -march=x86-64 -mtune=generic -O2 -pipe -fstack-protector-strong -O3 -Wall -Werror -Wno-unused-function -g -L ../../ -lcmocka -lunicorn -I ../../include -o test_mem_map test_mem_map.c
./test_sanity
[==========] Running 3 test(s).
[ RUN      ] test_uc_assert_macros_constants
[       OK ] test_uc_assert_macros_constants
[ RUN      ] test_uc_assert_macros_func_calls
[       OK ] test_uc_assert_macros_func_calls
[ RUN      ] test_uc_assert_macros_fail

--------------------------------------------------------------------------------
START: Failure of the following tests is expected.

[==========] Running 3 test(s).
[ RUN      ] fail_uc_assert_success
ERROR: No memory available or memory not present (UC_ERR_NOMEM)
test_sanity.c:43: error: Failure!

[  FAILED  ] fail_uc_assert_success
[ RUN      ] fail_uc_assert_err
ERROR: OK (UC_ERR_OK)
test_sanity.c:49: error: Failure!

[  FAILED  ] fail_uc_assert_err
[ RUN      ] fail_uc_assert_fail
ERROR: OK (UC_ERR_OK)
test_sanity.c:54: error: Failure!

[  FAILED  ] fail_uc_assert_fail
[==========] 3 test(s) run.
[  PASSED  ] 0 test(s).
[  FAILED  ] 3 test(s), listed below:
[  FAILED  ] fail_uc_assert_success
[  FAILED  ] fail_uc_assert_err
[  FAILED  ] fail_uc_assert_fail

3 FAILED TEST(S)

END: Failure of the preceding tests was expected.
--------------------------------------------------------------------------------

[       OK ] test_uc_assert_macros_fail
[==========] 3 test(s) run.
[  PASSED  ] 3 test(s).
./test_x86
[==========] Running 11 test(s).
[ RUN      ] test_i386
[       OK ] test_i386
[ RUN      ] test_i386_jump
[       OK ] test_i386_jump
[ RUN      ] test_i386_inout
[       OK ] test_i386_inout
[ RUN      ] test_i386_loop
[       OK ] test_i386_loop
[ RUN      ] test_i386_invalid_mem_read
[       OK ] test_i386_invalid_mem_read
[ RUN      ] test_i386_invalid_mem_write
ERROR: OK (UC_ERR_OK)
test_x86.c:441: error: Failure!

[  FAILED  ] test_i386_invalid_mem_write
[ RUN      ] test_i386_jump_invalid
[       OK ] test_i386_jump_invalid
[ RUN      ] test_x86_64
[       OK ] test_x86_64
[ RUN      ] test_x86_64_syscall
[       OK ] test_x86_64_syscall
[ RUN      ] test_x86_16
[       OK ] test_x86_16
[ RUN      ] test_basic_blocks
[       OK ] test_basic_blocks
[==========] 11 test(s) run.
[  PASSED  ] 10 test(s).
[  FAILED  ] 1 test(s), listed below:
[  FAILED  ] test_i386_invalid_mem_write

1 FAILED TEST(S)
Makefile:19: recipe for target 'test' failed
make[1]: *** [test] Error 1

JonathonReinhart commented 9 years ago

Hi @anthraxx, thanks for the bug report. Can you provide a little more information about your environment, like OS, GCC version, etc? Also, have you customized CFLAGS for this build?

anthraxx commented 9 years ago

sure, here it comes:

additional CFLAGS additions are coming from the build-system that I use automatically:

-march=x86-64 -mtune=generic -O2 -pipe -fstack-protector-strong

you can also observe those in the first lines of my previous (initial) comment.

Environment:

Distribution: Arch Linux x86-64
Kernel: Linux 4.2.2-1-ARCH
gcc: (GCC) 5.2.0
make: GNU Make 4.1
cmocka: 1.0.1
glib2: 2.46.0

JonathonReinhart commented 9 years ago

I cannot reproduce this. From a clean checkout of the 0.9 tag, I am building with the following command:

CFLAGS="-march=x86-64 -mtune=generic -O2 -fstack-protector-strong -O3" make test

(It doesn't make sense to include both -O2 and -O3, but your example did, so I did too.) I'm running

gcc version 5.1.1 20150618 (Red Hat 5.1.1-4) (GCC)

The test in question is passing:

[ RUN      ] test_i386_invalid_mem_write
[       OK ] test_i386_invalid_mem_write

anthraxx commented 9 years ago

maybe it has to do with gcc 5.2 or cmocka: 1.0.1 ? I can reproduce that 100% of the time. I also build from a totally clean chroot, non polluted environment.

Is there any log or trace that i could attach here why exactly this test fails?

JonathonReinhart commented 9 years ago

The failing test assertion is here:

    static const uint8_t code[] = {
        0x89, 0x0D, 0xAA, 0xAA, 0xAA, 0xAA,     // mov  [0xAAAAAAAA], ecx
    };

    // ...

    err = uc_emu_start(uc, address, address+sizeof(code), 0, 0);
    uc_assert_err(UC_ERR_WRITE_UNMAPPED, err);

This code generates a write at address 0xAAAAAAAA, which is not mapped into the current emulation, and therefore should cause uc_emu_start to return UC_ERR_WRITE_UNMAPPED.

I suspect that this is related to the fact that you're using -O3 on gcc 5.2. With each new version of GCC, -O3 tends to optimize "harder", which can bring out very subtle bugs. If you want to help, you could try to determine if -O3 is indeed the cause, and also specifically which optimization enabled by -O3 is causing the issue (by starting at -O2 and enabling the options from -O3 one by one until the test fails).

aquynh commented 9 years ago

perhaps this is due to some optimization in TCG layer is broken with the new GCC.

any newer Ubuntu has GCC 5.2, so i can try to reproduce this problem?

aquynh commented 9 years ago

@anthraxx: what is the output of samples/sample_x86 on your machine? is there any errors when you run it?

anthraxx commented 9 years ago

@aquynh turns out the problem is within '-fstack-protector-strong' that lets the test fail.

Can we get that somehow fixed? And no, I don't think building without "-fstack-protector-strong" is a good option to fix the problem :stuck_out_tongue_closed_eyes:

FAIL: with -fstack-protector-strong

Emulate i386 code
>>> Tracing basic block at 0x0ffffff, block size = 0x2
>>> Tracing instruction at 0x1000000, instruction size = 0x1
>>> --- EFLAGS is 0x0
>>> Tracing instruction at 0x1000001, instruction size = 0x1
>>> --- EFLAGS is 0x4
>>> Emulation done. Below is the CPU context
>>> ECX = 0x1235
>>> EDX = 0x788f
>>> Read 4 bytes from [0x1000000] = 0x4a41
===================================
Emulate i386 code with IN/OUT instructions
>>> Tracing basic block at 0x1000000, block size = 0x7
>>> Tracing instruction at 0x1000000, instruction size = 0x1
>>> --- EFLAGS is 0x0
>>> Tracing instruction at 0x1000001, instruction size = 0x2
>>> --- EFLAGS is 0x0
--- reading from port 0x3f, size: 1, address: 0x1000001
>>> Tracing instruction at 0x1000003, instruction size = 0x1
>>> --- EFLAGS is 0x0
>>> Tracing instruction at 0x1000004, instruction size = 0x2
>>> --- EFLAGS is 0x94
--- writing to port 0x46, size: 1, value: 0xf1, address: 0x1000004
--- register value = 0xf1
>>> Tracing instruction at 0x1000006, instruction size = 0x1
>>> --- EFLAGS is 0x94
>>> Emulation done. Below is the CPU context
>>> EAX = 0x12f1
>>> ECX = 0x678a
===================================
Emulate i386 code with jump
>>> Tracing basic block at 0x1000000, block size = 0x2
>>> Tracing instruction at 0x1000000, instruction size = 0x2
>>> --- EFLAGS is 0x0
>>> Emulation done. Below is the CPU context
===================================
Emulate i386 code that loop forever
>>> Emulation done. Below is the CPU context
>>> ECX = 0x1235
>>> EDX = 0x788f
===================================
Emulate i386 code that read from invalid memory
>>> Tracing basic block at 0x1000000, block size = 0x8
>>> Tracing instruction at 0x1000000, instruction size = 0x6
>>> --- EFLAGS is 0x0
Failed on uc_emu_start() with error returned 6: Invalid memory read (UC_ERR_READ_UNMAPPED)
>>> Emulation done. Below is the CPU context
>>> ECX = 0x1234
>>> EDX = 0x7890
===================================
Emulate i386 code that write to invalid memory
>>> Tracing basic block at 0x1000000, block size = 0x8
>>> Emulation done. Below is the CPU context
>>> ECX = 0x1234
>>> EDX = 0x7890
>>> Failed to read 4 bytes from [0xffffffaa]
>>> Failed to read 4 bytes from [0xffffffaa]
===================================
Emulate i386 code that jumps to invalid memory
>>> Tracing basic block at 0x1000000, block size = 0x5
>>> Tracing instruction at 0x1000000, instruction size = 0x5
>>> --- EFLAGS is 0x0
Failed on uc_emu_start() with error returned 8: Invalid memory fetch (UC_ERR_FETCH_UNMAPPED)
>>> Emulation done. Below is the CPU context
>>> ECX = 0x1234
>>> EDX = 0x7890

Success: without -fstack-protector-strong

Emulate i386 code
>>> Tracing basic block at 0x1000000, block size = 0x2
>>> Tracing instruction at 0x1000000, instruction size = 0x1
>>> --- EFLAGS is 0x0
>>> Tracing instruction at 0x1000001, instruction size = 0x1
>>> --- EFLAGS is 0x4
>>> Emulation done. Below is the CPU context
>>> ECX = 0x1235
>>> EDX = 0x788f
>>> Read 4 bytes from [0x1000000] = 0x4a41
===================================
Emulate i386 code with IN/OUT instructions
>>> Tracing basic block at 0x1000000, block size = 0x7
>>> Tracing instruction at 0x1000000, instruction size = 0x1
>>> --- EFLAGS is 0x0
>>> Tracing instruction at 0x1000001, instruction size = 0x2
>>> --- EFLAGS is 0x0
--- reading from port 0x3f, size: 1, address: 0x1000001
>>> Tracing instruction at 0x1000003, instruction size = 0x1
>>> --- EFLAGS is 0x0
>>> Tracing instruction at 0x1000004, instruction size = 0x2
>>> --- EFLAGS is 0x94
--- writing to port 0x46, size: 1, value: 0xf1, address: 0x1000004
--- register value = 0x7ff1
>>> Tracing instruction at 0x1000006, instruction size = 0x1
>>> --- EFLAGS is 0x94
>>> Emulation done. Below is the CPU context
>>> EAX = 0x12f1
>>> ECX = 0x678a
===================================
Emulate i386 code with jump
>>> Tracing basic block at 0x1000000, block size = 0x2
>>> Tracing instruction at 0x1000000, instruction size = 0x2
>>> --- EFLAGS is 0x0
>>> Emulation done. Below is the CPU context
===================================
Emulate i386 code that loop forever
>>> Emulation done. Below is the CPU context
>>> ECX = 0x1235
>>> EDX = 0x788f
===================================
Emulate i386 code that read from invalid memory
>>> Tracing basic block at 0x1000000, block size = 0x8
>>> Tracing instruction at 0x1000000, instruction size = 0x6
>>> --- EFLAGS is 0x0
Failed on uc_emu_start() with error returned 6: Invalid memory read (UC_ERR_READ_UNMAPPED)
>>> Emulation done. Below is the CPU context
>>> ECX = 0x1234
>>> EDX = 0x7890
===================================
Emulate i386 code that write to invalid memory
>>> Tracing basic block at 0x1000000, block size = 0x8
>>> Tracing instruction at 0x1000000, instruction size = 0x6
>>> --- EFLAGS is 0x0
>>> Missing memory is being WRITE at 0xaaaaaaaa, data size = 4, data value = 0x1234
>>> Tracing instruction at 0x1000006, instruction size = 0x1
>>> --- EFLAGS is 0x0
>>> Tracing instruction at 0x1000007, instruction size = 0x1
>>> --- EFLAGS is 0x4
>>> Emulation done. Below is the CPU context
>>> ECX = 0x1235
>>> EDX = 0x788f
>>> Read 4 bytes from [0xaaaaaaaa] = 0x1234
>>> Failed to read 4 bytes from [0xffffffaa]
===================================
Emulate i386 code that jumps to invalid memory
>>> Tracing basic block at 0x1000000, block size = 0x5
>>> Tracing instruction at 0x1000000, instruction size = 0x5
>>> --- EFLAGS is 0x0
Failed on uc_emu_start() with error returned 8: Invalid memory fetch (UC_ERR_FETCH_UNMAPPED)
>>> Emulation done. Below is the CPU context
>>> ECX = 0x1234
>>> EDX = 0x7890

JonathonReinhart commented 9 years ago

@anthraxx Can you see if you are able to successfully build QEMU v2.2.1 with the same GCC and CFLAGS, and run a test executable? We're trying to see if this is a bug in Unicorn on QEMU.

anthraxx commented 9 years ago

@JonathonReinhart just run any executable on qemu 2.2.1 with that GCC and CFLAGS? sure will do that soon, but would be amazing if that fails :grinning:

JonathonReinhart commented 9 years ago

@anthraxx Yes, it would be amazing. To state the obvious, it is QEMU that is to be built with that GCC and CFLAGS, not the test executable.

Thank you for pointing that out. I've since edited my original comment. You can edit yours if you wish, to keep this thread clean.

anthraxx commented 9 years ago

@JonathonReinhart ok looks like i did not test well enough, current test progress (verified very detailed and invested a lot of time to not make any mistakes and also clarify why i failed with my assumption before):

1) The problem is exactly -O3, to be specific its the '-ftree-partial-pre' option of -O3

fails with -O2 -ftree-partial-pre
success with -O2 and all -O3 options except -ftree-partial-pre

2) my test case was borked because it turned out that if CFLAGS was defined at all (even empty string) than the -O3 switch was added because of regeneration via configure and then the resulting config-host.mak included -O3. https://github.com/unicorn-engine/unicorn/blob/0.9/qemu/configure#L291

3) Isn't the UNICORN_DEBUG check the wrong way around or am I just mad?! https://github.com/unicorn-engine/unicorn/blob/master/Makefile#L61

4) Seems like the release tarball has UNICORN_DEBUG set to yes in config.mk https://github.com/unicorn-engine/unicorn/blob/0.9/config.mk#L11

5) It seems like whatever I do (even UNICORN_DEBUG set to no) the -g option seems to be added. This even happens with options where -O3 will not be included... you can check the output line:

CFLAGS            -pthread -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include -g  -O3

6)

rebuild qemu 2.2.1 works fine (i686 + x64) with all my options passed to it (without your -O3 options that include -ftree-partial-pre)
rebuild qemu 2.2.1 with '-ftree-partial-pre' works fine (i686 + x64) (because of the previous test [1] i assume its not needed to also rebuild and test with -O3 as -ftree-partial-pre exclusively was the failing option

JonathonReinhart commented 9 years ago

@anthraxx Thanks a lot for your very detailed report. So, you've confirmed that QEMU 2.2.1 builds and executes successfully when built with your GCC and CFLAGS (including -O3). It seems then that we have a very subtle bug on our hands that only GCC 5.2's -ftree-partial-pre brings out.

anthraxx commented 8 years ago

sorry, I don't want to create noise... I'm just wondering why @aquynh has labeled this only with 'question' rather then 'bug' :smile:

aquynh commented 8 years ago

it is just because i dont have an Arch box to test this. so a quick question: how to reproduce this on Ubuntu 14.04 64bit?

thanks.

anthraxx commented 8 years ago

@aquynh no clue I'm not a ubuntu guy :yum: did you try building with gcc (GCC) 5.2.0 on ubuntu... maybe thats already enough to trigger this on ubuntu? However just to as a re-summary: building stock QEMU 2.2.1 with -O3 on gcc 5.2.0 does not seem to result in a broken qemu (at least I could run different binaries emulated with qemu)

aquynh commented 8 years ago

@anthraxx, would you mind getting the latest code and build/install again to see if this problem is gone now on GCC 5.2?

thanks.

anthraxx commented 8 years ago

this issue (test_i386_invalid_mem_write) seems resolved with gcc 5.3.0 so looks like it was a gcc bug and corner case somewhere in your code. The current git HEAD has 3 tests failing (both -O2 and -O3), I will create a new bug report for that.

unicorn-engine / unicorn

test failing on x84_64 (test_i386_invalid_mem_write) #183