HTTP request checking is unreliable and should be removed in favor of watchdog() calls

Yes, please. ;) We should also ensure that the update manager does likewise. I can't do so myself anytime soon, but I hope someone will...

Thanks,
-Derek

linkchecker also use drupal http request and have it's own status code/error handling logics. Make sure this will not break, please.

When the current behavior isn't working correctly, it can cause a severe slowdown when visiting the admin pages of the site that makes it extremely difficult to perform site administration tasks. However, the bug only seems to affect a small number of users.

The current logic can result in many, many calls to variable_set(), since it keeps trying to set the same variable over and over until there's a successful request. There could also potentially be a race condition where the process that sets the variable off again is overwritten by another process. Either way the current method is really bad.

I just marked #959620: drupal_http_request() can lead to variable_set() stampede as duplicate. Switching from a variable to watchdog sounds better than my idea over there though.

One of my D6.20 sites is suffering from the very slow admin referred to in #1 and #3. Been wading through the many threads but hope someone on this thread know the best patch/solution to remove the error and reset whatever flag needs to be reset in the database. The Update Status works fine, btw, but admin issue is creating enormous headaches. Thanks.

I have had this exact problem.
Short summary:
ipvsadm/ldirectord DNAT load-balancing setup, with the webservers on the internal range 192.168.1.0/24, and the website on $external_ip .

Symptoms:
- The internet -> $external_ip -> 192.168.1.0/24 => works
- 192.168.1.0/24 -> the internet => works
- 192.168.1.0/24 -> $external_ip => times out.
It seems ipvsadm/ldirectord is simply broken.

Solution:
Add this iptables rule on the webservers:
iptables -t nat -A OUTPUT -p tcp -d $external_ip --dport 80 -j DNAT --to-destination `ifconfig | sed -n "s/.*inet addr:\(192\.168\.1\.[0-9]*\).*/\1/p"`
You may have to tweak it slightly to get it to work for you (this assumes your internal range is as mentioned above).

Subscribe

As this is merely a continuation to improve already fixed things, it's a task.

We still have this line in drupal_http_request():

    variable_set('drupal_http_request_fails', TRUE);

Still a bug.

Tagging issues not yet using summary template.

I'm strongly against this patch. In linkchecker I'm still doing drupal_http_request(), but i'm logging a *helpful* message what the reason really was and some other stuff if an action was taken. With this patch just fill watchdog with garbage and eat performance if drupal_http_requests are running and make all just more unreadable. As database performance is a real problem here, the http function themself should not save anything in watchdog. Maybe do it in hook requirement, but this patch is currently not modular and affects all drupal_http_request() requests what is not ok.

Count me -1 on the watchdog call as well.

Whether or whether not a failing HTTP request is actually a hard failure or error is application-level logic. Calling code needs to check that. Only application-level logic can decide whether it is a unexpected error.

The database load from watchdog calls pales in comparison to variable_set(). That said I would have no problem simply not logging failures internally and expecting calling code to handle it.

