Merge remote-tracking branch 'bits/revive-qemu-logs' into dev

This commit is contained in:
mio 2024-09-21 22:09:07 +08:00
commit 80f0898740
No known key found for this signature in database
GPG Key ID: DFF27E34A47CB873
3 changed files with 273 additions and 16 deletions

View File

@ -123,6 +123,76 @@ Therefore, if you still prefer the previous `paddr = vaddr` simple mapping, we h
In theory, `UC_TLB_VIRTUAL` will achieve better performance as it skips all MMU details, though not benchmarked.
## Something is wrong - I would like to dig deeper
Unicorn uses at several places logging by the qemu implementation.
This might provide a first glance what could be wrong.
The logs contains optionally the filename and the line number including
additional messages to indicate what is happening.
However, the qemu logs are partially commented-out and incomplete, but give it a try.
You might want to dig deeper - and add your own log messages where you expect or try to find the bug.
See the `unicorn/qemu/include/qemu/log.h` file for details.
To enable logs, you must recompile Unicorn with the enabled `LOGGING_ENABLED` define.
Logs are written in different log levels, which might result into a very verbose logging if enabled.
To control the log level information, two environment variables could be used.
`UNICORN_LOG_LEVEL` and `UNICORN_LOG_DETAIL_LEVEL`.
These environment variables are parsed into `uint32_t` values once, (due to performance reasons)
so set these environment variables before you execute any line of Unicorn.
Allowed are hexa-decimal, decimal and octal values, which fits into a buffer of 10 chars. (see stroul for details).
To define how detailed and what should be logged, use the following environment variables:
- `UNICORN_LOG_LEVEL`=\<32bit mask\>
- The qemu bit mask what should be logged.
- Use the value of `UINT32_MAX` to log everything.
- If no bit is set in the mask, there will be no logging.
- `UNICORN_LOG_DETAIL_LEVEL`=\<level\>
- The level defines how the filename and line is constructed.
- 0: no filename and no line is used.
- 1: full filename including the leading path is used with line information.
- 2: just the filename with line information. It might be a little confusing,
as the file name can be used in several places.
- If unsure or unwanted, leave this variable undefined or set it to 0.
As an example to set up the environment for python correctly, see the example below.
```python
import os
os.environ['UNICORN_LOG_LEVEL'] = "0xFFFFFFFF" # verbose - print anything
os.environ['UNICORN_LOG_DETAIL_LEVEL'] = "1" # full filename with line info
```
Please note that file names are statically compiled in and can reveal the paths
of the file system used during compilation.
## My code does not do what I would expect - is this a bug?
Please create an github issue and provide as much details as possible.
- [ ] Simplified version of your script / source
- Make sure that "no" external dependencies are needed.
- E.g. remove additional use of capstone or CTF tools.
- [ ] Used Unicorn git-hash commit
- Make sure to exclude any changes of you made in unicorn.
- Alternativily provide the repo link to your commit.
- [ ] Detailed explaination what is expected
- Try to verify if the instructions can be processed by qemu.
- Dumping the registers of unicorn and qemu helps a lot.
- [ ] Detailed explaination what is observed
- Describe what's going on (and what you might think about it).
- [ ] Output from your executed script
- You might have additional log messages which could be helpful.
- [ ] Output from the qemu-logs
- Try to gather more informations by enabling the qemu logging.
- [ ] More details
- Attach more details to help reproduce the bug.
- Like attaching a repo link to the CTF challenge containing the binary or source code.
## I'd like to make contributions, where do I start?
See [milestones](https://github.com/unicorn-engine/unicorn/milestones) and [coding convention](https://github.com/unicorn-engine/unicorn/wiki/Coding-Convention

View File

@ -30,20 +30,207 @@
/* Logging functions: */
/* log only if a bit is set on the current loglevel mask:
* @mask: bit to check in the mask
* @fmt: printf-style format string
* @args: optional arguments for format string
*/
#define qemu_log_mask(MASK, FMT, ...)
/* To verbose logging, enable the next line. */
//#define LOGGING_ENABLED // to enable logging
/* log only if a bit is set on the current loglevel mask
* and we are in the address range we care about:
* @mask: bit to check in the mask
* @addr: address to check in dfilter
* @fmt: printf-style format string
* @args: optional arguments for format string
*/
#define qemu_log_mask_and_addr(MASK, ADDR, FMT, ...)
#ifdef LOGGING_ENABLED
#include <stdint.h>
#include <string.h>
#include <stdlib.h>
#include <stdarg.h>
#include <stdio.h>
/**
* Reads the @p env_name and tries to parse the value into an uint32_t.
* @param env_name The environment variable name to parse.
* @return The parsed value.
** 0 in case if the value can not be parsed (or is 0).
** ULONG_MAX if the value is bigger than an uint32_t.
*/
static inline uint32_t read_and_parse_env(const char* env_name)
{
uint32_t data = 0;
const char* env_data = getenv(env_name);
if (env_data != NULL) {
char buffer[11] = {0}; // 0xFFFF'FFFF\0
strncpy(buffer, env_data, sizeof(buffer) - 1);
data = (uint32_t)strtoul(buffer, NULL, 0);
}
return data;
}
/**
* Gets the log level by reading it once.
* @return The log level.
*/
static inline uint32_t get_log_level()
{
static uint64_t log_level = UINT64_MAX;
if (log_level == UINT64_MAX) {
log_level = read_and_parse_env("UNICORN_LOG_LEVEL");
}
return (uint32_t)log_level;
}
/**
* Gets the log detail level by reading it once.
* @return The detail log level.
*/
static inline uint32_t get_log_detail_level()
{
static uint64_t log_detail_level = UINT64_MAX;
if (log_detail_level == UINT64_MAX) {
log_detail_level = read_and_parse_env("UNICORN_LOG_DETAIL_LEVEL");
}
return (uint32_t)log_detail_level;
}
/**
* Checks if the @p log_level is active.
* @param log_level The log level to be checked.
* @return True if the log level is active.
*/
static inline bool is_log_level_active(uint32_t log_level)
{
const uint32_t active_log_level = get_log_level();
const bool is_active = (active_log_level & log_level) == log_level;
return is_active;
}
/**
* Checks if the logging is enabled.
* @return True if enabled, else false.
*/
static inline bool is_logging_enabled()
{
const bool log_level = get_log_level();
return log_level != 0;
}
/**
* Gets the filename of the caller on given @p detail_level.
* @param filename The filename to process on.
* @param detail_level The level of detail of the filename.
** 0: Returns an empty string.
** 1: Returns the full filename including it's path.
** 2: Returns just the filename (to shorten the log).
* @return always an valid null-terminated string. Do NOT free it.
*/
static inline const char* const get_detailed_filename(const char* filename,
int detail_level)
{
filename = (filename != NULL) ? filename : "";
const char* resulting_filename = filename;
#if (defined(WIN32) || defined(WIN64) || defined(_WIN32) || defined(_WIN64))
const char path_separator = '\\';
#else
const char path_separator = '/';
#endif
switch (detail_level) {
default:
case 0:
resulting_filename = "";
break;
case 1:
resulting_filename = filename;
break;
case 2:
resulting_filename = strrchr(filename, path_separator);
if (resulting_filename == NULL) {
resulting_filename = filename;
}
else {
++resulting_filename;
}
break;
}
return resulting_filename;
}
/**
* Prints the formatted log message with details if enabled.
* @param mask The log mask to log on.
* @param filename The filename of the caller.
* @param line The line number of the caller.
* @param fmt Printf-style format string.
* @param args optional arguments for the format string.
*/
static inline void print_log(uint32_t mask, const char* filename, uint32_t line, const char* fmt, ...)
{
if ((mask & get_log_level()) == 0) {
return;
}
const uint32_t log_detail_level = get_log_detail_level();
if (log_detail_level > 0) {
const char* detailed_filename = get_detailed_filename(filename, log_detail_level);
printf("[%s:%u] ", detailed_filename, line);
}
va_list argptr;
va_start(argptr, fmt);
vfprintf(stdout, fmt, argptr);
va_end(argptr);
}
/**
* Logs only if the right log level is set.
* @param mask The log mask to log on.
* @param fmt Printf-style format string.
* @param args optional arguments for the format string.
*/
#define LOG_MESSAGE(mask, fmt, ...) \
do { \
print_log(mask, __FILE__, __LINE__, fmt, ## __VA_ARGS__); \
} while (0)
#else
#define LOG_MESSAGE(mask, fmt, ...)
/**
* Dummy implementation which returns always false.
* @return Always false.
*/
static inline bool is_logging_enabled()
{
return false;
}
/**
* Dummy implementation which returns always false.
* @param level The log level to be checked.
* @return Always false.
*/
static inline bool is_log_level_active(uint32_t level)
{
(void)level;
return false;
}
#endif /* LOGGING_ENABLED */
/**
* Logs only if the right log level is set.
* @param mask The log mask to log on.
* @param fmt Printf-style format string.
* @param args Optional arguments for the format string.
*/
#define qemu_log_mask(mask, fmt, ...) \
LOG_MESSAGE(mask, fmt, ## __VA_ARGS__)
#endif /* QEMU_LOG_H */

View File

@ -3728,7 +3728,7 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
TCGOp *op;
#ifndef NDEBUG
if (getenv("UNICORN_DEBUG")) {
if (is_log_level_active(CPU_LOG_TB_IN_ASM)) {
tcg_dump_ops(s, false, "TCG before optimization:");
}
#endif
@ -3777,7 +3777,7 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
#endif
#ifndef NDEBUG
if (getenv("UNICORN_DEBUG")) {
if (is_log_level_active(CPU_LOG_TB_IN_ASM)) {
tcg_dump_ops(s, false, "TCG before codegen:");
}
#endif