Ericsson / codechecker

CodeChecker is an analyzer tooling, defect database and viewer extension for the Clang Static Analyzer and Clang Tidy
https://codechecker.readthedocs.io
Apache License 2.0
2.23k stars 374 forks source link

Android A10 first full build does not generate any reports #2975

Closed wizwin closed 3 years ago

wizwin commented 3 years ago

Describe the bug Android A10 build full build does not generate any reports. The report directory is empty.

CodeChecker version

CodeChecker analyzer version:
---------------------------------------------------------------
Kind                 | Version
---------------------------------------------------------------
Base package version | 6.14.0
Package build date   | 2020-09-03T13:35
Git commit ID (hash) | e1bcd909b7885fd02498fd6bad96eb200882ed8c
Git tag information  | 6.14
---------------------------------------------------------------

CodeChecker web version:
------------------------------------------------------------------------
Kind                          | Version
------------------------------------------------------------------------
Base package version          | 6.14.0
Package build date            | 2020-09-03T13:35
Git commit ID (hash)          | e1bcd909b7885fd02498fd6bad96eb200882ed8c
Git tag information           | 6.14
Server supported API (Thrift) | 6.30
Client API (Thrift)           | 6.30
------------------------------------------------------------------------

To Reproduce

1. Configure clang from the following path:

LA.UM.8.2/LINUX/android/prebuilts/clang/host/linux-x86/clang-r353983c1​

"analyzers": {​
    "clangsa": "/build/Projects/A10/LA.UM.8.2/LINUX/android/prebuilts/clang/host/linux-x86/clang-r353983c1/bin/clang",​
    "clang-tidy": "/build/Projects/A10/LA.UM.8.2/LINUX/android/prebuilts/clang/host/linux-x86/clang-r353983c1/bin/clang-tidy"​
},

2. Perform build from LA.UM.8.2/LINUX/android/ using a script file with the following commands (so env is setup correctly):

Contents of ./cbuild.sh

------------------------------------------------------------------------
export _JAVA_OPTIONS="-Xmx4g"
export CC_LOGGER_DEBUG_FILE="/home/directory/CodeChecker/codechecker.debug.log"

cd LA.UM.8.2/LINUX/android/

source ./build/envsetup.sh
choosecombo 1 <product name> 2 1
make -j10
------------------------------------------------------------------------

$ CodeChecker check -b "./cbuild.sh" -o /build/Projects/results​ --verbose debug

3. See error