I'm checking ~200-500 or more links per cron run (depends on setting). This could result in 500 watchdog entries + a few hundred other db transactions. It's already expensive enough, don't add more slowliness, please. The function drupal_http_request() should not log the watchdog calls. Make the error handling outside of drupal_http_request() e.g in the code where the drupal_http_request() has been called. I must have a highly performant drupal_http_request() and i do not like to clone the function only because of modularity issues. This drupal_http_request() is an api function for http requests not a reliability checking function. For me it's very important to get all resulting status codes back in a consistent way. This consistency has already been broken in d7 and require conditions now, if status code is 3xx. But i can workaround this inconsistencies. :-(

Don't try to make drupal_http_request() intelligent... Just make it simple - call drupal_http_request() with parameters, check the link (in a reliable way), may follow a redirection, and provide all results back to the caller function, do status code handling outside the drupal_http_request() function in the calling function.

@hass - while it might make sense to have no reporting in the function, your performance argument makes no sense. The watchdog here is only replacing a variable_set() call, which is considerably worse (merge query, cache clear, cache rebuild then set). Additionally no errors are supressed here, that was the only behaviour change.

Maybe, but a variable call does not fill a watchdog table with 1.000.000 or more entries only for the reason that other modules make use of the function. As sun also said, error handling is application logic not api function logic. I'm also for removing the variable set. I very often see network issue errors with negative numbers, but the local system is absolutly fine. Triggering a functionality check for every negative error code - also have negative side effects.

How about this:

We remove the watchdog from drupal_http_request()

But then, we add back a system_requirements() that does the same check as now, but logs to watchdog if it fails.

Also we flood limit the system requirements() check to once every 24 hours or similar so it isn't done every request on /admin (could possibly include the variable, or a cache entry or something rather than rate limit so if it passes it only happens occasionally rather than flood).

And we add some documentation to drupal_http_request() to make it explicit that functionality that expects the check to work needs to log its own errors etc.

#20 sounds good.

Well I'd be fine with removing all error logging from drupal_http_request(), and the hook_requirements(), and also adding watchdog messages to every place in core that does not handle it properly.

An example of when you might not want to have logging to watchdog when it fails is doing something like http://www.downforeveryoneorjustme.com/ in Drupal.

Not quite what I said in #20 but this might be enough? Restricts the system_requirements() check to once every 24 hours, removes the variable, no new messages anywhere so no string changes.

Nice clean-up. One small nit:

+++ b/modules/system/system.install
@@ -466,14 +466,17 @@ function system_requirements($phase) {
+    if (flood_is_allowed('system_http_request', 1, $window = 86400, 'system_requirements')) {
+      flood_register_event('system_http_request', 86400, 'system_requirements');

The $window = 86400 is unnecessary (and located a bit unconventional).

Weird, fixed that.

Note this patch does not yet go through core checking for real instances of drupal_http_request() that might fail and need a watchdog message, that should probably be added to update status if it's not already. Re-rolled with that change though.

Here's a start on that, but I ran out of steam, some places are already checking for errors, some just ignore failures altogether.

Full list at http://api.drupal.org/api/drupal/includes--common.inc/function/drupal_ht...

Tagging for backport.

Did some more stragglers, everything else was already checking errors in one way or another.

#33: drupal_http_request.patch queued for re-testing.

#926426: system_check_http_request() causes deadlock on single threaded webserver has been marked as a duplicate of this issue.

Rerolled

Lets see if this helps

#40: drupal_http_request.patch queued for re-testing.

There's some junk at the end of that patch that is changing file permissions or something. Was that intended?

That just looks like cruft to me, removed.

Ooops, sorry was unintended junk

+++ b/core/modules/aggregator/aggregator.admin.inc
@@ -339,6 +339,9 @@ function aggregator_form_opml_submit($form, &$form_state) {
+    else {
+      watchdog('aggregator', 'HTTP request to !url failed with error: !error', array('!url' => $form_state['values']['remote'], '!error' => $response->error));
+    }

$response->error can contain stuff provided by a third party, i.e. it is untrusted user provided input. Therefore the "@" placeholder must be used for sanitization. I would suggest to just always use "@", also for the URL.

Yeah treating these as untrusted input makes sense, patch makes those changes. Patch size is slightly smaller since we no longer have a clean URL check in 8.x.

D7 and D6 backports. I left the system_check_http_request() function in the backports just in case a contrib module is using it.

If you're leaving in system_check_http_request() for backports then do we need to reopen #926426: system_check_http_request() causes deadlock on single threaded webserver because, as you say, it could get called by contrib.

Hmm I'd probably instead want to file issues against those contrib modules (if they exist) suggesting they just log to watchdog on fails instead, since we decided here that the function doesn't make sense anyway.

The only reason to leave it in is just in case some code somewhere happens to be calling it so people don't get fatal errors after upgrade, even if we check all of contrib it's not impossible a custom module somewhere is calling it.

Maybe for the backport, just leave the function in place as:

function system_check_http_request() {
  watchdog('php', t('The system_check_http_request() function is deprecated. See <a href="@url">the issue where it was deprecated</a> for more.', array('@url' => 'http://drupal.org/node/965078')));
}

Or something. ;) Doesn't cause a fatal, but nags them to fix their stuff, and doesn't leave us carrying around dead code.

Just a thought,
-Derek

But not in D6/D7, please.

We're only talking about D6/D7 here. Either this function is dangerous and shouldn't be used, or we fix it. We're deciding against fixing it. Hence, deprecating it. If your code relies on it, you're probably screwed and need to change your code.

I have two projects in public releases that use the function in hook_requirement. Both modules would break; if this is silently removed. ~15.000 installations.

Yeah I think just

Hmm I'd probably instead want to file issues against those contrib modules (if they exist) suggesting they just log to watchdog on fails instead, since we decided here that the function doesn't make sense anyway.

works for that then. We can add @deprecated to the D7 docs.

What's the chance of an RTBC for the 8.x patch?

@hass: Both modules are already broken, since the function they're calling is unreliable and broken. But that's your problem, not mine. ;)

@catch: #46 looks good to my eyes, the bot is happy. I'm not particularly trusting of update manager test coverage, but the diff to update.fetch.inc looks fine to me. I doubt anyone knows if update manager actually works in D8 yet. ;)

So yeah, for D8, #46 is hereby RTBC. I love patches that remove a lot more lines of code then they add and keep the same level of functionality.

Cheers,
-Derek

catch seems to be very involved with this patch so I'll let him handle it.

I skimmed the patch and it seems like it is a nice simplification, in addition to being a bug fix.

This patch may creates some support troubles for Link checker. Link checker for sure - expect to see failed requests to be able to notify authors about these failed links.

With this patch I cannot say for sure if the module works reliable or not - as the underlying infrastructure may be broken, but I have no indicator for this. This is really bad as past code - helped a lot when it comes to support analysis. It would much more helpful to have a real status flag that tells me if a Drupal site can issue reliable HTTP requests or not. Than I'm able to exit before running 1000+ HTTP requests in one cron run as I know all of them will fail. With the patch I can only guess by the number of same fails and strange errors that something may be wrong or not with the server. I remember it was not only failed to create socket type issues in past... :-(

Why is there no way to make a "reliability check" where a system variable can be evaluated by other modules; if the module may work or not?

@hass: there's no way to make a reliability check, because various combinations of server configuration can cause either false positives or false failures for the check. See #245990: HTTP request testing unreliable and may be undesirable and #926426: system_check_http_request() causes deadlock on single threaded webserver for some of the reasons.

I've gone ahead and committed/pushed this to 8.x, moving to 7.x for backport since we definitely want to backport most of this.

I'd already done a backport in #47, re-uploading that with a bot-testable name.

Completely different patch from a completely different issue..

If we decide to keep system_check_http_request() in D6 and D7 for BC reasons, I suggest adding a timeout on, say 10 seconds, to the drupal_http_request() call.

Here's a patch that adds that.

I opened #1635882: Remove stale drupal_http_request_fails variable for dropping the variable so we can keep the backport smooth here (that also has some retrospective justification for not adding an update, although thinking about it more on balance we should probably add one).

@deprecated sounds good to me, I don't have time to re-roll the patch, but tagging Novice in case someone else does just for adding that to system_check_http_request()

#10: http_request_D7.patch queued for re-testing.

Rerolled to add "DEPRECATED:" to the system_check_http_request() function description and the "@deprecated" directive.

The HTTP Request Fail Reset D6 module is very helpful with this if your problem is intermittent and you have no admin access to edit things on the server.

#67: replace-http-request-checking-965078-67.patch queued for re-testing.

I'm not sure WATCHDOG_WARNING is appropriate, some external requests will just fail because a service was down or temporary network issues, and that's not a problem with the Drupal site itself.

Moving back to 8.x for the rest of the discussion though.

Moving back to D7 as D8 is using guzzle.

#67: replace-http-request-checking-965078-67.patch queued for re-testing.

needs reroll

DrupalCon Portland Sprint: Working on Issue Summary Update

We are working today with this issue during Code Sprint UA

I didn't managed to even start work on this issue during code sprint.

FYI: the patch from comment #67 applies cleanly on the current 7.x-dev HEAD (tested @9am GMT on 05-Jun-2013 directly after a "git pull")
because it's a D7 patch !!

it seems the fact that this issue keeps flip-flopping between D8 and D7 is adding to the confusion.

assigning this to myself

i see a few things here that just need formalizing to progress the status of this issue, it seems all the work has been discussed and completed, it's just being held-up and needs someone to take ownership and bring it home

removing "Needs Reroll" and "Novice" tags

as far as i can tell reroll is *not* needed and additionally giving a task like this to a novice is just going to send them down a painful path of time-wasting discovery, when the real issue is that this is a D7 patch failing against the D8 codebase, which is perfectly normal and expected !

removing "Needs issue summary update" tag

because that was tagged in comment #11 on July 29, 2011 at 7:50pm and it seems was never done, although the summary seems perfectly adequate in content, it doesn't use the template format and it could use some extra details to clarify the current position (i will do that)

the new issue #1635882: Remove stale drupal_http_request_fails variable takes care of previous concerns about this unused variable creeping into D8 via a D7 upgrade.
[edit: removed because as catch informs in the next comment, CMI in D8 makes these variables entirely redundant anyway :]

i'm concerned that if i just flip this issue back to 7.x-dev to get the patch commited someone else will revert it back to 8.x-dev (as before), this is new territory for me so i need some time to find out the correct way to get both the working D8 patch & the D7 backport patch tested, reviewed and ultimately commited.

We can actually leave the stale variable in 8.x now, since all variables are stale with the API being removed - although an update to specifically remove it would also be fine - less in that table for people who are checking custom site updates.

The quickest way to get this issue done would be to discuss/resolve the remaining issues from #70.

The watchdog warning and error code both make sense, but that's actually been done already with the Guzzle conversion, see this from aggregator for example:

    catch (BadResponseException $e) {
      $response = $e->getResponse();
      watchdog('aggregator', 'The feed from %site seems to be broken due to "%error".', array('%site' => $feed->label(), '%error' => $response->getStatusCode() . ' ' . $response->getReasonPhrase()), WATCHDOG_WARNING);
      drupal_set_message(t('The feed from %site seems to be broken because of error "%error".', array('%site' => $feed->label(), '%error' => $response->getStatusCode() . ' ' . $response->getReasonPhrase())));
      return FALSE;
    }
    catch (RequestException $e) {
      watchdog('aggregator', 'The feed from %site seems to be broken due to "%error".', array('%site' => $feed->label(), '%error' => $e->getMessage()), WATCHDOG_WARNING);
      drupal_set_message(t('The feed from %site seems to be broken because of error "%error".', array('%site' => $feed->label(), '%error' => $e->getMessage())));
      return FALSE;
    }

Logging the full URL or not I'm not sure, I'd probably add the 'access site reports' permission to the security sensitive ones, since if you're debugging an issue with this, you really want to see the whole string, and in 8.x the string mostly comes from Guzzle itself as the exception message which we can't control the contents of.

I've opened #2012468: Add trusted roles recommendation to 'access site reports' for that in 8.x to discuss.

The error handling/message is going to be slightly different in 7.x so if we wanted to be more circumspect there we could.

Given that, I think we can move this back to 7.x again. Re-rolling the patch with WATCHDOG_WARNING would be a good start to get things moving towards a commit there.

@catch thanks very much for those clarifications.

this D7 patch adds the WATCHDOG_WARNING severity level.

with the extra parameter to the watchdog function calls i felt it was a good time to break it down to enable the code to be a bit more "readable".

Drupalcon Sprint: Updated Issue summary

Updated issue summary (1st pass).

Updated issue summary (add a related issue and tidying :).

just my sloppy coding.. whoops!

Important:
If you are reviewing this patch please also consider the comments from #70 as part of the code review.

updated the issue summary as best i could,
hopefully this will help us to make progress.

standing down.. *salutes*
(but still available for additional work/tasks :)

re #88:

i'm trying to balance the overhead of an "access site reports" check against just "clipping" the query-string part of the URL (anything after the ?= i.e. name/value pairs / tokens etc) which is fairly trivial.

my argument is that the fact that it's failing is a more useful piece of information than the URL at which it fails (because essentially it will fail for all --external-- URLs regardless of the location or what parameters were passed)

trim it, report it and done.. no security concerns :)

@catch you raise a valid point (when debugging more information is useful) but how to isolate the "security sensitive ones" ? how to test for that ?

The query string might cause a 500/401/403/404 depending on what's at the other end - there's both network issues and response codes from the endpoint to consider.

It's not just URLs that get into dblog though, PHP errors, node titles - there's lots of situations where there's potential information disclosure to the person reading the logs that they otherwise might not see elsewhere on the site.

Updated issue summary (more detailed Remaining tasks).

Updated issue summary (i corrected some mistakes made in my initial understanding).

Updated issue summary.

Updated issue summary.

had another go at updating the issue summary because there was some confusion in my understanding of the Remaining tasks section. I think it is accurate now.

Updated issue summary (more tinkering).

i have been thinking about the 'access site reports' permissions issue and my conclusion is that the logic to implement that functionality belongs in the watchdog module, not in other modules that are generating log messages.

if a module is generating a log message then it's responsibility is to provide the most complete and appropriate information about the situation that it is capable of, the module should not need to be concerned about who might or might not view that message.
(of course it should still perform sanitization of untrusted values as usual)

when the watchdog module detects a message that contains a URL it needs the ability to decide if it will show it or mask it in some way, i think this is outside of scope for this issue and we should spawn a separate issue to handle this permissions check in the watchdog module if that is the way forward.

Can I ask what is the reason for patching in watchdog messages in every place that drupal_http_request() is called?

Why not just replace variable_set('drupal_http_request_fails', TRUE); with a watchdog message from within the drupal_http_request() function?

Updated issue summary.

91: http-request-checking-d7-backport-965078-91.patch queued for re-testing.

91: http-request-checking-d7-backport-965078-91.patch queued for re-testing.

gonna give a try!

I am just gonna be bold and set RTBC again. It still passes tests, the @url within watchdog should not be a real problem - but if it is it can be set back to CNW and we can just remove the URL from the message as before there was no message at all ...

And this is still fixing the cache_set stampede.

#2012468: Add trusted roles recommendation to 'access site reports' is fixed, hoping someone is willing to take up this helm again.

Patch still works.

Hmm, should be testing #91, not #47.

Okay, I thought hard about it and while I did RTBC this before, I am no longer convinced as much.

The biggest trouble is the variable_set() (Performance wise) and that it is very unreliable anyway.

On the other hand this variable_set() has brought down more than one site for me.

While the UX of aggregator, etc. sucks, those are essentially other issues.

For here I first suggest to fix the issue at hand:

+ if (variable_get('drupal_http_request_fails', FALSE) === FALSE) {
    variable_set('drupal_http_request_fails', TRUE);
+}

That would do one variable_set() until the next time the status report is checked for.

That is still not good, but better than to clear the variable_cache again and again.

The aggregator thing, etc. can be nice follow-up issues, but are independent of this one.

Note: This makes it also possible to just do a quick and simple:

$conf['drupal_http_request_fails'] = NULL;

to remove the check completely for custom installations, which we could recommend.

@Fabianx:

This is a backport issue, so are you suggesting removing the watchdog calls from D8?
If not then what's the problem with having feature parity?

Also whilst it may not work perfectly the current system and proposed watchdog system both allow admins to be flagged of connection issues, whereas $conf['drupal_http_request_fails'] = NULL; would mean this ability is lost.

I don't really care if it appears in the status report or watchdog log, but I'd like to have visibility, arguably watchdog even provides greater visibility.

#112: What I mean is:

We should split this into:

a) A feature request / task to have watchdog() and co log those messages.

