Mirror
/
cpython
mirror of https://github.com/python/cpython
4
1
Fork 0
Code Issues Releases Wiki Activity

Cleanup tier2 debug output (#116920) 

Various tweaks, including a slight refactor of the special cases for `_PUSH_FRAME`/`_POP_FRAME` to show the actual operand emitted.
This commit is contained in:
Guido van Rossum 2024-03-18 11:08:43 -07:00 committed by GitHub
parent 849e0716d3
commit 76d0868907
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
5 changed files with 50 additions and 22 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

9
Python/ceval.c
View File

@ -1017,7 +1017,12 @@ enter_tier_two:
uopcode = next_uop->opcode;
#ifdef Py_DEBUG
if (lltrace >= 3) {
printf("%4d uop: ", (int)(next_uop - (current_executor == NULL ? next_uop : current_executor->trace)));
if (next_uop->opcode == _START_EXECUTOR || next_uop->opcode == _COLD_EXIT) {
printf("%4d uop: ", 0);
}
else {
printf("%4d uop: ", (int)(next_uop - current_executor->trace));
}
_PyUOpPrint(next_uop);
printf(" stack_level=%d\n",
(int)(stack_pointer - _PyFrame_Stackbase(frame)));
@ -1113,7 +1118,7 @@ side_exit:
_PyUOpPrint(&next_uop[-1]);
printf(", exit %u, temp %d, target %d -> %s]\n",
exit_index, exit->temperature, exit->target,
_PyOpcode_OpName[frame->instr_ptr->op.code]);
_PyOpcode_OpName[_PyCode_CODE(_PyFrame_GetCode(frame))[exit->target].op.code]);
}
#endif
Py_INCREF(exit->executor);

43
Python/optimizer.c
View File

