HTTP listener false positive error for non-blocking requests

[luisarn]

Version Information

• PHP: 7.1.9
• WordPress: 4.8.3

Steps to Reproduce

1. Install Wordpress
2. Install Wonolog
3. Include the composer autoload script on wp-config.php
4. Create the mu-plugin for initializing Wonolog

What I Expected

Nothing is shown on the error log since it's a brand new install without anything else.

What Happened Instead

Wonolog keeps registering the following error:

HTTP.ERROR:` WP HTTP API Error - Response code: . {"transport":"Requests","context":"response","query_args":{"method":"POST","timeout":0.01,"redirection":5,"httpversion":"1.0","user-agent":"WordPress/4.8.3; http://wordpress.local","reject_unsafe_urls":false,"blocking":false,"headers":[],"cookies":[],"body":null,"compress":false,"decompress":true,"sslverify":false,"sslcertificates":"/data/wordpress/wp-includes/certificates/ca-bundle.crt","stream":false,"filename":null,"limit_response_size":null,"_redirection":5},"url":"http://wordpress.local/wp-cron.php?doing_wp_cron=1509694724.2679729461669921875000","headers":"[object] (Requests_Utility_CaseInsensitiveDictionary: {})"} {"wp":{"doing_cron":false,"doing_ajax":true,"is_admin":true,"user_id":1}}```

[gmazzap]

Hi @luisarn,

even if it's a brand new install, WordPress sends HTTP requests to handle its default "cron" tasks (some info here https://developer.wordpress.org/plugins/cron/).

Normally Wonolog recognizes those cron requests and log it properly.

However, what I see here is that in your case the request is not recognized as a cron request (I see "doing_cron":false) but as an AJAX request (I see "doing_ajax":true) even if the URL is typical of cron requests ("url":"http://wordpress.local/wp-cron.php?doing_wp_cron=1509694724.2679729461669921875000")

I will try to figure out if this is a Wonolog bug or it could be an issue with your installation / server setup.

[luisarn]

Hi @gmazapp, thanks for the reply! Please find below my server details to aid your investigation:

SLES11
Nginx 1.8.1
Php-fpm 7.1.9

You can install the plugin wp-crontrol and run the default wp cron jobs to trigger the error.

Best regards,
Luís

[luisarn]

After a quick debug, I think I might found the issue:

In the HttpApiListener.php:

private function is_error( $response ) {

	if ( is_wp_error( $response ) ) {
		return TRUE;
	}

	if ( ! isset( $response[ 'response' ][ 'code' ] ) ) {
		return FALSE;
	}

	if ( ! is_numeric( $response[ 'response' ][ 'code' ] ) ) {
		return TRUE;
	}

	$code = (int) $response[ 'response' ][ 'code' ];

	return ! in_array( $code, self::$http_success_codes );
}

1 - Wonolog checks the response if is a WP Error by passing the response to the is_wp_error function. In my case is_wp_error returns false which I assume it's not an error.
2 - Wonolog then checks if the response code is set or not, if not then returns false, however, the $response['response']['code'] is set but it's empty, so Wonolog proceeds with the next checking.
3 - On this step Wonolog check if the $response['response']['code'] is not numeric, in this case, since it's empty, it returns true because 'empty' is not numeric.

I believe this is a false alarm so by adding the following checking on the 2nd step might fix the issue:

if ( ! isset( $response[ 'response' ][ 'code' ] ) || empty( $response[ 'response' ][ 'code' ] ) ) {
	return FALSE;
}

unless the empty response code is really an error.

[gmazzap]

Hi @luisarn and thanks for the time you spent on this.

Yes, I was aware of the code, but I thought that when the request is not blocking the response was empty, so it would not pass the second if, but it seems that when the request is not blocking response 'code' key is there and hardcoded to false (https://github.com/WordPress/WordPress/blame/master/wp-includes/class-http.php#L401-L411) not sure it has always been like this, strange choice anyway.

Btw, I will fix this skipping the response code check for non-blocking requests.

Thanks again.

[gmazzap]

@luisarn 64cf621 should fix the issue. Can you confirm? If so, I think we could release a new bugfix version.

[luisarn]

Hi @gmazzap,

Confirmed! The false positive error for non-blocking requests is fixed.

Thank you!