b) A bug fix to not set the variable again and again if we know that a request failed.

I don't care which issue should be used for which, but the D8 backports are new functionality the system gains, while the http_request fails can bring a site down.

That means I don't want to mix a bug fix with new functionality.

The problem is if we remove the http_request fails completely, custom code would not log any message - intentionally, but that means a behavior change and I believe that should be opt-in.

We could expose the http_request fails in the UI in a follow-up after the watchdog message is in, too then:

So three steps is what I propose:

1. Ensure that drupal_http_request fails does no longer bring down and site and can be disabled by setting NULL (settings.php only).

2. This patch by adding all the nice watchdog calls to aggregator and co (Great!)

3. Expose the settings.php setting in the UI to allow to turn off messages once contrib has used watchdog to display messages, too when something fails in drupal_http_request.

Splitting this in two sounds good. I'd do the quick bug fix here and open a new issue for the watchdog() calls.

I am gonna open an issue for the bug fix "soon" (as soon as I get back to the core queue) - unless someone beats me to it. Adding a tag for issues I want to focus for the next bugfix release on.

Any movement here?

This remains a major bug, although dormant for years. The check relies on the following line in system.module
drupal_http_request(url('', array('absolute' => TRUE)), array('max_redirects' => 0))
The request is supposed to call the front page and checks for status code between 100 and 600. Without that status code it returns false and sets drupal_http_request_fails to true.

