View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0001445XdebugUncategorizedpublic2017-05-30 16:442017-05-30 20:31
Reporterbgamrat Assigned Toderick  
PrioritynormalSeverityminorReproducibilityalways
Status resolvedResolutionno change required 
Product Version2.5.1 
Summary0001445: Profiler not capturing POST requests immediately followed by a location.href
Description

I need to use the profiler (obviously).

The application I am working with uses the string returned from an Ajax POST request to redirect to the next action.

I need the profile data from the POST request, but it is not creating a profile file for requests that run this way.

I am able to get profile data for POST requests which are consumed and not immediately followed by a client side redirect.

Steps To Reproduce

Test instructions:

  1. Load form.php
  2. Click Go

form.php



<!DOCTYPE html>

<html>

<head>

<meta charset="UTF-8" />

<title>Post Test</title>

</head>

<body>

<h1>Post Test</h1>

<blockquote>Just click Go</blockquote>

<form id="ajax-form" method="post" action="/post.php">

<div>

<label for="one">One: <input type="text" id="one" name="one"></label>

</div>

<button id="go" type="button">Go</button>

</form>

<div id="status"></div>

<script>

document.getElementById("go").addEventListener("click", function () {

var xmlhttp;

function done()

{

document.getElementById("status").textContent = 'Done!';

// The delay has no effect, but I am leaving it here because this is the last code I tested with

setTimeout(function(){location.href = 'form.php';},1000);

}

xmlhttp = new XMLHttpRequest();

xmlhttp.addEventListener("load", done, false);

xmlhttp.open("POST", "post.php", true);

xmlhttp.send();

});

</script>

</body>

</html>

post.php



<?php

echo 'Hello';

exit;

Additional Information

/etc/php5/apache2/conf.d/20-xdebug.ini



zend_extension="/usr/lib/php5/20121212/xdebug.so"

#xdebug.profiler_enable_trigger=1

xdebug.profiler_enable=1

TagsNo tags attached.
Operating SystemUbuntu 14.04.5 LTS
PHP Version5.5.20-5.5.24

Activities

derick

2017-05-30 16:53

administrator   ~0004353

How do you activate the debugger? Do you use a "browser plugin" , through requesting the URl with the ?XDEBUG_SESSION_START=foo GET/POST parameter, or through an IDE?

Can you check the headers that are being sent by your browser for both the GET request of the form, as well as for the POST through XMLHTTPRequest?

bgamrat

2017-05-30 16:58

reporter   ~0004354

I thought xdebug.profiler_enable=1 ensured all requests would be profiled.

derick

2017-05-30 17:08

administrator   ~0004355

Hmm, it should indeed. I was thinking debugger here. Are you sure they don't end up in another file, or are written to the same file as the first profiling file? There is no reason why these shouldn't work.

You can try customising the format of the filename through one of the letters at https://xdebug.org/docs/all#trace_output_name

For example, setting xdebug.profiler_output_name to cachegrind.out.%s should do the trick.

bgamrat

2017-05-30 17:26

reporter   ~0004356

Last edited: 2017-05-30 17:27

It is creating cache grind files okay ...



ls -l /tmp/cach*

-rw-r--r-- 1 www-data www-data   22092 May 30 12:20 /tmp/cachegrind.out.28203

-rw-r--r-- 1 www-data www-data   40870 May 30 10:59 /tmp/cachegrind.out.28212

-rw-r--r-- 1 www-data www-data   33237 May 30 10:54 /tmp/cachegrind.out.28217

-rw-r--r-- 1 www-data www-data   52760 May 30 11:29 /tmp/cachegrind.out.28447

-rw-r--r-- 1 www-data www-data   33303 May 30 12:03 /tmp/cachegrind.out.28521

-rw-r--r-- 1 www-data www-data   51916 May 30 11:30 /tmp/cachegrind.out.28959

-rw-r--r-- 1 www-data www-data   25107 May 30 11:57 /tmp/cachegrind.out.29049

