Skip to content

Commit 80f0898

Browse files
wtdcodewtdcode
committed
Merge remote-tracking branch 'bits/revive-qemu-logs' into dev
2 parents 920d076 + 6670841 commit 80f0898

File tree

3 files changed

+271
-14
lines changed

3 files changed

+271
-14
lines changed

‎docs/FAQ.md

+70
Original file line numberDiff line numberDiff line change
@@ -123,6 +123,76 @@ Therefore, if you still prefer the previous `paddr = vaddr` simple mapping, we h
123123

124124
In theory, `UC_TLB_VIRTUAL` will achieve better performance as it skips all MMU details, though not benchmarked.
125125

126+
## Something is wrong - I would like to dig deeper
127+
128+
Unicorn uses at several places logging by the qemu implementation.
129+
This might provide a first glance what could be wrong.
130+
131+
The logs contains optionally the filename and the line number including
132+
additional messages to indicate what is happening.
133+
However, the qemu logs are partially commented-out and incomplete, but give it a try.
134+
You might want to dig deeper - and add your own log messages where you expect or try to find the bug.
135+
136+
See the `unicorn/qemu/include/qemu/log.h` file for details.
137+
To enable logs, you must recompile Unicorn with the enabled `LOGGING_ENABLED` define.
138+
139+
Logs are written in different log levels, which might result into a very verbose logging if enabled.
140+
To control the log level information, two environment variables could be used.
141+
142+
`UNICORN_LOG_LEVEL` and `UNICORN_LOG_DETAIL_LEVEL`.
143+
144+
These environment variables are parsed into `uint32_t` values once, (due to performance reasons)
145+
so set these environment variables before you execute any line of Unicorn.
146+
Allowed are hexa-decimal, decimal and octal values, which fits into a buffer of 10 chars. (see stroul for details).
147+
148+
To define how detailed and what should be logged, use the following environment variables:
149+
150+
- `UNICORN_LOG_LEVEL`=\<32bit mask\>
151+
- The qemu bit mask what should be logged.
152+
- Use the value of `UINT32_MAX` to log everything.
153+
- If no bit is set in the mask, there will be no logging.
154+
- `UNICORN_LOG_DETAIL_LEVEL`=\<level\>
155+
- The level defines how the filename and line is constructed.
156+
- 0: no filename and no line is used.
157+
- 1: full filename including the leading path is used with line information.
158+
- 2: just the filename with line information. It might be a little confusing,
159+
as the file name can be used in several places.
160+
- If unsure or unwanted, leave this variable undefined or set it to 0.
161+
162+
As an example to set up the environment for python correctly, see the example below.
163+
164+
```python
165+
import os
166+
os.environ['UNICORN_LOG_LEVEL'] = "0xFFFFFFFF" # verbose - print anything
167+
os.environ['UNICORN_LOG_DETAIL_LEVEL'] = "1" # full filename with line info
168+
```
169+
170+
Please note that file names are statically compiled in and can reveal the paths
171+
of the file system used during compilation.
172+
173+
## My code does not do what I would expect - is this a bug?
174+
175+
Please create an github issue and provide as much details as possible.
176+
177+
- [ ] Simplified version of your script / source
178+
- Make sure that "no" external dependencies are needed.
179+
- E.g. remove additional use of capstone or CTF tools.
180+
- [ ] Used Unicorn git-hash commit
181+
- Make sure to exclude any changes of you made in unicorn.
182+
- Alternativily provide the repo link to your commit.
183+
- [ ] Detailed explaination what is expected
184+
- Try to verify if the instructions can be processed by qemu.
185+
- Dumping the registers of unicorn and qemu helps a lot.
186+
- [ ] Detailed explaination what is observed
187+
- Describe what's going on (and what you might think about it).
188+
- [ ] Output from your executed script
189+
- You might have additional log messages which could be helpful.
190+
- [ ] Output from the qemu-logs
191+
- Try to gather more informations by enabling the qemu logging.
192+
- [ ] More details
193+
- Attach more details to help reproduce the bug.
194+
- Like attaching a repo link to the CTF challenge containing the binary or source code.
195+
126196
## I'd like to make contributions, where do I start?
127197

