php-fpm, Symfony and xdebug assistance?

I have the following system which I'm trying to debug.

PHPStorm 7.0.1 EAP 131.487, locally debugging the following:
nginx 1.4.3 proxying to:
php-fpm 5.4.21 on port 9000
xdebug on port 8999, phpstorm has been updated to that port.

I have configured my xdebug.  I do get an accept request dialog the first, and only the first time I make the request, but my breakpoints refuse to halt.  I've tried xdebug bookmarkets, debugging the idea log, and a number of other things.  Can you help me figure out what's gone wrong?  I'm posting the xdebug/idea logs below.

xdebug.log output:

Log opened at 2013-11-13 22:17:51
I: Connecting to configured address/port: localhost:8999.
I: Connected to client. :-)
-> <init xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" fileuri="file:///Users/akreps/src/Athletepath/web/app.php" language="PHP" protocol_version="1.0" appid="77353" idekey="PHPSTORM"><engine version="2.2.3"><![CDATA[Xdebug]]></engine><author><![CDATA[Derick Rethans]]></author><url><![CDATA[http://xdebug.org]]></url><copyright><![CDATA[Copyright (c) 2002-2013 by Derick Rethans]]></copyright></init>


<- feature_set -i 0 -n show_hidden -v 1
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="0" feature="show_hidden" success="1"></response>


<- feature_set -i 1 -n max_depth -v 1
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="1" feature="max_depth" success="1"></response>


<- feature_set -i 2 -n max_children -v 100
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="2" feature="max_children" success="1"></response>


<- status -i 3
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="status" transaction_id="3" status="starting" reason="ok"></response>


<- step_into -i 4
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="step_into" transaction_id="4" status="break" reason="ok"><xdebug:message filename="file:///Users/akreps/src/Athletepath/web/app.php" lineno="6"></xdebug:message></response>


<- eval -i 5 -- aXNzZXQoJF9TRVJWRVJbJ1BIUF9JREVfQ09ORklHJ10p
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="eval" transaction_id="5"><property address="140734627130240" type="bool"><![CDATA[0]]></property></response>


<- eval -i 6 -- aXNzZXQoJF9TRVJWRVJbJ1NFUlZFUl9OQU1FJ10p
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="eval" transaction_id="6"><property address="140734627130240" type="bool"><![CDATA[1]]></property></response>


<- eval -i 7 -- KHN0cmluZykoJF9TRVJWRVJbJ1NFUlZFUl9OQU1FJ10p
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="eval" transaction_id="7"><property address="140734627130240" type="string" size="8" encoding="base64"><![CDATA[c3ltZm9ueTI=]]></property></response>


<- eval -i 8 -- KHN0cmluZykoJF9TRVJWRVJbJ1NFUlZFUl9QT1JUJ10p
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="eval" transaction_id="8"><property address="140734627130240" type="string" size="3" encoding="base64"><![CDATA[NDQz]]></property></response>


<- eval -i 9 -- KHN0cmluZykoJF9TRVJWRVJbJ1JFUVVFU1RfVVJJJ10p
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="eval" transaction_id="9"><property address="140734627130240" type="string" size="34" encoding="base64"><![CDATA[L3N0eWxlc2hlZXRzX2dydW50L2Nzcy9kZWZhdWx0LmNzcw==]]></property></response>


<- breakpoint_set -i 10 -t line -f file:///Users/akreps/src/athletepath/src/CoreBundle/Controller/UserController.php -n 184
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="breakpoint_set" transaction_id="10" id="773530217"></response>


<- breakpoint_set -i 11 -t line -f file:///Users/akreps/src/athletepath/src/CoreBundle/Controller/UserController.php -n 174
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="breakpoint_set" transaction_id="11" id="773530218"></response>


<- breakpoint_set -i 12 -t line -f file:///Users/akreps/src/athletepath/src/CoreBundle/Controller/UserController.php -n 185
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="breakpoint_set" transaction_id="12" id="773530219"></response>


<- breakpoint_set -i 13 -t line -f file:///Users/akreps/src/athletepath/src/CoreBundle/Controller/UserController.php -n 183
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="breakpoint_set" transaction_id="13" id="773530220"></response>


