From 2a225fbc02334d9dfab68e047eb9de364ab3a60e Mon Sep 17 00:00:00 2001 From: Lukas Petr Date: Sun, 11 Jan 2026 18:15:23 +0100 Subject: [PATCH] build-kernel: Add logging for debugging issues Sometimes when running `diffkemp build-kernel` command to build snapshots of a kernel, the `build-kernel` can be unable to compile the source files of functions to LLVM IR. In these cases the output contains the following: ``` : source not found ``` This information is not enough to find the reason why the compilation failed and manual debugging is necessary. For this reason, this commit introduces logging for `diffkemp build-kernel` command to speed up the debugging process by logging certain informations. For logging is used python logging module [1]. The detail of logging is based on how DiffKemp is run: - `diffkemp build-kernel`: Logs error messages (not used right now), - `diffkemp -v build-kernel`: Logs warning messages (not used right now), - `diffkemp -d build-kernel`: Logs information messages (not used right now), - `diffkemp -dd build-kernel`: Logs debug messages (used in this commit). The level of logging detail is created for a future use and to be partly consistent with `diffkemp compare` command. When running `diffkemp build-kernel` command for: - `__bpf_get_stackid` function - on repo [2] - on commit `e17d62fedd10ae56e2426858bd0757da544dbc73` the previous output was (and current without `-dd` option is): ``` __bpf_get_stackid: source not found ``` when the `-dd` option is provided, the following can be extracted from the output (which helps to solve the problem). ``` In file included from ./include/linux/nodemask.h:94: ./include/linux/random.h:24:39: error: use of undeclared identifier 'latent_entropy'; did you mean 'add_latent_entropy'? 24 | add_device_randomness((const void *)&latent_entropy, sizeof(latent_entropy)); | ^~~~~~~~~~~~~~ | add_latent_entropy ./include/linux/random.h:21:20: note: 'add_latent_entropy' declared here 21 | static inline void add_latent_entropy(void) | ^ ./include/linux/random.h:24:62: error: use of undeclared identifier 'latent_entropy'; did you mean 'add_latent_entropy'? 24 | add_device_randomness((const void *)&latent_entropy, sizeof(latent_entropy)); | ^~~~~~~~~~~~~~ | add_latent_entropy ./include/linux/random.h:21:20: note: 'add_latent_entropy' declared here 21 | static inline void add_latent_entropy(void) | ^ ``` [1] https://docs.python.org/3/library/logging.html [2] https://git.kernel.org/pub/scm/linux/kernel/git/bpf/bpf-next.git --- diffkemp/building/build_kernel.py | 4 +- .../llvm_ir/kernel_llvm_source_builder.py | 44 ++++++++++++------- diffkemp/utils.py | 13 ++++++ 3 files changed, 45 insertions(+), 16 deletions(-) diff --git a/diffkemp/building/build_kernel.py b/diffkemp/building/build_kernel.py index 218742e41..31ed8111e 100644 --- a/diffkemp/building/build_kernel.py +++ b/diffkemp/building/build_kernel.py @@ -6,12 +6,13 @@ generate_from_function_list, read_symbol_list, EMSG_EMPTY_SYMBOL_LIST) +from diffkemp.utils import init_logger import errno import os import sys -def build_kernel(args): +def build_kernel(args) -> None: """ Create snapshot of a Linux kernel source tree. Kernel sources are compiled into LLVM IR on-the-fly as necessary. @@ -19,6 +20,7 @@ def build_kernel(args): - list of functions (default) - list of sysctl options """ + init_logger(args.verbose) # Create a new snapshot from the kernel source directory. snapshot = _generate_snapshot(args) diff --git a/diffkemp/llvm_ir/kernel_llvm_source_builder.py b/diffkemp/llvm_ir/kernel_llvm_source_builder.py index 6999ff751..b9e8df216 100644 --- a/diffkemp/llvm_ir/kernel_llvm_source_builder.py +++ b/diffkemp/llvm_ir/kernel_llvm_source_builder.py @@ -6,11 +6,15 @@ from diffkemp.llvm_ir.llvm_source_finder import LlvmSourceFinder, \ SourceNotFoundException from diffkemp.llvm_ir.optimiser import opt_llvm, BuildException +import logging import os import shutil -from subprocess import check_call, check_output, CalledProcessError +from subprocess import (check_call, check_output, CalledProcessError, run, + DEVNULL, PIPE) import subprocess +logger = logging.getLogger(__package__) + class KernelLlvmSourceBuilder(LlvmSourceFinder): """ @@ -489,7 +493,7 @@ def _get_build_source(command): """Get name of the object file built by the command.""" return command[command.index("-c") + 1] - def _kbuild_object_command(self, object_file): + def _kbuild_object_command(self, object_file: str) -> str: """ Check which command would be run by KBuild to build the given object file. @@ -502,11 +506,14 @@ def _kbuild_object_command(self, object_file): self._clean_object(object_file) with open(os.devnull, "w") as stderr: try: - output = check_output( - ["make", "V=1", - "CFLAGS=-w", "EXTRA_CFLAGS=-w", - object_file, - "--just-print"], stderr=stderr).decode("utf-8") + command = [ + "make", "V=1", + "CFLAGS=-w", "EXTRA_CFLAGS=-w", + object_file, + "--just-print", + ] + logger.debug(f"Running command: {command}") + output = check_output(command, stderr=stderr).decode("utf-8") except CalledProcessError: raise BuildException("Error compiling {}".format(object_file)) finally: @@ -560,7 +567,7 @@ def _kbuild_module_commands(self, mod_dir, mod_name): os.chdir(cwd) raise BuildException("Could not build module {}".format(mod_name)) - def _build_source_to_llvm(self, source_file): + def _build_source_to_llvm(self, source_file: str) -> str: """ Build C source file into LLVM IR. Gets the Kbuild command that is used for building an object file, @@ -578,16 +585,23 @@ def _build_source_to_llvm(self, source_file): try: # Get GCC command for building the .o file command = self._kbuild_object_command("{}.o".format(name)) + logger.debug("Extracted gcc command") # Convert the GCC command to a corresponding Clang command command = self._gcc_to_llvm(command) + logger.debug("Translated gcc command to llvm") # Run the Clang command - with open(os.devnull, "w") as stderr: - try: - check_call(command, stderr=stderr) - except CalledProcessError: - os.chdir(cwd) - raise BuildException( - "Could not build {}".format(llvm_file)) + try: + logger.debug(f"Running clang: {command}") + run(command, check=True, text=True, + stdout=DEVNULL, stderr=PIPE) + except CalledProcessError as e: + os.chdir(cwd) + logger.debug( + f"Could not build {source_file} to {llvm_file}:\n" + f"{e.stderr}" + ) + raise BuildException( + "Could not build {}".format(llvm_file)) # Run opt with selected optimisations opt_llvm(llvm_file) except BuildException: diff --git a/diffkemp/utils.py b/diffkemp/utils.py index bd04a442b..73585d07f 100644 --- a/diffkemp/utils.py +++ b/diffkemp/utils.py @@ -1,3 +1,4 @@ +import logging import os import subprocess import re @@ -8,6 +9,18 @@ CMP_OUTPUT_FILE = "diffkemp-out.yaml" +def init_logger(verbose_level: int) -> None: + """Initialise logger.""" + logger_map = { + 0: logging.ERROR, + 1: logging.WARNING, + 2: logging.INFO, + 3: logging.DEBUG, + } + logger_level = logger_map.get(verbose_level, logging.DEBUG) + logging.basicConfig(level=logger_level) + + def get_simpll_build_dir(): """ Return the current SimpLL build directory as specified