@ -313,7 +313,7 @@ _PyUOpPrint(const _PyUOpInstruction *uop)
else {
printf("%s", name);
}
printf(" (%d, target=%d, operand=%" PRIx64 ")",
printf(" (%d, target=%d, operand=%#" PRIx64 ")",
uop->oparg,
uop->target,
(uint64_t)uop->operand);
@ -528,7 +528,7 @@ translate_bytecode_to_trace(
}
#endif
DPRINTF(4,
DPRINTF(2,
"Optimizing %s (%s:%d) at byte offset %d\n",
PyUnicode_AsUTF8(code->co_qualname),
PyUnicode_AsUTF8(code->co_filename),
@ -546,7 +546,7 @@ top: // Jump here after _PUSH_FRAME or likely branches
uint32_t oparg = instr->op.arg;
uint32_t extended = 0;
DPRINTF(3, "%d: %s(%d)\n", target, _PyOpcode_OpName[opcode], oparg);
DPRINTF(2, "%d: %s(%d)\n", target, _PyOpcode_OpName[opcode], oparg);
if (opcode == ENTER_EXECUTOR) {
assert(oparg < 256);
@ -606,7 +606,7 @@ top: // Jump here after _PUSH_FRAME or likely branches
confidence = confidence * (18 - bitcount) / 20;
}
uint32_t uopcode = BRANCH_TO_GUARD[opcode - POP_JUMP_IF_FALSE][jump_likely];
DPRINTF(2, "%d: %s(%d): counter=%x, bitcount=%d, likely=%d, confidence=%d, uopcode=%s\n",
DPRINTF(2, "%d: %s(%d): counter=%04x, bitcount=%d, likely=%d, confidence=%d, uopcode=%s\n",
target, _PyOpcode_OpName[opcode], oparg,
counter, bitcount, jump_likely, confidence, _PyUOpName(uopcode));
if (confidence < CONFIDENCE_CUTOFF) {
@ -617,7 +617,7 @@ top: // Jump here after _PUSH_FRAME or likely branches
_Py_CODEUNIT *next_instr = instr + 1 + _PyOpcode_Caches[_PyOpcode_Deopt[opcode]];
_Py_CODEUNIT *target_instr = next_instr + oparg;
if (jump_likely) {
DPRINTF(2, "Jump likely (%x = %d bits), continue at byte offset %d\n",
DPRINTF(2, "Jump likely (%04x = %d bits), continue at byte offset %d\n",
instr[1].cache, bitcount, 2 * INSTR_IP(target_instr, code));
instr = target_instr;
ADD_TO_TRACE(uopcode, max_length, 0, INSTR_IP(next_instr, code));
@ -716,12 +716,12 @@ top: // Jump here after _PUSH_FRAME or likely branches
expansion->uops[i].offset);
Py_FatalError("garbled expansion");
}
ADD_TO_TRACE(uop, oparg, operand, target);
if (uop == _POP_FRAME) {
TRACE_STACK_POP();
/* Set the operand to the function object returned to,
* to assist optimization passes */
trace[trace_length-1].operand = (uintptr_t)func;
ADD_TO_TRACE(uop, oparg, (uintptr_t)func, target);
DPRINTF(2,
"Returning to %s (%s:%d) at byte offset %d\n",
PyUnicode_AsUTF8(code->co_qualname),
@ -730,6 +730,7 @@ top: // Jump here after _PUSH_FRAME or likely branches
2 * INSTR_IP(instr, code));
goto top;
}
if (uop == _PUSH_FRAME) {
assert(i + 1 == nuops);
int func_version_offset =
@ -738,7 +739,7 @@ top: // Jump here after _PUSH_FRAME or likely branches
+ 1;
uint32_t func_version = read_u32(&instr[func_version_offset].cache);
PyFunctionObject *new_func = _PyFunction_LookupByVersion(func_version);
DPRINTF(3, "Function object: %p\n", func);
DPRINTF(2, "Function: version=%#x; object=%p\n", (int)func_version, new_func);
if (new_func != NULL) {
PyCodeObject *new_code = (PyCodeObject *)PyFunction_GET_CODE(new_func);
if (new_code == code) {
@ -748,6 +749,7 @@ top: // Jump here after _PUSH_FRAME or likely branches
PyUnicode_AsUTF8(new_code->co_filename),
new_code->co_firstlineno);
OPT_STAT_INC(recursive_call);
ADD_TO_TRACE(uop, oparg, 0, target);
ADD_TO_TRACE(_EXIT_TRACE, 0, 0, 0);
goto done;
}
@ -756,6 +758,7 @@ top: // Jump here after _PUSH_FRAME or likely branches
// Perhaps it may happen again, so don't bother tracing.
// TODO: Reason about this -- is it better to bail or not?
DPRINTF(2, "Bailing because co_version != func_version\n");
ADD_TO_TRACE(uop, oparg, 0, target);
ADD_TO_TRACE(_EXIT_TRACE, 0, 0, 0);
goto done;
}
@ -763,9 +766,9 @@ top: // Jump here after _PUSH_FRAME or likely branches
instr += _PyOpcode_Caches[_PyOpcode_Deopt[opcode]] + 1;
TRACE_STACK_PUSH();
_Py_BloomFilter_Add(dependencies, new_code);
/* Set the operand to the callee's code object,
* to assist optimization passes */
trace[trace_length-1].operand = (uintptr_t)new_func;
/* Set the operand to the callee's function object,
* to assist optimization passes */
ADD_TO_TRACE(uop, oparg, (uintptr_t)new_func, target);
code = new_code;
func = new_func;
instr = _PyCode_CODE(code);
@ -777,9 +780,14 @@ top: // Jump here after _PUSH_FRAME or likely branches
2 * INSTR_IP(instr, code));
goto top;
}
DPRINTF(2, "Bail, new_func == NULL\n");
ADD_TO_TRACE(uop, oparg, operand, target);
ADD_TO_TRACE(_EXIT_TRACE, 0, 0, 0);
goto done;
}
// All other instructions
ADD_TO_TRACE(uop, oparg, operand, target);
}
break;
}
@ -803,17 +811,18 @@ done:
// Skip short traces like _SET_IP, LOAD_FAST, _SET_IP, _EXIT_TRACE
if (progress_needed || trace_length < 5) {
OPT_STAT_INC(trace_too_short);
DPRINTF(4,
"No trace for %s (%s:%d) at byte offset %d\n",
DPRINTF(2,
"No trace for %s (%s:%d) at byte offset %d (%s)\n",
PyUnicode_AsUTF8(code->co_qualname),
PyUnicode_AsUTF8(code->co_filename),
code->co_firstlineno,
2 * INSTR_IP(initial_instr, code));
2 * INSTR_IP(initial_instr, code),
progress_needed ? "no progress" : "too short");
return 0;
}
ADD_TO_TRACE(_EXIT_TRACE, 0, 0, target);
DPRINTF(1,
"Created a trace for %s (%s:%d) at byte offset %d -- length %d\n",
"Created a proto-trace for %s (%s:%d) at byte offset %d -- length %d\n",
PyUnicode_AsUTF8(code->co_qualname),
PyUnicode_AsUTF8(code->co_filename),
code->co_firstlineno,
@ -938,6 +947,8 @@ make_executor_from_uops(_PyUOpInstruction *buffer, const _PyBloomFilter *depende
assert(next_exit == -1);
assert(dest == executor->trace);
dest->opcode = _START_EXECUTOR;
dest->oparg = 0;
dest->target = 0;
dest->operand = (uintptr_t)executor;
_Py_ExecutorInit(executor, dependencies);
#ifdef Py_DEBUG
@ -947,7 +958,7 @@ make_executor_from_uops(_PyUOpInstruction *buffer, const _PyBloomFilter *depende
lltrace = *python_lltrace - '0'; // TODO: Parse an int and all that
}
if (lltrace >= 2) {
printf("Optimized executor (length %d):\n", length);
printf("Optimized trace (length %d):\n", length);
for (int i = 0; i < length; i++) {
printf("%4d OPTIMIZED: ", i);
_PyUOpPrint(&executor->trace[i]);

18
Python/optimizer_analysis.c
View File

@ -35,6 +35,7 @@
#ifdef Py_DEBUG
extern const char *_PyUOpName(int index);
extern void _PyUOpPrint(const _PyUOpInstruction *uop);
static const char *const DEBUG_ENV = "PYTHON_OPT_DEBUG";
static inline int get_lltrace(void) {
char *uop_debug = Py_GETENV(DEBUG_ENV);
@ -377,14 +378,20 @@ optimize_uops(
_Py_UopsSymbol **stack_pointer = ctx->frame->stack_pointer;
DPRINTF(3, "Abstract interpreting %s:%d ",
_PyUOpName(opcode),
oparg);
#ifdef Py_DEBUG
if (get_lltrace() >= 3) {
printf("%4d abs: ", (int)(this_instr - trace));
_PyUOpPrint(this_instr);
printf(" ");
}
#endif
switch (opcode) {
#include "optimizer_cases.c.h"
default:
DPRINTF(1, "Unknown opcode in abstract interpreter\n");
DPRINTF(1, "\nUnknown opcode in abstract interpreter\n");
Py_UNREACHABLE();
}
assert(ctx->frame != NULL);
@ -397,11 +404,13 @@ optimize_uops(
return 1;
out_of_space:
DPRINTF(3, "\n");
DPRINTF(1, "Out of space in abstract interpreter\n");
_Py_uop_abstractcontext_fini(ctx);
return 0;
error:
DPRINTF(3, "\n");
DPRINTF(1, "Encountered error in abstract interpreter\n");
_Py_uop_abstractcontext_fini(ctx);
return 0;
@ -411,6 +420,7 @@ hit_bottom:
// This means that the abstract interpreter has hit unreachable code.
// We *could* generate an _EXIT_TRACE or _FATAL_ERROR here, but it's
// simpler to just admit failure and not create the executor.
DPRINTF(3, "\n");
DPRINTF(1, "Hit bottom in abstract interpreter\n");
_Py_uop_abstractcontext_fini(ctx);
return 0;

1
Python/optimizer_bytecodes.c
View File

@ -544,6 +544,7 @@ dummy_func(void) {
(void)callable;
PyFunctionObject *func = (PyFunctionObject *)(this_instr + 2)->operand;
DPRINTF(3, "func: %p ", func);
if (func == NULL) {
goto error;
}

1
Python/optimizer_cases.c.h generated
View File

@ -1597,6 +1597,7 @@
int argcount = oparg;
(void)callable;
PyFunctionObject *func = (PyFunctionObject *)(this_instr + 2)->operand;
DPRINTF(3, "func: %p ", func);
if (func == NULL) {
goto error;
}