<- breakpoint_set -i 14 -t line -f file:///Users/akreps/src/athletepath/src/CoreBundle/Controller/UserController.php -n 181
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="breakpoint_set" transaction_id="14" id="773530221"></response>


<- breakpoint_set -i 15 -t line -f file:///Users/akreps/src/athletepath/src/CoreBundle/Controller/UserController.php -n 171
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="breakpoint_set" transaction_id="15" id="773530222"></response>


<- breakpoint_set -i 16 -t line -f file:///Users/akreps/src/athletepath/src/CoreBundle/Controller/UserController.php -n 176
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="breakpoint_set" transaction_id="16" id="773530223"></response>


<- breakpoint_set -i 17 -t line -f file:///Users/akreps/src/athletepath/src/CoreBundle/Controller/UserController.php -n 182
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="breakpoint_set" transaction_id="17" id="773530224"></response>


<- breakpoint_set -i 18 -t line -f file:///Users/akreps/src/athletepath/src/CoreBundle/Controller/UserController.php -n 190
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="breakpoint_set" transaction_id="18" id="773530225"></response>


<- breakpoint_set -i 19 -t line -f file:///Users/akreps/src/athletepath/src/CoreBundle/Controller/UserController.php -n 175
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="breakpoint_set" transaction_id="19" id="773530226"></response>


<- breakpoint_set -i 20 -t line -f file:///Users/akreps/src/athletepath/src/CoreBundle/Controller/UserController.php -n 179
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="breakpoint_set" transaction_id="20" id="773530227"></response>


<- stack_get -i 21
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="stack_get" transaction_id="21"><stack where="{main}" level="0" type="file" filename="file:///Users/akreps/src/Athletepath/web/app.php" lineno="6"></stack></response>


<- run -i 22
-> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="http://xdebug.org/dbgp/xdebug" command="run" transaction_id="22" status="stopping" reason="ok"></response>


<- run -i 23
Log closed at 2013-11-13 22:17:52



idea.log output after enabling com.jetbrains.php.debug debug logging:

2013-11-13 14:21:11,098 [ 581303]  DEBUG - .connection.PhpDebugConnection - 1509239325#----connection started
2013-11-13 14:21:13,069 [ 583274]  DEBUG - .connection.PhpDebugConnection - 1509239325#---input stream is finished
2013-11-13 14:21:13,070 [ 583275]  DEBUG - .connection.PhpDebugConnection - 1509239325#---stop reading
2013-11-13 14:21:13,070 [ 583275]  DEBUG - .connection.PhpDebugConnection - 1509239325#---stop writing
2013-11-13 14:21:13,070 [ 583275]  DEBUG - .connection.PhpDebugConnection - 1509239325#----connection stopped
2013-11-13 14:21:13,108 [ 583313]  DEBUG - .connection.PhpDebugConnection - 1785362477#----connection started
2013-11-13 14:21:13,404 [ 583609]  DEBUG - .connection.PhpDebugConnection - 1785362477#---input stream is finished
2013-11-13 14:21:13,404 [ 583609]  DEBUG - .connection.PhpDebugConnection - 1785362477#---stop writing
2013-11-13 14:21:13,404 [ 583609]  DEBUG - .connection.PhpDebugConnection - 1785362477#----connection stopped
2013-11-13 14:21:13,404 [ 583609]  DEBUG - .connection.PhpDebugConnection - 1785362477#---stop reading





And here's php-fpm -i | grep xdebug:


/opt/boxen/homebrew/etc/php/5.4/conf.d/ext-xdebug.ini
xdebug
xdebug support => enabled
xdebug.auto_trace => Off => Off
xdebug.cli_color => 0 => 0
xdebug.collect_assignments => Off => Off
xdebug.collect_includes => On => On
xdebug.collect_params => 0 => 0
xdebug.collect_return => Off => Off
xdebug.collect_vars => Off => Off
xdebug.coverage_enable => On => On
xdebug.default_enable => On => On
xdebug.dump.COOKIE => no value => no value
xdebug.dump.ENV => no value => no value
xdebug.dump.FILES => no value => no value
xdebug.dump.GET => no value => no value
xdebug.dump.POST => no value => no value
xdebug.dump.REQUEST => no value => no value
xdebug.dump.SERVER => no value => no value
xdebug.dump.SESSION => no value => no value
xdebug.dump_globals => On => On
xdebug.dump_once => On => On
xdebug.dump_undefined => Off => Off
xdebug.extended_info => On => On
xdebug.file_link_format => no value => no value
xdebug.idekey => PHPSTORM => PHPSTORM
xdebug.max_nesting_level => 200 => 200
xdebug.overload_var_dump => On => On
xdebug.profiler_aggregate => Off => Off
xdebug.profiler_append => Off => Off
xdebug.profiler_enable => Off => Off
xdebug.profiler_enable_trigger => Off => Off
xdebug.profiler_output_dir => /var/tmp/ => /var/tmp/
xdebug.profiler_output_name => cachegrind.out.%p => cachegrind.out.%p
xdebug.remote_autostart => On => On
xdebug.remote_connect_back => Off => Off
xdebug.remote_cookie_expire_time => 3600 => 3600
xdebug.remote_enable => On => On
xdebug.remote_handler => dbgp => dbgp
xdebug.remote_host => localhost => localhost
xdebug.remote_log => /Users/akreps/logs/xdebug.log => /Users/akreps/logs/xdebug.log
xdebug.remote_mode => req => req
xdebug.remote_port => 8999 => 8999
xdebug.scream => Off => Off
xdebug.show_exception_trace => Off => Off
xdebug.show_local_vars => Off => Off
xdebug.show_mem_delta => Off => Off
xdebug.trace_enable_trigger => Off => Off
xdebug.trace_format => 0 => 0
xdebug.trace_options => 0 => 0
xdebug.trace_output_dir => /var/tmp/ => /var/tmp/
xdebug.trace_output_name => trace.%c => trace.%c
xdebug.var_display_max_children => 128 => 128
xdebug.var_display_max_data => 512 => 512
xdebug.var_display_max_depth => 3 => 3




I've followed several tutorials and all of the instructions I can find, and still something eludes me.  Please offer any assistance you might have.  Thanks!
5 comments
Comment actions Permalink

Hi there,

idea.log output after enabling com.jetbrains.php.debug debug logging:

It should be MUCH MORE in that log -- I do not see any xdebug details here at all.

1) Where project is located? (FULL PATH PLEASE, exactly as it is -- that's important on MAC) -- prove it (may sound a bit rude, I know) with screenshot (important!)
2) Any symbolic links in the path ?
3) Have you EVER renamed any folder in that path (i.e. changed your user name .. or project folder (small letter to capital etc))?
4) Show a screenshot with breakpoint -- maybe you have set it in a line where xdebug is unable to break
5) Screenshot of "Setting (Preferences) | PHP | Servers"
6) "Run | Break at first line in PHP scripts" -- try enabling it
7) initiate breakpoint programmatically by placing xdebug_break(); in your code.
8) Try xdebug.remote_autostart = OFF and initiate debug connection manually, i.e. via bookmarklet or some browser extension etc (sometimes this option somehow prevents it from breaking... no real ideas why though)

0
Comment actions Permalink

I think I know the reason .. but I definitely need confirmation from you on first 3 questions at very least.

0
Comment actions Permalink

You nailed it, Andriy.  I noticed the logs referencing src/Athletepath but my project was actually in src/athletepath.  Now, OSX does not have a case sensitive filesystem but it seems either Xdebug or PHPStorm is a little more finicky.  I gave the pathname a capital A and the debugger started working as intended.  

Thanks so much!

0
Comment actions Permalink

This happens on Mac when you renaming folder in Finder and you only changing letters to opposite case. If you check the path in actual terminal you will notice the different letter cases.

So, next time do such rename in either Terminal/Console (or whatever it is called on Mac; recommended) .. or add some extra characters (when renaming in Finder) which you can then remove on next rename straight away.

This is Mac-specific issue -- does not happen on Linux or Windows (latter is case-insensitive anyway).

Now, OSX does not have a case sensitive filesystem

I'm not 100% sure on this ...  but AFAIK you can actually change that to have it (read about it somewhere on Internet).

0
Comment actions Permalink

Good ideas.  

It is possible to run your OSX install on a journaled, case sensitive filesystem.  The last time I tried, several applications failed, including Photoshop.  In the past I've run a small case-sensitive fs for the codebase so I can more easily emulate the environment the code runs in.  

Thanks again!

0

Please sign in to leave a comment.