128198
See [milestones](https://github.com/unicorn-engine/unicorn/milestones) and [coding convention](https://github.com/unicorn-engine/unicorn/wiki/Coding-Convention

‎qemu/include/qemu/log.h

+199-12
Original file line numberDiff line numberDiff line change
@@ -30,20 +30,207 @@
3030

3131
/* Logging functions: */
3232

33-
/* log only if a bit is set on the current loglevel mask:
34-
* @mask: bit to check in the mask
35-
* @fmt: printf-style format string
36-
* @args: optional arguments for format string
33+
/* To verbose logging, enable the next line. */
34+
//#define LOGGING_ENABLED // to enable logging
35+
36+
#ifdef LOGGING_ENABLED
37+
38+
#include <stdint.h>
39+
#include <string.h>
40+
#include <stdlib.h>
41+
#include <stdarg.h>
42+
#include <stdio.h>
43+
44+
/**
45+
* Reads the @p env_name and tries to parse the value into an uint32_t.
46+
* @param env_name The environment variable name to parse.
47+
* @return The parsed value.
48+
** 0 in case if the value can not be parsed (or is 0).
49+
** ULONG_MAX if the value is bigger than an uint32_t.
50+
*/
51+
static inline uint32_t read_and_parse_env(const char* env_name)
52+
{
53+
uint32_t data = 0;
54+
const char* env_data = getenv(env_name);
55+
56+
if (env_data != NULL) {
57+
char buffer[11] = {0}; // 0xFFFF'FFFF\0
58+
strncpy(buffer, env_data, sizeof(buffer) - 1);
59+
data = (uint32_t)strtoul(buffer, NULL, 0);
60+
}
61+
62+
return data;
63+
}
64+
65+
/**
66+
* Gets the log level by reading it once.
67+
* @return The log level.
68+
*/
69+
static inline uint32_t get_log_level()
70+
{
71+
static uint64_t log_level = UINT64_MAX;
72+
73+
if (log_level == UINT64_MAX) {
74+
log_level = read_and_parse_env("UNICORN_LOG_LEVEL");
75+
}
76+
77+
return (uint32_t)log_level;
78+
}
79+
80+
/**
81+
* Gets the log detail level by reading it once.
82+
* @return The detail log level.
83+
*/
84+
static inline uint32_t get_log_detail_level()
85+
{
86+
static uint64_t log_detail_level = UINT64_MAX;
87+
88+
if (log_detail_level == UINT64_MAX) {
89+
log_detail_level = read_and_parse_env("UNICORN_LOG_DETAIL_LEVEL");
90+
}
91+
92+
return (uint32_t)log_detail_level;
93+
}
94+
95+
/**
96+
* Checks if the @p log_level is active.
97+
* @param log_level The log level to be checked.
98+
* @return True if the log level is active.
3799
*/
38-
#define qemu_log_mask(MASK, FMT, ...)
100+
static inline bool is_log_level_active(uint32_t log_level)
101+
{
102+
const uint32_t active_log_level = get_log_level();
103+
const bool is_active = (active_log_level & log_level) == log_level;
39104

40-
/* log only if a bit is set on the current loglevel mask
41-
* and we are in the address range we care about:
42-
* @mask: bit to check in the mask
43-
* @addr: address to check in dfilter
44-
* @fmt: printf-style format string
45-
* @args: optional arguments for format string
105+
return is_active;
106+
}
107+
108+
/**
109+
* Checks if the logging is enabled.
110+
* @return True if enabled, else false.
46111
*/
47-
#define qemu_log_mask_and_addr(MASK, ADDR, FMT, ...)
112+
static inline bool is_logging_enabled()
113+
{
114+
const bool log_level = get_log_level();
115+
116+
return log_level != 0;
117+
}
48118

119+
/**
120+
* Gets the filename of the caller on given @p detail_level.
121+
* @param filename The filename to process on.
122+
* @param detail_level The level of detail of the filename.
123+
** 0: Returns an empty string.
124+
** 1: Returns the full filename including it's path.
125+
** 2: Returns just the filename (to shorten the log).
126+
* @return always an valid null-terminated string. Do NOT free it.
127+
*/
128+
static inline const char* const get_detailed_filename(const char* filename,
129+
int detail_level)
130+
{
131+
filename = (filename != NULL) ? filename : "";
132+
const char* resulting_filename = filename;
133+
134+
#if (defined(WIN32) || defined(WIN64) || defined(_WIN32) || defined(_WIN64))
135+
const char path_separator = '\\';
136+
#else
137+
const char path_separator = '/';
49138
#endif
139+
140+
switch (detail_level) {
141+
default:
142+
case 0:
143+
resulting_filename = "";
144+
break;
145+
case 1:
146+
resulting_filename = filename;
147+
break;
148+
case 2:
149+
resulting_filename = strrchr(filename, path_separator);
150+
151+
if (resulting_filename == NULL) {
152+
resulting_filename = filename;
153+
}
154+
else {
155+
++resulting_filename;
156+
}
157+
158+
break;
159+
}
160+
161+
return resulting_filename;
162+
}
163+
164+
/**
165+
* Prints the formatted log message with details if enabled.
166+
* @param mask The log mask to log on.
167+
* @param filename The filename of the caller.
168+
* @param line The line number of the caller.
169+
* @param fmt Printf-style format string.
170+
* @param args optional arguments for the format string.
171+
*/
172+
static inline void print_log(uint32_t mask, const char* filename, uint32_t line, const char* fmt, ...)
173+
{
174+
if ((mask & get_log_level()) == 0) {
175+
return;
176+
}
177+
178+
const uint32_t log_detail_level = get_log_detail_level();
179+
180+
if (log_detail_level > 0) {
181+
const char* detailed_filename = get_detailed_filename(filename, log_detail_level);
182+
printf("[%s:%u] ", detailed_filename, line);
183+
}
184+
185+
va_list argptr;
186+
187+
va_start(argptr, fmt);
188+
vfprintf(stdout, fmt, argptr);
189+
va_end(argptr);
190+
}
191+
192+
/**
193+
* Logs only if the right log level is set.
194+
* @param mask The log mask to log on.
195+
* @param fmt Printf-style format string.
196+
* @param args optional arguments for the format string.
197+
*/
198+
#define LOG_MESSAGE(mask, fmt, ...) \
199+
do { \
200+
print_log(mask, __FILE__, __LINE__, fmt, ## __VA_ARGS__); \
201+
} while (0)
202+
#else
203+
#define LOG_MESSAGE(mask, fmt, ...)
204+
205+
/**
206+
* Dummy implementation which returns always false.
207+
* @return Always false.
208+
*/
209+
static inline bool is_logging_enabled()
210+
{
211+
return false;
212+
}
213+
214+
/**
215+
* Dummy implementation which returns always false.
216+
* @param level The log level to be checked.
217+
* @return Always false.
218+
*/
219+
static inline bool is_log_level_active(uint32_t level)
220+
{
221+
(void)level;
222+
223+
return false;
224+
}
225+
#endif /* LOGGING_ENABLED */
226+
227+
/**
228+
* Logs only if the right log level is set.
229+
* @param mask The log mask to log on.
230+
* @param fmt Printf-style format string.
231+
* @param args Optional arguments for the format string.
232+
*/
233+
#define qemu_log_mask(mask, fmt, ...) \
234+
LOG_MESSAGE(mask, fmt, ## __VA_ARGS__)
235+
236+
#endif /* QEMU_LOG_H */

‎qemu/tcg/tcg.c

+2-2
Original file line numberDiff line numberDiff line change
@@ -3728,7 +3728,7 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
37283728
TCGOp *op;
37293729

37303730
#ifndef NDEBUG
3731-
if (getenv("UNICORN_DEBUG")) {
3731+
if (is_log_level_active(CPU_LOG_TB_IN_ASM)) {
37323732
tcg_dump_ops(s, false, "TCG before optimization:");
37333733
}
37343734
#endif
@@ -3777,7 +3777,7 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
37773777
#endif
37783778

37793779
#ifndef NDEBUG
3780-
if (getenv("UNICORN_DEBUG")) {
3780+
if (is_log_level_active(CPU_LOG_TB_IN_ASM)) {
37813781
tcg_dump_ops(s, false, "TCG before codegen:");
37823782
}
37833783
#endif

0 commit comments

Comments
 (0)