353632 [ 99% 166181/166182] Target system fs image: out/target/product/product/obj/PACKAGING/systemimage_intermediates/system.img
353633 [100% 166182/166182] Install system fs image: out/target/product/device/system.img
353634
353635 ^[[0;32m#### build completed successfully (03:28:54 (hh:mm:ss)) ####^[[00m
353636
353637 Wed Oct  7 22:43:56 IST 2020
353638 Done SA build...
353639 [INFO][2020-10-07 22:43:56] {buildlogger} [14695] <140316576413504> - build_manager.py:119 perform_build_command() - Build finished successfully.
353640 [DEBUG_ANALYZER][2020-10-07 22:43:56] {buildlogger} [14695] <140316576413504> - build_manager.py:120 perform_build_command() - The logfile is: /tmp/tmpykmqjar0
353641 [INFO][2020-10-07 22:43:56] {buildlogger} [14695] <140316576413504> - build_manager.py:132 perform_build_command() - The debug log file is: /build/CodeChecker/codechecker.debug.log
353642 [DEBUG][2020-10-07 22:43:57] {system} [14695] <140316576413504> - check.py:798 main() - Calling ANALYZE with args:
353643 [DEBUG][2020-10-07 22:43:57] {system} [14695] <140316576413504> - check.py:799 main() - Namespace(analyzer_config=['clang-tidy: HeaderFilterRegex=.*'], compile_uniqueing='none', config_file=None, jobs=1, keep_gcc_include_fixed=False, keep_gcc_intrin=False, logfile='/tmp/tmpykmqjar0', output_format='plist', output_path='/build/results\u200b', verbose='debug')
353644 [DEBUG][2020-10-07 22:43:57] {system} [14695] <140316576413504> - analyzer_context.py:521 get_context() - Loading package config.
353645 [DEBUG][2020-10-07 22:43:57] {system} [14695] <140316576413504> - analyzer_context.py:526 get_context() - Reading config: /build/CodeChecker/build/CodeChecker/config/config.json
353646 [DEBUG][2020-10-07 22:43:57] {system} [14695] <140316576413504> - analyzer_context.py:532 get_context() - {'environment_variables': {'env_path': 'PATH', 'env_ld_lib_path': 'LD_LIBRARY_PATH', 'cc_logger_bin': 'CC_LOGGER_BIN', 'cc_logger_file': 'CC_LOGGER_FILE', 'cc_logger_compiles': 'CC_LOGGER_GCC_LIKE', 'ld_preload': 'LD_PRELOAD', 'codechecker_workspace': 'CODECHECKER_WORKSPACE'}}
353647 [DEBUG][2020-10-07 22:43:57] {system} [14695] <140316576413504> - analyzer_context.py:534 get_context() - Loading layout config.
353648 [DEBUG][2020-10-07 22:43:57] {system} [14695] <140316576413504> - analyzer_context.py:538 get_context() - /build/CodeChecker/build/CodeChecker/config/package_layout.json
353649 [WARNING][2020-10-07 22:43:59] {system} [14695] <140316576413504> - util.py:105 load_json_or_empty() - 'json' is not a valid /tmp/tmpykmqjar0 file.
353650 [WARNING][2020-10-07 22:43:59] {system} [14695] <140316576413504> - util.py:106 load_json_or_empty() - Expecting ',' delimiter: line 149944 column 2025 (char 95096588)

Size of /tmp: /dev/mapper/vg--sdc-tmp 393G 8.2G 365G 3% /tmp

Expected behaviour CodeChecker should not fail for a full Android build. It should generate reports on the initial build (as base reports).

Desktop (please complete the following information)

Follow up of bug: #2916

Additional Notes: Subsequent build (incremental) using the same command, without cleaning the out directory:

gyorb commented 3 years ago

Hi,

Could you check if there is any unicode character in the modified package_layout.json? For me vim shows this with the example you mentioned in the issue:

  "analyzers": {​<200b>
    "clangsa": "/build/Projects/A10/LA.UM.8.2/LINUX/android/prebuilts/clang/host/linux-x86/clang-r353983c1/bin/clang",​<200b>
    "clang-tidy": "/build/Projects/A10/LA.UM.8.2/LINUX/android/prebuilts/clang/host/linux-x86/clang-r353983c1/bin/clang-tidy"​<200b>
  },

There are some unicode 'zero width space' characters there. You can check if the json file is valid with this command python3 -m json.tool config/package_layout.json

wizwin commented 3 years ago

@gyorb - I am using the same config for the incremental build as well, which works fine.

(venv) user@server:/build/user/CodeChecker/build/CodeChecker$ python3 -m json.tool config/package_layout.json
{
    "runtime": {
        "analyzers": {
            "clangsa": "/build/Projects/A10/LA.UM.8.2/LINUX/android/prebuilts/clang/host/linux-x86/clang-r353983c1/bin/clang",
            "clang-tidy": "/build/Projects/A10/LA.UM.8.2/LINUX/android/prebuilts/clang/host/linux-x86/clang-r353983c1/bin/clang-tidy"
        },
        "clang-apply-replacements": "clang-apply-replacements"
    },
    "ld_lib_path_extra": [],
    "path_env_extra": []
}
gyorb commented 3 years ago

I think the compile_command.json is invalid /tmp/tmpykmqjar0 for some reason. I thought at first that there is a problem in the config file. Could you execute the log phase separately, to check the content of the compile_command.json file?

wizwin commented 3 years ago

@gyorb I tried the following command for log phase, Please correct me if this is wrong: CodeChecker log -b "./cbuild.sh" -o /build/codechecker_full_log.log --verbose debug > full_build_checker_log.log 2>&1

This command generated a logfile /build/codechecker_full_log.log of 62MB

Android full build logs full_build_checker_log.log shows the following statements:

^[[0;32m#### build completed successfully (44:49 (mm:ss)) ####^[[00m

Fri Oct 30 20:57:23 IST 2020
Done SA build...
[INFO][2020-10-30 20:57:23] {buildlogger} [30032] <140673242408768> - build_manager.py:119 perform_build_command() - Build finished successfully.
[DEBUG_ANALYZER][2020-10-30 20:57:23] {buildlogger} [30032] <140673242408768> - build_manager.py:120 perform_build_command() - The logfile is: /build/codechecker_full_log.log
[INFO][2020-10-30 20:57:23] {buildlogger} [30032] <140673242408768> - build_manager.py:132 perform_build_command() - The debug log file is: /build/CodeChecker/codechecker.debug.log

I don't see any evident error messages which I can post here. Maybe this time with only log phase it did not fail with same error?

Also I do not see reports folder having any files for checking compile_command.json

Anything other pointers to check?

gyorb commented 3 years ago

The check command does multiple steps: 1 log the compilation commands and create a compile command database 2 do some compilation command deduplication and uniqueing and execute the analyze command on the compile command database created in the previous step. The unique compilation command json file can be found in the report directory unique_compile_commands.json 3 run the parse command on the reports created in the analyze step

Executing the three commands separately can help to find the problem.

Could you check if the log is a valid json? python3 -m json.tool /build/codechecker_full_log.log I'm still not sure if the compile command database is a valid json file or there is some problem with it. It is worth to check the content of it too to see if there are valid compiler calls.

It everything is ok with the compile command database the analyze command can be executed to see if the analyzers can be configured and started with the compilation commands.

I think it would be worth to go through each step and verify separately which step was successful and where the error occurred.

wizwin commented 3 years ago

@gyorb

  1. Running python3 -m json.tool /build/codechecker_full_log.log. It ran through and spitted out all the commands and exited without telling anything more. Looks like there are no errors here.

  2. Tried to execute a few compilation commands from the log and it executed without any errors. (The code base is building fine and we are still using the same code base mentioned in #2916)

  3. results folder is not created with the log command, however if I run checker it will create the results folder (but not for a full build - This issue). I have to perform a full build first (without CodeChecker) and then trigger one more build (with CodeChecker).

I see when the log is stored in /tmp partition it says it is invalid. Can I ask checker to keep the logs in /tmp after it is done, so that I can run checker and do the same steps above to check it that one is valid?

gyorb commented 3 years ago

@wizwin There is no flag right now to keep the temporary compile command database file. If you remove these two lines, the temporary file should be kept: https://github.com/Ericsson/codechecker/blob/131861b7e94298f58cad883a533814573b89a0f3/analyzer/codechecker_analyzer/cmd/check.py#L842-L843

wizwin commented 3 years ago

I got some time to look at this issue now.

Thank you for the tip @gyorb, I could preserve and analyse the tmp file generated.

(venv) $:/build/Projects/A10/LA.UM.8.2/LINUX/android$ python3 -m json.tool /tmp/tmp2kvaxs4_
Expecting ',' delimiter: line 149956 column 2025 (char 95097758)
(venv) $:/build/Projects/A10/LA.UM.8.2/LINUX/android$

Looks like the JSON is not formed properly and CodeChecker could not proceed after Android full build was completed.

Extracted the following lines from compilation database: (venv) $:/build/Projects/A10/LA.UM.8.2/LINUX/android$ sed -n 149953,149959p /tmp/tmp2kvaxs4_ > JSON_parse_fail.txt

The same file (JSON_parse_fail.txt) is pasted below (as comment) for further analysis.

Looks like it has failed to parse this (column 2025) from the compilation database:

-DSYSCONFDIR=\\\"\\\\\\"/etc/libnl\\\\\\"\\\"
                 ^ Error here at column 2025

Hope this will help you fix this issue.

wizwin commented 3 years ago
    ,
    {
        "directory": "/build/Projects/A10/LA.UM.8.2/LINUX/android",
        "command": "vendor/qcom/proprietary/llvm-arm-toolchain-ship/8.0/bin/clang -c -Wno-enum-compare -Wno-enum-compare-switch -Wno-null-pointer-arithmetic -Wno-null-dereference -Iexternal/libnl/include -Iexternal/libnl/include -Iexternal/libnl/include/linux-private -Iexternal/libnl -Werror=implicit-function-declaration -DANDROID -fmessage-length=0 -W -Wall -Wno-unused -Winit-self -Wpointer-arith -no-canonical-prefixes -DNDEBUG -UDEBUG -DTARGET_Z_COMMON -DTARGET_PLATFORM_H -fno-exceptions -Wno-multichar -O2 -g -fno-strict-aliasing -fdebug-prefix-map=/proc/self/cwd= -D__compiler_offsetof=__builtin_offsetof -faddrsig -Wimplicit-fallthrough -Werror=int-conversion -Wno-reserved-id-macro -Wno-format-pedantic -Wno-unused-command-line-argument -fcolor-diagnostics -Wno-zero-as-null-pointer-constant -Wno-sign-compare -Wno-defaulted-function-deleted -Wno-inconsistent-missing-override -ffunction-sections -fdata-sections -fno-short-enums -funwind-tables -fstack-protector-strong -Wa,--noexecstack -D_FORTIFY_SOURCE=2 -Wstrict-aliasing=2 -Werror=return-type -Werror=non-virtual-dtor -Werror=address -Werror=sequence-point -Werror=date-time -Werror=format-security -nostdlibinc -march=armv8-a -DTARGET_Z_COMMON -DTARGET_PLATFORM_H -Iexternal/libcxx/include -Iexternal/libcxxabi/include -Ibionic/libc/include -D__LIBC_API__=10000 -D__LIBM_API__=10000 -D__LIBDL_API__=10000 -Isystem/core/include -Isystem/media/audio/include -Ihardware/libhardware/include -Ihardware/libhardware_legacy/include -Ihardware/ril/include -Iframeworks/native/include -Iframeworks/native/opengl/include -Iframeworks/av/include -isystem bionic/libc/include -isystem bionic/libc/kernel/uapi -isystem bionic/libc/kernel/uapi/asm-arm64 -isystem bionic/libc/kernel/android/scsi -isystem bionic/libc/kernel/android/uapi -Ilibnativehelper/include_jni -D_BSD_SOURCE -Wall -Werror -Wno-unused-parameter -Wno-sign-compare -Wno-missing-field-initializers -Wno-tautological-compare -Wno-pointer-arith -UNDEBUG -D_GNU_SOURCE -DSYSCONFDIR=\\\"\\\\\\"/etc/libnl\\\\\\"\\\" -target aarch64-linux-android -Bprebuilts/gcc/linux-x86/aarch64/aarch64-linux-android-4.9/aarch64-linux-android/bin -fPIC -D_USING_LIBCXX -fsanitize-blacklist=build/soong/cc/config/integer_overflow_blacklist.txt -fsanitize=unsigned-integer-overflow,signed-integer-overflow -fsanitize-trap=all -ftrap-function=abort -fsanitize-minimal-runtime -fno-sanitize-trap=integer,undefined -fno-sanitize-recover=integer,undefined -fno-sanitize=implicit-integer-sign-change -std=gnu99 -Werror=int-to-pointer-cast -Werror=pointer-to-int-cast -Werror=address-of-temporary -Werror=return-type -Wno-tautological-constant-compare -Wno-tautological-type-limit-compare -Wno-tautological-unsigned-enum-zero-compare -Wno-tautological-unsigned-zero-compare -Wno-c++98-compat-extra-semi -Wno-return-std-move-in-c++11 -MD -MF out/soong/.intermediates/external/libnl/libnl/android_arm64_armv8-a_core_static/obj/external/libnl/lib/cache.o.d -o out/soong/.intermediates/external/libnl/libnl/android_arm64_armv8-a_core_static/obj/external/libnl/lib/cache.o external/libnl/lib/cache.c",
        "file": "external/libnl/lib/cache.c"
    }
    ,

@gyorb

wizwin commented 3 years ago

@gyorb @whisperity Any quick fix which I can try out?

wizwin commented 3 years ago

@gyorb @whisperity Please check out this parsing error. This will really help us run CodeChecker on several Android desserts.

csordasmarton commented 3 years ago

@wizwin Could you please try out this patch: https://github.com/Ericsson/codechecker/pull/3169. Maybe it will solve your problem too.

wizwin commented 3 years ago

@csordasmarton

I tried this out:

1. After pulling the latest code:

CodeChecker analyzer version:
---------------------------------------------------------------
Kind                 | Version
---------------------------------------------------------------
Base package version | 6.16.0
Package build date   | 2021-02-04T18:53
Git commit ID (hash) | 6626d77afa5807b800ca70e084a2933c110f66b4
Git tag information  | 6.16
---------------------------------------------------------------

CodeChecker web version:
------------------------------------------------------------------------
Kind                          | Version
------------------------------------------------------------------------
Base package version          | 6.16.0
Package build date            | 2021-02-04T18:53
Git commit ID (hash)          | 6626d77afa5807b800ca70e084a2933c110f66b4
Git tag information           | 6.16
Server supported API (Thrift) | 6.39
Client API (Thrift)           | 6.39
------------------------------------------------------------------------

2. Enabled the new escape logic: export CC_LOGGER_NEW_ESCAPING=true

3. Got the following error with checker on A10 full build:

357393 [DEBUG][2021-02-07 02:58:29] {buildlogger} [15046] <139682365347648> - log_parser.py:384 get_compiler_includes() - Retrieving default includes via 'prebuilts/clang/host/linux-x86/clang-3289846/bin/clang -std=c99 -E -x c++ - -v '

357394 [ERROR][2021-02-07 02:58:30] {buildlogger} [15046] <139682365347648> - log_parser.py:1370 parse_unique_log() - The compile database is not valid.

357395 [DEBUG][2021-02-07 02:58:30] {buildlogger} [15046] <139682365347648> - log_parser.py:1371 parse_unique_log() - Traceback (most recent call last):
357396   File "/build/CodeChecker/build/CodeChecker/lib/python3/codechecker_analyzer/buildlog/log_parser.py", line 1318, in parse_unique_log
357397     if action.__hash__ not in uniqued_build_actions:
357398   File "/build/CodeChecker/build/CodeChecker/lib/python3/codechecker_analyzer/buildlog/build_action.py", line 78, in __hash__
357399     return hash(''.join(hash_content))
357400 TypeError: sequence item 15: expected str instance, dict found
357401
357402 [DEBUG][2021-02-07 02:58:30] {buildlogger} [15046] <139682365347648> - log_parser.py:1372 parse_unique_log() - sequence item 15: expected str instance, dict found
csordasmarton commented 3 years ago

@wizwin Could you please print the hash_content variable before this line: https://github.com/Ericsson/codechecker/blob/6626d77afa5807b800ca70e084a2933c110f66b4/analyzer/codechecker_analyzer/buildlog/build_action.py#L78 Just insert the following code above this line: print(hash_content)

wizwin commented 3 years ago

@csordasmarton

Output of print(hash_content) where the error occurs:

['-I/build/Projects/A10/LA.UM.8.2/LINUX/android/frameworks/rs/script_api/include', '-MD', '-DRS_VERSION=24', '-std=c99', '-O3', '-fno-builtin', '-emit-llvm', '-fsigned-char', '-Wno-deprecated', '-Wall', '-Wextra', '-I/build/Projects/A10/LA.UM.8.2/LINUX/android/frameworks/rs/cpu_ref', '-DRS_DECLARE_EXPIRED_APIS', '-DARCH_ARM64_HAVE_NEON', '-1', {}, '/build/Projects/A10/LA.UM.8.2/LINUX/android/frameworks/rs/driver/runtime/rs_allocation.c']

Output of print(hash_content) where the error does not occur (truncated for example):

... ... ... '-MD', '-1', 'x86_64-linux-gnu', '/build/Projects/A10/LA.UM.8.2/LINUX/android/system/core/liblog/logger_read.cpp']

csordasmarton commented 3 years ago

It looks like the target value is a dictionary but I don't know the reason why. Could you please try to debug this? We can start and print the target value at the beginning and at the end of this function (print("BEFORE", details['target']) / print("AFTER", details['target'])): https://github.com/Ericsson/codechecker/blob/6626d77afa5807b800ca70e084a2933c110f66b4/analyzer/codechecker_analyzer/buildlog/log_parser.py#L537

wizwin commented 3 years ago

@csordasmarton

I added logs for BEFORE and AFTER (C and C++):

358658 BEFORE defaultdict(<class 'dict'>, {'c': 'renderscript64-linux-android'})
358659 [DEBUG][2021-02-09 01:58:41] {buildlogger} [12329] <140489042704192> - log_parser.py:384 get_compiler_includes() - Retrieving default includes via 'prebuilts/clang/host/linux-x86/clang-3289846/bin/clang -std=c99 -E -x c - -v '
358660 AFTER C defaultdict(<class 'dict'>, {'c': 'renderscript64-linux-android'})
358661 [DEBUG][2021-02-09 01:58:41] {buildlogger} [12329] <140489042704192> - log_parser.py:384 get_compiler_includes() - Retrieving default includes via 'prebuilts/clang/host/linux-x86/clang-3289846/bin/clang -std=c99 -E -x c++ - -v '
358662 AFTER C++ defaultdict(<class 'dict'>, {'c': 'renderscript64-linux-android'})
358663 ['-I/build/Projects/A10/LA.UM.8.2/LINUX/android/frameworks/rs/script_api/include', '-MD', '-DRS_VERSION=24', '-std=c99', '-O3', '-fno-builtin', '-emit-llvm', '-fsigned-char', '-Wno-deprecated', '-Wall', '-Wextra', '-I/build/Projects/A10/LA.UM.8.2/LINUX/android/frameworks/rs/cpu_ref', '-DRS_DECLARE_EXPIRED_APIS', '-DARCH_ARM64_HAVE_NEON', '-1', {}, '/build/Projects/A10/LA.UM.8.2/LINUX/android/frameworks/rs/driver/runtime/rs_allocation.c']
csordasmarton commented 3 years ago

I have created a patch: #3184. Can you please try out whether it solves your problem?

wizwin commented 3 years ago

@csordasmarton - Success!! The above patch works for me.

Checker finally completed analysis after 12 days and 20 hours for generating 100000 reports in A10! This would be the longest duration build command I have ever used :)

I had mentioned regarding the time taken for analysis in Additional Notes, that was for the incremental builds (for 11000 reports) which was quite long.

Please let me know if there is any way to speed this up. Do we need to track using a ticket or is this already known?

csordasmarton commented 3 years ago

@wizwin uh, thats a really-really long analysis.

How is your CodeChecker analyze command looks like?

By the way I can see two reasons why the analysis takes so much time:

wizwin commented 3 years ago

Wrongly quoted:

@gyorb I tried the following command for log phase, Please correct me if this is wrong: CodeChecker log -b "./cbuild.sh" -o /build/codechecker_full_log.log --verbose debug > full_build_checker_log.log 2>&1

Correct command: CodeChecker check -b "./cbuild.sh" -o /build/results​ --verbose debug 2>&1 > full_build_check.log

@csordasmarton I am using the same command with the additional print statements added since we were debugging this issue. I left it on the server and came back today as it was taking forever to complete.

Let me try without --verbose debug and also try out your suggestions.

csordasmarton commented 3 years ago

@wizwin In you previous comment you talked about analysis and reports. You said that the analysis took ~13 days. The CodeChecker log command doesn't do analysis, it will just catches the compiler calls on your host and creates a compilation database: /build/codechecker_full_log.log (for this I recommend to use a better name like: compilation_database.json or build.json) So is the CodeChecker log command takes you so much time?

wizwin commented 3 years ago

@csordasmarton - Sorry, I quoted the wrong command. Update my previous comment.

csordasmarton commented 3 years ago

Ah, you are using the CodeChecker check command. Actucally it will call the CodeChecker log -> CodeChecker analyze -> CodeChecker parse commands. In our case it would be better to run these commands separately and measure the time of each commands:

# Log the project.
time CodeChecker log -b "./cbuild.sh" -o ./compilation_database.json

# Do the analysis.
time CodeChecker analyze ./compilation_database.json -o ./reports

# Print out the reports.
time CodeChecker parse ./reports

Also I am curious how many translation units do you have. Could you please run the following command on your compilation database: grep "{" ./compilation_database.json | wc -l. You can run this command immediatelly after the CodeChecker log command.

csordasmarton commented 3 years ago

@wizwin Also, one more thing. Both the CodeChecker check and the CodeChecker analyze commands has an option to run the analysis on multiple threads:

  -j JOBS, --jobs JOBS  Number of threads to use in analysis. More threads
                        mean faster analysis at the cost of using more memory.
                        (default: 1)

By default it is set to 1. You can try to increase it to a higher value. That will definitely speed up the analysis.

wizwin commented 3 years ago

@csordasmarton I think we can close this ticket with the patch you provided. I will open a new ticket with data on analysis/checker speed after running these commands.

Thank you for your support! @bruntib @csordasmarton @whisperity