Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

added backtrace to query logging #535

Closed
wants to merge 1 commit into from
Closed

added backtrace to query logging #535

wants to merge 1 commit into from

Conversation

dmecke
Copy link

@dmecke dmecke commented Feb 28, 2014

I've added a stacktrace to each logged query to be able to display it later on. This can help to find out why a query has been executed.
This one is needed for pull request doctrine/DoctrineBundle#275 in doctrine/doctrineBundle.

@doctrinebot
Copy link

Hello,

thank you for creating this pull request. I have automatically opened an issue
on our Jira Bug Tracker for you. See the issue link:

http://www.doctrine-project.org/jira/browse/DBAL-824

We use Jira to track the state of pull requests and the versions they got
included in.

$this->queries[++$this->currentQuery] = array('sql' => $sql, 'params' => $params, 'types' => $types, 'executionMS' => 0);

$trace = debug_backtrace();
if (function_exists('xdebug_get_function_stack')) {
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

copied from Symfony\Component\Debug\FlattenException::setTraceFromException - is there a place to share this code for non-exceptions?

@@ -62,7 +62,33 @@ public function startQuery($sql, array $params = null, array $types = null)
{
if ($this->enabled) {
$this->start = microtime(true);
$this->queries[++$this->currentQuery] = array('sql' => $sql, 'params' => $params, 'types' => $types, 'executionMS' => 0);

$trace = debug_backtrace();
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this should be inside the else to avoid useless processing

@Ocramius
Copy link
Member

@dmecke this is seriously overboard. Just store debug_backtrace(true) in a key and that's it :)

@@ -26,6 +26,7 @@ public function testLoggedQuery()
'params' => null,
'types' => null,
'executionMS' => 0,
'stacktrace' => null,
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The test fails, because the stacktrace is already set with an actual array. How can I test this here without that failure?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Anyone who can help me? Or should the stacktrace simply be removed from the test as we cannot know what should be in there?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You can only do minimal assumptions on it, such as "it is an array", and "it is not empty"

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, but how can I do that inside the assertEquals for the whole array? I mean that general assertEquals will now always fail because of that one new element...
I am sorry, but I am new to unit tests and such cases still gives me some headaches.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@dmecke you simply can't use assertEquals here - it is too generic. Use multiple assertions instead.

@dmecke
Copy link
Author

dmecke commented Apr 4, 2014

Ok, I fixed the tests now, thx @Ocramius for your help! Now the travis build still fails for sqlite and mysqli, but this is the case in the master as well, so I think it's not a problem about this pull request.
Anything else to do here?

@deeky666
Copy link
Member

deeky666 commented Apr 4, 2014

@dmecke The current master is not failing as far as I can see. But your PR branch uses a rather outdated codebase. Maybe the master tests were failing back then. Try to rebase your PR branch with current master and see what travis says.

@deeky666
Copy link
Member

deeky666 commented Apr 4, 2014

Hmm weird. There seems to be a problem with locked tables: https://travis-ci.org/doctrine/dbal/jobs/22262335#L418
IMO it must have something to do with your PR because the last commit into master was successful: https://travis-ci.org/doctrine/dbal/builds/21987946

@deeky666
Copy link
Member

deeky666 commented Apr 4, 2014

I'm not that familiar with debug_backtrace() but may it be that the trace keeps the database resources alive and therefore the driver fails to execute subsequent commands? Something like that?
@Ocramius thoughts?

@stof
Copy link
Member

stof commented Apr 4, 2014

If you use debug_backtrace()t, it will indeed keep the objects alive. This is a big issue IMO (for memory usage as well btw).

IMO, the DebugStack should not keep the stacktrace in memory. If you want to log the stack trace of queries, you should do it with a custom logger which processes the stacktrace just after retrieving it, so that it does not keep it around

@stof
Copy link
Member

stof commented Apr 4, 2014

Thus, if your use case is storing the backtrace of queries in the Symfony profiler, you will need to process it anyway, because it needs to be serializable to be stored anyway

@deeky666
Copy link
Member

deeky666 commented Apr 4, 2014

I agree with @stof. The chosen approach is more harmful than useful then and can lead to unpredicted behaviour. We should not merge this IMO. This should be done elsewise as suggested.

@fprochazka
Copy link
Contributor

You should foreach it and drop references to objects and propbably even call arguments.

@guilhermeblanco
Copy link
Member

You can create your own Logger for this support.
Adding this have resources usage implication and therefore cannot be blindly added.
I also see a potential serialization issue depending on the driver used to log this information.

Closing as won't fix.

@dmecke
Copy link
Author

dmecke commented Apr 22, 2014

Ok, thanks for your time.

@Koc
Copy link
Contributor

Koc commented Jun 13, 2015

ref #719

@ostrolucky
Copy link
Member

Implemented in doctrine/DoctrineBundle#954

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Aug 9, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

9 participants