Drupal version:
branch 8.x
devel version:
branch 8.x-1.x

How to reproduce:

1) Minimal D8 installation
2) enable Devel module
3) enable query log with default settings
4) navigate to homepage.

Displays notices:

Notice: Undefined index: file in Drupal\Core\Database\Log->findCaller() (line 159 of core/lib/Drupal/Core/Database/Log.php).
Notice: Undefined index: line in Drupal\Core\Database\Log->findCaller() (line 160 of core/lib/Drupal/Core/Database/Log.php).
Notice: Undefined index: file in Drupal\Core\Database\Log->findCaller() (line 159 of core/lib/Drupal/Core/Database/Log.php).
Notice: Undefined index: line in Drupal\Core\Database\Log->findCaller() (line 160 of core/lib/Drupal/Core/Database/Log.php).

AND
Doesn't display query log.

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

salvis’s picture

Priority: Minor » Normal
Status: Active » Needs work

Yes, I see that, too. Pretty nasty display...

salvis’s picture

Status: Reviewed & tested by the community » Needs review
Issue tags: -Needs backport to D7
FileSize
591 bytes

This is a bug in core. Log->findCaller() ignores the fact that the debug_backtrace() may not have file/line information for some of the calls on the stack. Here's what we get multiple times in the case that the OP describes:

(screenshot)

Specifically, in the call stack above, node_page_default() does not have file/line information (in PHP 5.3.8), and that's what trips up findCaller() .

Another issue presumably caused by this bug:
#1404854: Undefined index/offset error in "DatabaseLog->findCaller"

According to
#1323134: Request ability to have CCK module NOT evaluate (fire) default/allowed value PHP code when editing a field
Unknown error messages due to PHP-script in block.
#1434146: Notice: Undefined index: args en DatabaseLog->findCaller() (line 154 de /includes/database/log.inc
'args' can also be undefined, so we may as well default-initialize that one, too.

The attached tiny patch fixes this issue.

EDIT: Somehow the screenshot got broken and I have to edit the comment to refresh some cache, apparently.

salvis’s picture

Title: Notice when Query log enabled » Notice: Undefined index: file in Drupal\Core\Database\Log->findCaller()
Project: Devel » Drupal core
Version: 8.x-1.x-dev » 8.x-dev
Component: devel » database system
Status: Needs work » Needs review
Issue tags: +Needs backport to D7
Berdir’s picture

Noticed this myself as well.

Attaching a patch that improves this a bit by actually ignoring these as well, they are due using call_user_func_array() which is not helpful in any way and also added test coverage.

Status: Needs review » Needs work

The last submitted patch, log-notice-1739808-4-tests-only.patch, failed testing.

Berdir’s picture

Status: Needs work » Needs review

Testbot, what are you doing?

salvis’s picture

Status: Needs review » Needs work

Thanks, Berdir!

