Posted by mkalkbrenner on March 4, 2010 at 9:08pm
| Project: | Drupal core |
| Version: | 8.x-dev |
| Component: | search.module |
| Category: | bug report |
| Priority: | normal |
| Assigned: | Unassigned |
| Status: | needs work |
Issue Summary
The search module logs all searches to watchdog. I attached a patch that allows to turn this logging on or off.
| Attachment | Size | Status | Test result | Operations |
|---|---|---|---|---|
| watchdog_searches_logging_configurable-D6.patch | 2.78 KB | Ignored: Check issue status. | None | None |
Comments
#1
I'm not convinced this would be regarded as a bug but rather as a feature, in which case there's no chance of it making 6.x and possibly not 7.x even (easy enough to do via hook_form_alter() anyway to avoid hacking core).
#2
I am not sure what you mean by using hook_form_alter() to accomplish this. In Drupal 7, at least, the watchdog logging is done on every search during search_view() [the page callback for the search page].
Anyway, yes it is a feature request and it needs to be put up for consideration in Drupal 8 at this point.
#3
#4
I understand that you'll treat this as a feature request and I'll be happy if my patch will goes into drupal some day, no matter if it's drupal 7 or 8.
But we run a website on drupal 6 which mostly consists of apachesolr search results. In this case it's a real performance impact that nearly every page request triggers an INSERT statement on the database. That's why consider it as a bug if you cannot turn this off (by configuration). For those who want to see this issue fixed in drupal 6 it might be interesting to get an already patched drupal 6 version from http://drupal.cocomore.com/de/project/drupal
#5
OK, I see your point. I'm willing to consider it to be a bug. At this point, we fix bugs in Drupal 7, and then consider backporting to Drupal 6.
#6
#7
Thanks a lot!
#8
@2: Aahhhhhh yes fair point, in a custom module we can use hook_form_alter() to create an additional setting, and we can implement hook_watchdog() to perform additional or custom logging, but there is no particularly clean way of preventing http://api.drupal.org/api/function/search_view/6 from doing its watchdog call or of intercepting dblog_watchdog() to filter out "search" log entries.
The only options that come to mind - to avoid hacking core - are:
1. override the search module paths that use the search_view callback and replace with a custom implementation that doesn't invoke watchdog()
2. copy modules/watchdog to sites/all/modules/custom/dblog (i.e. make a drop-in replacement) and there in dblog.module in dblog_watchdog() filter out the messages which have $log-['type'] == 'search'.
Playing devil's advocate: why should search module get special treatment and allow its watchdog calls to be filtered out? Shouldn't we come up with a more generic way of handling this?
And if performance is an issue, maybe that's what syslog.module is for?
#9
I see your point, but most modules don't log as much as the search module does, and they mostly log admin tasks like creating nodes, deleting users, etc., rather than ordinary anonymous user tasks like doing a search.
#10
I adjusted the patch to be applicable against Drupal core 7.0. I also changed the default setting to log the searches for compatibility reasons.
#11
mkalkbrenner: At this point, we probably can't add anything to the Drupal 7 user interface, so we would either need to (a) push this off to Drupal 8, (b) convince webchick/Dries that this is important for Drupal 7, or (c) add it as a variable_set() without adding in a user interface for setting it (i.e., it would just be something you would set in your settings.php file for a site).
It probably also needs a test to be added to the search test suite.
Also, when you attach patches, please set the issue status to "needs review" so that people know there is a patch, and so that the test bot will run the test suite and make sure the patch doesn't break anything else. Thanks!
Regarding this specific patch:
// Log the search keys.- watchdog('search', 'Searched %type for %keys.', array('%keys' => $keys, '%type' => $info['title']), WATCHDOG_NOTICE, l(t('results'), 'search/' . $info['path'] . '/' . $keys));
+ if (variable_get('search_log_searches_to_watchdog', 1)) {
+ // Log the search keys:
+ watchdog('search', 'Searched %type for %keys.', array('%keys' => $keys, '%type' => $info['title']), WATCHDOG_NOTICE, l(t('results'), 'search/' . $info['path'] . '/' . $keys));
+ }
It's probably not necessary to repeat the "Log the search keys" comment. Also, all comments should end in a . not a :, to comply with Drupal coding standards (see http://drupal.org/node/1354).
#12
@jhodgdon:
Done.
It was you who turned this feature request into a bug for D7 on March 5, 2010 at 6:53pm ;-)
I adjusted my patch to be compatible to Drupal 7.0. Anything else is up to the maintainers: accept or reject the patch, remove the settings part, port it forward to D8, write tests for it, ...
Or leave it in the issue queue for years like other core issues ;-)
See http://lists.drupal.org/pipermail/development/2008-October/031240.html and http://lists.drupal.org/pipermail/development/2008-November/031310.html
BTW I don't see a blocker to integrate the patch in D7. Until somebody disables the new checkbox, nothing will change. But the user has the option to speed up his system.
#13
I realize I turned it into a bug. However, that was nearly a year ago, and since then Drupal 7 has been user-interface-frozen, not to mention released, so things have changed. Meaning that at this point, the people who make the final decisions (webchick/Dries) probably won't accept into Drupal 7 patches that change the user interface.
Regarding "up to the maintainers"... The only way core issues move from being in the issue queue to being committed is if someone who is interested in the issue works on the patch and gets it to a point where it is up to the standards we have for Drupal. It's a community project, and we are all volunteers. We work on what's interesting to us, or what someone finds interesting enough to fund. Despairing about issues staying in the queue forever is not really all that welcome, nor is "that's all I'm doing, you work on it". Besides which, at the moment the core search module doesn't really have an active maintainer, for all practical purposes.
So off-hand I don't know of anyone besides you who is likely to work on fixing up the patch so that it can be committed -- you seem to be the only person who is interested in getting this fixed. I volunteered my time to let you know what you would need to do to get this issue resolved... If you care about this issue, continue to work on it or convince someone else who has time that it's worthwhile. If you don't, it's not likely to go anywhere. That's the reality... sorry!
#14
Stable versions are string-frozen which means that no strings can be added or changed.
What might be possible to get into Drupal 7 at this point is a patch without UI, so that it is only possible to override the setting through $conf in settings.php.
Anyway, If you're worried about watchdog performance, you might want to replace dblog.module with something else, syslog.module for example, or http://drupal.org/project/mongodb.
#15
@jhodgdon: Please don't get me wrong. It was not my intention to start a flame war here. And I really appreciate your participation.
If a find a bug or a possible improvement in drupal core I'm always posting a patch in the issue queue. And I'll keep doing so. But I don't have the time to keep these patches up-to-date for months and years.
BTW I'm not the only one interested in this issue: #732956: Logging searches to watchdog should be configurable
@Berdir:
Thanks for your hints. I'm aware of syslog and MongoDB. (One year ago dereine and I did a quick and dirty Drupal-5 backport of the mongoDB based watchdog replacement for a customer.)
My intention was to offer a little improvement for normal site administrators. For those who prefer a settings-only version I attached an alternative patch.
#16
Yeah. Keeping a patch up to date forever isn't fun. All I'm saying is that the alternative plan would be to take the patch to where it can be committed, and then it's done.
This latest patch looks more promising in that regard, in that it could actually be committed, if it's verified and probably it needs a test. Thanks!
#17
I agree with @Bedir, if logging is a performance hit, the solution could be to use a different watchdog implementation (I thought of the exact same solutions, syslog or mongodb_watchdog).
But we might consider a new issue to drupal_alter watchdog in D8. If we had this, we could write a contrib module to filtering any message, not just search messages. I'm not sure however, if adding an alter for watchdog, might introduce additional overhead, instead of solving the problem.
#18
Actually, we can do this already without the new hook, I've done something like this (actually @chx did it) before in a custom module:
<?php
/**
* implements hook_module_implements_alter().
*/
function nosearch_watchdog_module_implements_alter(&$implementations, $hook) {
if ($hook == 'watchdog' || $hook == 'cron') {
// dblog_watchdog() will be called from our own watchdog implementation
// when necessary.
// dblog_cron() is not necessary and it won't work. While install tries to
// kill it with a variable, better safe than sorry.
unset($implementations['dblog']);
}
}
/**
* implements hook_watchdog().
*/
function nosearch_watchdog_watchdog($log_entry) {
if ($log_entry['type'] != 'search') {
dblog_watchdog($log_entry);
}
}
/**
* implements hook_menu_alter().
*/
function nosearch_watchdog_menu_alter(&$items) {
$paths = array_keys(dblog_menu());
foreach ($paths as $path) {
$items[$path]['access callback'] = FALSE;
}
}
Can we mark this as 'wontfix'?
#19
Is someone able to explain why it makes sense to log search requests in the watchdog?
The watchdog is not suitable for statistics.
Logging every search query is like logging every comment that gets posted.
#20
Subscribing (D6)
#21
The solution for D7 is above. This will likely never get changed in D6. The question is does this make sense for D8.
I doubt that the actual logging of the results is the worst bit of search's performance. While this is an easy thing to take out, I'd like to see performance tests to justify it. My gut tells me that this is 1-5% of the total search time, but that's just my gut.
For a performance test, I'd load up a test site with 10,000 nodes (using devel generate), index it (using drush search-reindex), then write two drush commands, one that prepped a file with my search terms (values in and out of the index, single and multiple terms, but probably 90% single terms, don't duplicate searches though) and another that just read the terms from a file and did the search. I'd like to see the xhprof output, but a simple command line time before and after would be a helpful start.