We can check what this code does with drush php-eval "var_dump(drupal_http_request(url('', array('absolute' => TRUE)), array('max_redirects' => 0)));"

There are several common scenarios in which it returns 'false' (and sets drupal_http_request_fails to true) on a working site. If your base url is not set (and for example drush uli outputs http://default/...), the output is

object(stdClass)#19 (2) {
  ["code"]=>
  int(0)
  ["error"]=>
  string(71) "php_network_getaddresses: getaddrinfo failed: Name or service not known"
}

If you set your base URL but your SSL certificate is not valid, the output is:

object(stdClass)#20 (2) {
  ["code"]=>
  int(0)
  ["error"]=>
  string(58) "Error opening socket ssl://mysite.com:443"
}

The results are however unpredictable. On a server where we firewall port 80, opening port 80 causes the message to disappear without altering the results of that drush command (or of calling the checking function which populates the status report using ).

So, For Drupal 7.x is the patch from #91 still "RTBC" or "Needs work" as result of comments #111 - 113 ?

Needs change record, please write a draft CR

Yes, needs a draft CR but also needs work as described in comment #113 which may affect the contents of CR.
Added to #3179845: [meta] Priorities for 2020-12-02 bugfix release of Drupal 7.76 / 7.77 in unsorted to draw attention to it.

Re-rolled the patch against dev, as the current d7 patch did not apply against 7.82