-rw-r--r-- 1 www-data www-data   56106 May 30 11:36 /tmp/cachegrind.out.29106

-rw-r--r-- 1 www-data www-data   32314 May 30 12:01 /tmp/cachegrind.out.30074

-rw-r--r-- 1 www-data www-data  315287 May 30 12:37 /tmp/cachegrind.out.30079

-rw-r--r-- 1 www-data www-data   29898 May 30 12:37 /tmp/cachegrind.out.30156

-rw-r--r-- 1 www-data www-data 1080356 May 30 12:06 /tmp/cachegrind.out.30160

-rw-r--r-- 1 www-data www-data    1319 May 30 12:18 /tmp/cachegrind.out.30260

-rw-r--r-- 1 www-data www-data    1460 May 30 12:21 /tmp/cachegrind.out.30330

-rw-r--r-- 1 www-data www-data   22090 May 30 12:22 /tmp/cachegrind.out.30351

-rw-r--r-- 1 www-data www-data   13943 May 30 12:06 /tmp/cachegrind.out.30474

-rw-r--r-- 1 www-data www-data   11370 May 30 12:31 /tmp/cachegrind.out.30493

-rw-r--r-- 1 www-data www-data     201 May 30 12:37 /tmp/cachegrind.out.30770

-rw-r--r-- 1 www-data www-data   27185 May 30 12:19 /tmp/cachegrind.out.30845

-rw-r--r-- 1 www-data www-data    1317 May 30 12:23 /tmp/cachegrind.out.30920

-rw-r--r-- 1 www-data www-data   27289 May 30 12:25 /tmp/cachegrind.out.30922

-rw-r--r-- 1 www-data www-data   11378 May 30 12:30 /tmp/cachegrind.out.30989





grep -i '(form|post).php' /tmp/cach*

/tmp/cachegrind.out.30770:cmd: /var/bgamrat/form.php

/tmp/cachegrind.out.30770:fl=(1) /var/bgamrat/form.php

derick

2017-05-30 20:24

administrator   ~0004357

This is not a bug.

If you would have tried my suggestion to use xdebug.profiler_output_name as cachegrind.out.%s, you would have seen that Xdebug creates the profile file just fine.

The issue here is that if you write a profile file (the post.php) one, and then you redirect to form.php again, the same PID is likely going to be used by the webserver for that second request due to Keep Alive features. The number in the cachegrind.out.XXX output is this PID. Because the direct happens after the original request has ended, the profile file just gets overwritten by the location.href request to the old form.php script again.

You can also observe this happening by changing your timeout to for example 60 seconds and examine the cachegrind.out.XXX files in the meanwhile.

In any case, this is not a bug, so I'm closing this issue.

bgamrat

2017-05-30 20:26

reporter   ~0004358

Last edited: 2017-05-30 20:31

Thank you - changing the name as you recommended worked.

Issue History

Date Modified Username Field Change
2017-05-30 16:44 bgamrat New Issue
2017-05-30 16:53 derick Note Added: 0004353
2017-05-30 16:53 derick Assigned To => derick
2017-05-30 16:53 derick Status new => feedback
2017-05-30 16:58 bgamrat Note Added: 0004354
2017-05-30 16:58 bgamrat Status feedback => assigned
2017-05-30 17:08 derick Note Added: 0004355
2017-05-30 17:08 derick Status assigned => feedback
2017-05-30 17:26 bgamrat Note Added: 0004356
2017-05-30 17:26 bgamrat Status feedback => assigned
2017-05-30 17:27 bgamrat Note Edited: 0004356
2017-05-30 20:24 derick Note Added: 0004357
2017-05-30 20:24 derick Status assigned => resolved
2017-05-30 20:24 derick Resolution open => no change required
2017-05-30 20:26 bgamrat Note Added: 0004358
2017-05-30 20:31 bgamrat Note Edited: 0004358
2020-03-12 16:35 derick Category Usage problems (Wrong Results) => Variable Display
2020-03-12 16:38 derick Category Variable Display => Uncategorized