+++ b/core/lib/Drupal/Core/Database/Log.php
@@ -131,11 +131,9 @@ class Log {
    * We define "the routine that called this query" as the first entry in
    * the call stack that is not inside the includes/Drupal/Database directory
-   * and does not begin with db_. That makes the climbing logic very simple, and
-   * handles the variable stack depth caused by the query builders.
-   *
-   * @todo Revisit this logic to not be dependent on file path, so that we can
-   *       split most of the DB layer out of Drupal.
+   * does not begin with db_ and does have a file (which excludes
+   * call_user_func_array(), anonymous functions and similar). That makes the
+   * climbing logic very simple, and handles the variable stack depth caused by the query builders.
    *

After dropping the 'and' you need a comma now, as well as a comma before the succeeding 'and'.

The last comment line is way too long (>80).

+++ b/core/lib/Drupal/Core/Database/Log.php
@@ -154,7 +152,8 @@ class Log {
-      if (strpos($stack[$i]['class'], __NAMESPACE__) === FALSE && strpos($stack[$i + 1]['function'], 'db_') === FALSE) {
+      if (strpos($stack[$i]['class'], __NAMESPACE__) === FALSE && strpos($stack[$i + 1]['function'], 'db_') === FALSE && !empty($stack[$i]['file'])) {

Why is it not a legitimate caller, just because empty($stack[$i]['file'])? I think this should remain unchanged.

Berdir’s picture

It is legitimate, but it is not useful. The purpose of that function is to give you an idea where the query was executed. If there is no file, then we can IMHO be sure that it's not helpful in any way because it's something like call_user_func_array. See the test, without that check it would give you "call_user_func_array" as the caller and not the test method.

salvis’s picture

Agreed.

Do we also need a DBTNG test for the class case?

Berdir’s picture

Not sure what you mean, the namespace/class stuff is already covered because db_query() goes through various methods on classes within the database namespace and they are correctly ignored. So this just needs a re-roll for the comment changes.

salvis’s picture

Ok, never mind.

Berdir’s picture

Status: Needs work » Needs review
FileSize
956 bytes
9.56 KB

Fixed the comment.

salvis’s picture

Status: Needs review » Needs work

You posted the wrong patch file.

Berdir’s picture

Status: Needs work » Needs review
FileSize
2.99 KB

True. This one should be good. the interdiff was the right now.

salvis’s picture

Looks good, thanks!

GrzegorzNowak’s picture

I can confirm - that this patch removed the notice and query log is now displayed on "more" pages, but:
there still remains the issue of query log not being displayed on front page (whereas it seems to be displayed elsewhere).

salvis’s picture

there still remains the issue of query log not being displayed on front page (whereas it seems to be displayed elsewhere).

You're probably referring to #1748082: "Fatal error: [] operator not supported for strings" from the query log. I fixed that yesterday. Be sure to get the very latest -dev of Devel.

If that doesn't help, then open a new issue in the Devel queue. IAC it's unrelated to this issue here.

GrzegorzNowak’s picture

Status: Needs review » Fixed

Indeed - pulling the latest from Devel repo resolved the problem. Thanks!

Berdir’s picture

Status: Fixed » Needs review

It's fixed when it's commited. What you should do is set the status to reviewed and tested by the community, so that it can get commited.

GrzegorzNowak’s picture

Roger that.
ps. great job guys!

corvus_ch’s picture

Status: Needs review » Reviewed & tested by the community

Jep, that one does its job.

Verified with manual testing. Reproduced by following the the steps in the issue description. Then applied the patch an the notice was gone. (Devel version in use 8.x-1.x-dev).

salvis’s picture

Status: Needs review » Reviewed & tested by the community
Issue tags: +Needs backport to D7
FileSize
24.71 KB

(somehow the image in #2 was lost — here it is again)

webchick’s picture

Version: 8.x-dev » 7.x-dev
Status: Reviewed & tested by the community » Patch (to be ported)

Committed and pushed to 8.x! Thanks!

Moving to 7.x for backport.

salvis’s picture

Status: Patch (to be ported) » Needs review
FileSize
2.59 KB
1.23 KB

Backported to D7.

Berdir’s picture

Status: Needs review » Reviewed & tested by the community

Backport looks good.

David_Rothstein’s picture

Status: Reviewed & tested by the community » Fixed

Automatically closed -- issue fixed for 2 weeks with no activity.

gielfeldt’s picture

Issue summary: View changes

I'm getting this error too now. Looking at the patches, doesn't 'args' reside in $stack[$i + 1] and not $stack[$i] ?

gielfeldt’s picture

Status: Closed (fixed) » Needs work
salvis’s picture

Status: Needs work » Closed (fixed)
Issue tags: -Needs backport to D7

@gielfeldt: It doesn't make sense to reopen this old issue that was fixed and hasn't received any complaint in 3 years. Please open a new issue with all the relevant information.

kenorb’s picture