Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -140,6 +140,9 @@ All with no changes to your application and minimal overhead.
<varname>@<path>:<lineno>
<varname>@<path>:<start>-<end>
e.g., xyz@/path/to.php:10-20
--peek-max-len=<len> Limit each peeked value to `len` chars
(increase `-b` for longer output)
(default: 255)
-D, --peek-pdo Peek at the SQL and arguments of PDO
queries. Emits varpeek events.
-g, --peek-global=<glospec> Peek at the contents of a global var
Expand Down
16 changes: 16 additions & 0 deletions phpspy.c
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,7 @@ static char *opt_path_child_out = "phpspy.%d.out";
static char *opt_path_child_err = "phpspy.%d.err";
static char *opt_phpv = "auto";
static int opt_pause = 0;
static int opt_peek_max_len = PHPSPY_DEFAULT_PEEK_MAX_LEN;
static int (*opt_event_handler)(struct trace_context_s *context, int event_type) = event_handler_fout;
static char *opt_event_handler_opts = NULL;
static int opt_continue_on_error = 0;
Expand Down Expand Up @@ -197,6 +198,9 @@ void usage(FILE *fp, int exit_code) {
fprintf(fp, " <varname>@<path>:<lineno>\n");
fprintf(fp, " <varname>@<path>:<start>-<end>\n");
fprintf(fp, " e.g., xyz@/path/to.php:10-20\n");
fprintf(fp, " --peek-max-len=<len> Limit each peeked value to `len` chars\n");
fprintf(fp, " (increase `-b` for longer output)\n");
fprintf(fp, " (default: %d)\n", opt_peek_max_len);
fprintf(fp, " -D, --peek-pdo Peek at the SQL and arguments of PDO\n");
fprintf(fp, " queries. Emits varpeek events.\n");
fprintf(fp, " -g, --peek-global=<glospec> Peek at the contents of a global var\n");
Expand Down Expand Up @@ -275,6 +279,7 @@ static void parse_opts(int argc, char **argv) {
{ "version", no_argument, NULL, 'v' },
{ "pause-process", no_argument, NULL, 'S' },
{ "peek-var", required_argument, NULL, 'e' },
{ "peek-max-len", required_argument, NULL, PHPSPY_LONGOPT_PEEK_MAX_LEN },
{ "peek-global", required_argument, NULL, 'g' },
{ "peek-pdo", no_argument, NULL, 'D' },
{ "top", no_argument, NULL, 't' },
Expand Down Expand Up @@ -385,6 +390,7 @@ static void parse_opts(int argc, char **argv) {
exit(0);
case 'S': opt_pause = 1; break;
case 'e': varpeek_add(optarg); break;
case PHPSPY_LONGOPT_PEEK_MAX_LEN: opt_peek_max_len = atoi_with_min_or_exit("--peek-max-len", optarg, 1); break;
case 'g': glopeek_add(optarg); break;
case 't': opt_top_mode = 1; break;
case PHPSPY_LONGOPT_LIBNAME_AWK_PATT: opt_libname_awk_patt = optarg; break;
Expand Down Expand Up @@ -447,6 +453,15 @@ int main_pid(pid_t pid) {
}
#endif

context.peek_buf_size = (size_t)opt_peek_max_len + 1;
context.peek_buf = malloc(context.peek_buf_size);
if (!context.peek_buf) {
log_perror("main_pid: malloc peek buffer");
if (context.stack_ptrs) utarray_free(context.stack_ptrs);
context.event_handler(&context, PHPSPY_TRACE_EVENT_DEINIT);
return PHPSPY_ERR;
}

/* calc stop_time */
stop_time = NULL;
if (in_pgrep_mode) {
Expand Down Expand Up @@ -503,6 +518,7 @@ int main_pid(pid_t pid) {

if (context.stack_ptrs) utarray_free(context.stack_ptrs);
context.event_handler(&context, PHPSPY_TRACE_EVENT_DEINIT);
free(context.peek_buf);

/* in pgrep mode, trigger done condition if we went over the trace limit.
it is ok for multiple threads to call this. */
Expand Down
7 changes: 5 additions & 2 deletions phpspy.h
Original file line number Diff line number Diff line change
Expand Up @@ -50,6 +50,7 @@
#ifndef PHPSPY_STR_SIZE
#define PHPSPY_STR_SIZE 256
#endif
#define PHPSPY_DEFAULT_PEEK_MAX_LEN (PHPSPY_STR_SIZE - 1)
#define PHPSPY_MAX_ARRAY_BUCKETS 128
#define PHPSPY_MAX_ARRAY_TABLE_SIZE 512
#define PHPSPY_HASH_FLAG_PACKED (1 << 2)
Expand Down Expand Up @@ -96,6 +97,7 @@ enum {
PHPSPY_LONGOPT_LIBNAME_AWK_PATT,
PHPSPY_LONGOPT_EVENT_HANDLER,
PHPSPY_LONGOPT_EVENT_HANDLER_OPTS,
PHPSPY_LONGOPT_PEEK_MAX_LEN,
};

typedef struct varpeek_var_s {
Expand Down Expand Up @@ -177,8 +179,9 @@ typedef struct trace_context_s {
void *event_udata;
int (*event_handler)(struct trace_context_s *context, int event_type);
const char *event_handler_opts;
char buf[PHPSPY_STR_SIZE];
size_t buf_len;
char *peek_buf;
size_t peek_buf_size;
size_t peek_buf_len;
UT_array *stack_ptrs;
} trace_context;

Expand Down
27 changes: 14 additions & 13 deletions phpspy_trace.c
Original file line number Diff line number Diff line change
Expand Up @@ -292,12 +292,12 @@ static int trace_globals(trace_context *context) {

/* Print the element within the array */

rv = sprint_zarray_val(context, garray, gentry->varname, context->buf, sizeof(context->buf), &context->buf_len);
rv = sprint_zarray_val(context, garray, gentry->varname, context->peek_buf, context->peek_buf_size, &context->peek_buf_len);

if (rv == PHPSPY_OK) {
context->event.glopeek.gentry = gentry;
context->event.glopeek.zval_str = context->buf;
context->event.glopeek.zval_str_len = context->buf_len;
context->event.glopeek.zval_str = context->peek_buf;
context->event.glopeek.zval_str_len = context->peek_buf_len;
try(rv, context->event_handler(context, PHPSPY_TRACE_EVENT_GLOPEEK));
}
}
Expand All @@ -319,7 +319,7 @@ static int trace_globals(trace_context *context) {
*/
static int trace_locals(trace_context *context, zend_op *zop, zend_execute_data *remote_execute_data, zend_op_array *op_array, char *file, int file_len) {
int rv, i, num_vars_found, num_vars_peeking;
char tmp[PHPSPY_STR_SIZE];
char var_name[PHPSPY_STR_SIZE];
size_t tmp_len;
zend_string *zstrp;
varpeek_entry *entry;
Expand All @@ -336,16 +336,16 @@ static int trace_locals(trace_context *context, zend_op *zop, zend_execute_data

for (i = 0; i < op_array->last_var; i++) {
try_copy_proc_mem("var", op_array->vars + i, &zstrp, sizeof(zstrp));
try(rv, sprint_zstring(context, "var", zstrp, tmp, sizeof(tmp), &tmp_len));
HASH_FIND(hh, entry->varmap, tmp, tmp_len, var);
try(rv, sprint_zstring(context, "var", zstrp, var_name, sizeof(var_name), &tmp_len));
HASH_FIND(hh, entry->varmap, var_name, tmp_len, var);
if (!var) continue;
num_vars_found += 1;
/* See ZEND_CALL_VAR_NUM macro in php-src */
try_copy_proc_mem("zval", ((zval*)(remote_execute_data)) + ((int)(5 + i)), &zv, sizeof(zv));
try(rv, sprint_zval(context, &zv, tmp, sizeof(tmp), &tmp_len));
try(rv, sprint_zval(context, &zv, context->peek_buf, context->peek_buf_size, &tmp_len));
context->event.varpeek.entry = entry;
context->event.varpeek.var = var;
context->event.varpeek.zval_str = tmp;
context->event.varpeek.zval_str = context->peek_buf;
context->event.varpeek.zval_str_len = tmp_len;
try(rv, context->event_handler(context, PHPSPY_TRACE_EVENT_VARPEEK));
if (num_vars_found >= num_vars_peeking) break;
Expand All @@ -366,7 +366,8 @@ static int trace_pdo(trace_context *context, zend_execute_data *remote_execute_d
zend_object lobj;
pdo_stmt_t lstmt;
zval first_arg;
char buf[PHPSPY_STR_SIZE];
char *buf = context->peek_buf;
size_t buf_size = context->peek_buf_size;
size_t buf_len;
uint8_t this_type;

Expand Down Expand Up @@ -401,7 +402,7 @@ static int trace_pdo(trace_context *context, zend_execute_data *remote_execute_d

if (lobj.properties_table[0].u1.v.type == PHPSPY_ZVAL_TYPE_STRING) {
try(rv, sprint_zstring(context, "pdo_qs",
lobj.properties_table[0].value.str, buf, sizeof(buf), &buf_len));
lobj.properties_table[0].value.str, buf, buf_size, &buf_len));
context->event.varpeek.entry = &entry;
context->event.varpeek.var = &var_sql;
context->event.varpeek.zval_str = buf;
Expand All @@ -414,7 +415,7 @@ static int trace_pdo(trace_context *context, zend_execute_data *remote_execute_d
try_copy_proc_mem("pdo_arg0",
((zval*)remote_execute_data) + 5, &first_arg, sizeof(first_arg));
if (first_arg.u1.v.type == PHPSPY_ZVAL_TYPE_ARRAY) {
rv = sprint_zarray(context, first_arg.value.arr, buf, sizeof(buf), &buf_len);
rv = sprint_zarray(context, first_arg.value.arr, buf, buf_size, &buf_len);
if (rv == PHPSPY_OK && buf_len > 0) {
context->event.varpeek.entry = &entry;
context->event.varpeek.var = &var_args;
Expand All @@ -428,7 +429,7 @@ static int trace_pdo(trace_context *context, zend_execute_data *remote_execute_d
void *rstmt = (void*)((char*)robj - offsetof(pdo_stmt_t, std));
try_copy_proc_mem("pdo_stmt", rstmt, &lstmt, sizeof(lstmt));
if (lstmt.bound_params) {
rv = sprint_pdo_binds(context, lstmt.bound_params, buf, sizeof(buf), &buf_len);
rv = sprint_pdo_binds(context, lstmt.bound_params, buf, buf_size, &buf_len);
if (rv == PHPSPY_OK && buf_len > 0) {
context->event.varpeek.entry = &entry;
context->event.varpeek.var = &var_args;
Expand All @@ -445,7 +446,7 @@ static int trace_pdo(trace_context *context, zend_execute_data *remote_execute_d
((zval*)remote_execute_data) + 5, &first_arg, sizeof(first_arg));
if (first_arg.u1.v.type == PHPSPY_ZVAL_TYPE_STRING) {
try(rv, sprint_zstring(context, "pdo_sql",
first_arg.value.str, buf, sizeof(buf), &buf_len));
first_arg.value.str, buf, buf_size, &buf_len));
context->event.varpeek.entry = &entry;
context->event.varpeek.var = &var_sql;
context->event.varpeek.zval_str = buf;
Expand Down
13 changes: 13 additions & 0 deletions tests/test_glopeek.sh
Original file line number Diff line number Diff line change
Expand Up @@ -32,3 +32,16 @@ declare -A test_expected
test_expected[glopeek1 ]="^# glopeek server.Ez = 1"
test_expected[glopeek2 ]="^# glopeek server.FY = 2"
test_invoke

peek_length=5000
peek_buffer_size=8192
php_src="<?php
\$GLOBALS['long_value'] = str_repeat('x', $peek_length);
sleep(1);"
php_file=$(mktemp)
echo "$php_src" >"$php_file"
test_phpspy_opts=(--limit=0 --buffer-size "$peek_buffer_size" --peek-max-len "$peek_length" --peek-global "globals.long_value" -- "${PHP[@]}" "$php_file")
declare -A test_expected
test_expected[glopeek_long]="^# glopeek globals.long_value = x{$peek_length}$"
test_invoke
rm -f "$php_file"
32 changes: 32 additions & 0 deletions tests/test_varpeek.sh
Original file line number Diff line number Diff line change
Expand Up @@ -34,3 +34,35 @@ declare -A test_expected
test_expected[varpeek2 ]="^# varpeek a@$php_file:4 = k=42,j=dolphin$"
test_invoke
rm -f "$php_file"

peek_length=5000
peek_buffer_size=8192
php_src="<?php
function f() {
\$a = str_repeat('x', $peek_length);
sleep(1);
}
f();"
php_file=$(mktemp)
echo "$php_src" >"$php_file"
test_phpspy_opts=(--limit=0 --buffer-size "$peek_buffer_size" --peek-max-len "$peek_length" --peek-var "a@$php_file:4" -- "${PHP[@]}" "$php_file")
declare -A test_expected
test_expected[varpeek_long]="^# varpeek a@$php_file:4 = x{$peek_length}$"
test_invoke
rm -f "$php_file"

help_output=$("$PHPSPY" --help)
test_assert_re peek_max_len_help "peek-max-len=<len>" "$help_output"

virtual_memory_limit_kib=131072
oversized_peek_length=268435456
allocation_error=$(
ulimit -v "$virtual_memory_limit_kib"
"$PHPSPY" \
--peek-max-len "$oversized_peek_length" \
--limit=1 \
--child-stdout=/dev/null \
--child-stderr=/dev/null \
-- "${PHP[@]}" -r 'sleep(1);' 2>&1
)
test_assert_re peek_max_len_allocation_error "^main_pid: malloc peek buffer:" "$allocation_error"
33 changes: 33 additions & 0 deletions tests/test_varpeek_pdo.sh
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,39 @@ test_expected[pdo_args_execute_array]="^# varpeek #pdo_args@PDOStatement::execut
test_invoke
rm -f "$php_file"

# Long query
peek_length=5000
peek_max_length=6000
peek_buffer_size=8192
php_src="<?php
\$long_sql_part = str_repeat('x', $peek_length);
\$pdo = new PDO('sqlite::memory:');
\$pdo->sqliteCreateFunction('slow', function (\$x) { sleep(1); return \$x; }, 1);
\$stmt = \$pdo->prepare(\"SELECT slow(:value) AS r WHERE '\$long_sql_part' <> ''\");
\$stmt->execute([':value' => 'ok']);"
php_file=$(mktemp)
echo "$php_src" >"$php_file"
test_phpspy_opts=(--limit=1 --buffer-size "$peek_buffer_size" --peek-max-len "$peek_max_length" --peek-pdo -- "${PHP[@]}" "$php_file")
declare -A test_expected
test_expected[pdo_sql_long]="^# varpeek #pdo_sql@PDOStatement::execute = SELECT slow\(:value\) AS r WHERE 'x{$peek_length}' <> ''$"
test_invoke
rm -f "$php_file"

# Long execute argument
php_src="<?php
\$long_value = str_repeat('x', $peek_length);
\$pdo = new PDO('sqlite::memory:');
\$pdo->sqliteCreateFunction('slow', function (\$x) { sleep(1); return \$x; }, 1);
\$stmt = \$pdo->prepare('SELECT slow(:value) AS r');
\$stmt->execute([':value' => \$long_value]);"
php_file=$(mktemp)
echo "$php_src" >"$php_file"
test_phpspy_opts=(--limit=1 --buffer-size "$peek_buffer_size" --peek-max-len "$peek_max_length" --peek-pdo -- "${PHP[@]}" "$php_file")
declare -A test_expected
test_expected[pdo_args_long]="^# varpeek #pdo_args@PDOStatement::execute = :value=x{$peek_length}$"
test_invoke
rm -f "$php_file"

# PDOStatement::execute with packed (positional) array
read -r -d '' php_src <<'EOD'
<?php
Expand Down