fixed bug of dropping mentions when structure wasn't in the expected form + better debugging
Peter Molnar hello@petermolnar.eu
Tue, 08 Mar 2016 13:36:59 +0000
4 files changed,
99 insertions(+),
57 deletions(-)
M
readme.txt
→
readme.txt
@@ -3,8 +3,8 @@ Contributors: cadeyrn
Donate link: https://paypal.me/petermolnar/3 Tags: webmention, pingback, indieweb Requires at least: 4.3 -Tested up to: 4.4.1 -Stable tag: 0.5 +Tested up to: 4.4.2 +Stable tag: 0.5.1 License: GPLv3 License URI: http://www.gnu.org/licenses/gpl-3.0.html Required minimum PHP version: 5.3@@ -32,6 +32,13 @@
* every A. indicates BIG changes. * every .B version indicates new features. * every ..C indicates bugfixes for A.B version. + += 0.5.1 = +*2016-03-08* + +* fixed bug of dropping mentions when structure wasn't in the expected form +* better debugging + = 0.5= *2016-03-01*
M
receiver.php
→
receiver.php
@@ -305,12 +305,12 @@ empty( $received->target ) ||
! isset( $received->source ) || empty( $received->source ) ) { - static::debug( " target or souce empty, aborting" ); + static::debug( " target or souce empty, aborting", 6 ); static::queue_del ( $received->id ); continue; } - static::debug( "processing webmention: target -> {$received->target}, source -> {$received->source}" ); + static::debug( "processing webmention: target -> {$received->target}, source -> {$received->source}", 5); if ( empty( $received->object_id ) || 0 == $received->object_id ) $post_id = url_to_postid ( $received->target );@@ -320,14 +320,14 @@
$post = get_post ( $post_id ); if ( ! static::is_post( $post ) ) { - static::debug( " no post found for this mention, try again later, who knows?" ); + static::debug( " no post found for this mention, try again later, who knows?", 6); //static::queue_del ( $received->id ); continue; } // too many retries, drop this mention and walk away if ( $received->tries >= static::retry() ) { - static::debug( " this mention was tried earlier and failed too many times, drop it" ); + static::debug( " this mention was tried earlier and failed too many times, drop it", 5); static::queue_del ( $received->id ); continue; }@@ -339,7 +339,7 @@ // validate target
$remote = static::try_receive_remote( $post_id, $received->source, $received->target ); if ( false === $remote || empty( $remote ) ) { - static::debug( " parsing this mention failed, retrying next time" ); + static::debug( " parsing this mention failed, retrying next time", 6); continue; }@@ -348,15 +348,15 @@ $c = static::try_parse_remote ( $post_id, $received->source, $received->target, $remote );
$ins = static::insert_comment ( $post_id, $received->source, $received->target, $remote, $c ); if ( true === $ins ) { - static::debug( " duplicate (or something similar): this queue element has to be ignored; deleting queue entry" ); + static::debug( " duplicate (or something similar): this queue element has to be ignored; deleting queue entry", 5); static::queue_del ( $received->id ); } elseif ( is_numeric( $ins ) ) { - static::debug( " all went well, we have a comment id: {$ins}, deleting queue entry" ); + static::debug( " all went well, we have a comment id: {$ins}, deleting queue entry", 5); static::queue_done ( $received->id ); } else { - static::debug( "This is unexpected. Try again." ); + static::debug( "This is unexpected. Try again.", 6); } } }@@ -401,27 +401,27 @@
// check if source really links to target // this could be a temporary error, so we'll retry later this one as well if ( false == $found ) { - static::debug( " missing link to {$t} in remote body" ); + static::debug( " missing link to {$t} in remote body", 6); return false; } $ctype = isset( $q['headers']['content-type'] ) ? $q['headers']['content-type'] : 'text/html'; if ( "text/plain" == $ctype ) { - static::debug( " interesting, plain text webmention. I'm not prepared for this yet" ); + static::debug( " interesting, plain text webmention. I'm not prepared for this yet", 6); return false; } elseif ( $ctype == "application/json" ) { - static::debug( " content is JSON" ); + static::debug( " content is JSON", 6); $content = json_decode( $q['body'], true ); } else { - static::debug( " content is (probably) html, trying to parse it with MF2" ); + static::debug( " content is (probably) html, trying to parse it with MF2", 6); try { $content = Mf2\parse( $q['body'], $source ); } catch ( Exception $e ) { - static::debug( " parsing MF2 failed: " . $e->getMessage() ); + static::debug( " parsing MF2 failed: " . $e->getMessage(), 4); return false; }@@ -465,7 +465,7 @@
if ( isset( $content['items']['properties'] ) && isset( $content['items']['type'] ) ) { $item = $content['items']; } - elseif ( is_array($content['items'] ) && ! empty( $content['items']['type'] ) ) { + elseif ( is_array($content['items'] ) ) { foreach ( $content['items'] as $i ) { if ( 'h-entry' == $i['type'] ) { $items[] = $i;@@ -487,7 +487,8 @@
// if the entry wasn't found, fall back to a regular mention if (! $item || empty( $item )) { - static::debug(' no parseable h-entry found, saving as standard mention comment'); + static::debug(' no parseable h-entry found, saving as standard mention comment', 6); + static::debug(' the content was:' . json_encode( $content ), 7); return $c; }@@ -702,21 +703,21 @@ 'second' => $t[2],
); //test if we already have this imported - static::debug( "checking comment existence (with date) for post #{$post_id}" ); + static::debug( "checking comment existence (with date) for post #{$post_id}", 6); } else { // we do need a date $comment['comment_date'] = date( "Y-m-d H:i:s" ); $comment['comment_date_gmt'] = date( "Y-m-d H:i:s" ); - static::debug( "checking comment existence (no date) for post #{$post_id}" ); + static::debug( "checking comment existence (no date) for post #{$post_id}", 6); } $existing = get_comments( $testargs ); // no matching comment yet, insert it if ( ! empty( $existing ) ) { - static::debug ( "comment already exists" ); + static::debug ( "comment already exists", 6); return true; }@@ -753,7 +754,7 @@ // re-add flood control
add_filter( 'check_comment_flood', 'check_comment_flood_db', 10, 3 ); do_action ( 'wp_webmention_again_insert_comment' ); - static::debug( $r ); + static::debug( $r, 7); return $comment_id; }
M
sender.php
→
sender.php
@@ -115,7 +115,7 @@ */
public static function queue_post( $new_status, $old_status, $post ) { if ( ! static::is_post( $post ) ) { - static::debug( "Whoops, this is not a post." ); + static::debug( "Whoops, this is not a post.", 6); return false; }@@ -124,7 +124,7 @@ static::debug( "Not adding {$post->ID} to mention queue yet; not published" );
return false; } - static::debug("Trying to get urls for #{$post->ID}"); + static::debug("Trying to get urls for #{$post->ID}", 6); // try to avoid redirects, so no shortlink is sent for now as source $source = get_permalink( $post->ID );@@ -172,7 +172,7 @@
$r = static::queue_add ( 'out', $source, $target, $post->post_type, $post->ID ); if ( !$r ) - static::debug( " tried adding post #{$post->ID}, url: {$target} to mention queue, but it didn't go well" ); + static::debug( " tried adding post #{$post->ID}, url: {$target} to mention queue, but it didn't go well", 4); } }@@ -197,16 +197,16 @@ empty( $send->target ) ||
! isset( $send->source ) || empty( $send->source ) ) { - static::debug( " target or souce empty, aborting" ); + static::debug( " target or souce empty, aborting", 6); static::queue_del ( $send->id ); continue; } - static::debug( "processing webmention: target -> {$send->target}, source -> {$send->source}" ); + static::debug( "processing webmention: target -> {$send->target}, source -> {$send->source}", 5 ); // too many retries, drop this mention and walk away if ( $send->tries >= static::retry() ) { - static::debug( " this mention was tried earlier and failed too many times, drop it" ); + static::debug( " this mention was tried earlier and failed too many times, drop it", 5); static::queue_done ( $send->id ); continue; }@@ -218,10 +218,10 @@ // try sending
$s = static::send( $send->source, $send->target ); if ( is_wp_error ( $s ) ) { - static::debug( " sending failed: " . $s->get_error_message() ); + static::debug( " sending failed: " . $s->get_error_message(), 5); } else { - static::debug( " sending succeeded!" ); + static::debug( " sending succeeded!", 5); $post_types = get_post_types( '', 'names' ); if ( in_array( $send->object_type, $post_types ) && 0 != $send->object_id ) {@@ -268,7 +268,7 @@ 'body' => 'source=' . urlencode( $source ) . '&target=' . urlencode( $target ),
'timeout' => static::remote_timeout(), ); - static::debug( "Sending webmention to: " .$webmention_server_url . " as: " . $args['body'] ); + static::debug( "Sending webmention to: " .$webmention_server_url . " as: " . $args['body'], 5); $response = wp_remote_post( $webmention_server_url, $args ); // use the response to do something usefull@@ -307,7 +307,7 @@
$response = wp_remote_head( $url, array( 'timeout' => static::remote_timeout(), 'httpversion' => '1.0' ) ); if ( is_wp_error( $response ) ) { - static::debug( "Something went wrong: " . $response->get_error_message() ); + static::debug( "Something went wrong: " . $response->get_error_message(), 5); return false; }
M
wp-webmention-again.php
→
wp-webmention-again.php
@@ -132,12 +132,12 @@ KEY `time` (`date`),
KEY `key` (`direction`) ) {$charset_collate};"; - static::debug("Initiating DB {$dbname}"); + static::debug("Initiating DB {$dbname}", 4); try { $wpdb->query( $db_command ); } catch (Exception $e) { - static::debug('Something went wrong: ' . $e->getMessage()); + static::debug('Something went wrong: ' . $e->getMessage(), 4); } }@@ -155,12 +155,12 @@ $dbname = $wpdb->prefix . static::tablename;
$db_command = "DROP TABLE IF EXISTS `{$dbname}`;"; - static::debug("Deleting DB {$dbname}"); + static::debug("Deleting DB {$dbname}", 4); try { $wpdb->query( $db_command ); } catch (Exception $e) { - static::debug('Something went wrong: ' . $e->getMessage()); + static::debug('Something went wrong: ' . $e->getMessage(), 4); } }@@ -239,7 +239,7 @@ try {
$req = $wpdb->query( $q ); } catch (Exception $e) { - static::debug('Something went wrong: ' . $e->getMessage()); + static::debug('Something went wrong: ' . $e->getMessage(), 4); } return $id;@@ -267,7 +267,7 @@ try {
$req = $wpdb->query( $q ); } catch (Exception $e) { - static::debug('Something went wrong: ' . $e->getMessage()); + static::debug('Something went wrong: ' . $e->getMessage(), 4); } return $req;@@ -295,7 +295,7 @@ try {
$req = $wpdb->query( $q ); } catch (Exception $e) { - static::debug('Something went wrong: ' . $e->getMessage()); + static::debug('Something went wrong: ' . $e->getMessage(), 4); } return $req;@@ -329,7 +329,7 @@ try {
$req = $wpdb->query( $q ); } catch (Exception $e) { - static::debug('Something went wrong: ' . $e->getMessage()); + static::debug('Something went wrong: ' . $e->getMessage(), 4); } return $req;@@ -360,7 +360,7 @@ try {
$req = $wpdb->get_results( $q ); } catch (Exception $e) { - static::debug('Something went wrong: ' . $e->getMessage()); + static::debug('Something went wrong: ' . $e->getMessage(), 4); } if ( ! empty ( $req ) )@@ -396,7 +396,7 @@ try {
$req = $wpdb->get_results( $q ); } catch (Exception $e) { - static::debug('Something went wrong: ' . $e->getMessage()); + static::debug('Something went wrong: ' . $e->getMessage(), 4); } if ( ! empty ( $req ) )@@ -414,7 +414,7 @@ * @return array wp_remote_get array
*/ protected static function _wp_remote_get ( &$source ) { $content = false; - static::debug( " fetching {$source}" ); + static::debug( " fetching {$source}", 6); $url = htmlspecialchars_decode( $source ); $q = wp_remote_get( $source );@@ -424,21 +424,21 @@ return false;
} if ( !is_array( $q ) ) { - static::debug( " $q is not an array. It should be one." ); + static::debug( " $q is not an array. It should be one.", 6); return false; } if ( ! isset( $q['headers'] ) || ! is_array( $q['headers'] ) ) { - static::debug( " missing response headers." ); + static::debug( " missing response headers.", 6); return false; } if ( ! isset( $q['body'] ) || empty( $q['body'] ) ) { - static::debug( " missing body" ); + static::debug( " missing body", 6); return false; } - static::debug('Headers: ' . json_encode($q['headers'])); + static::debug('Headers: ' . json_encode($q['headers']), 7); return $q; }@@ -586,30 +586,64 @@
return $r; } + /** + * * debug messages; will only work if WP_DEBUG is on * or if the level is LOG_ERR, but that will kill the process * * @param string $message * @param int $level + * + * @output log to syslog | wp_die on high level + * @return false on not taking action, true on log sent */ - protected static function debug( $message, $level = LOG_NOTICE ) { + public static function debug( $message, $level = LOG_NOTICE ) { + if ( empty( $message ) ) + return false; + if ( @is_array( $message ) || @is_object ( $message ) ) - $message = json_encode( $message ); + $message = json_encode($message); + $levels = array ( + LOG_EMERG => 0, // system is unusable + LOG_ALERT => 1, // Alert action must be taken immediately + LOG_CRIT => 2, // Critical critical conditions + LOG_ERR => 3, // Error error conditions + LOG_WARNING => 4, // Warning warning conditions + LOG_NOTICE => 5, // Notice normal but significant condition + LOG_INFO => 6, // Informational informational messages + LOG_DEBUG => 7, // Debug debug-level messages + ); - switch ( $level ) { - case LOG_ERR : - wp_die( '<h1>Error:</h1>' . '<p>' . $message . '</p>' ); - exit; - default: - if ( ! defined( 'WP_DEBUG' ) || true != WP_DEBUG ) - return; - break; + // number for number based comparison + // should work with the defines only, this is just a make-it-sure step + $level_ = $levels [ $level ]; + + // in case WordPress debug log has a minimum level + if ( defined ( 'WP_DEBUG_LEVEL' ) ) { + $wp_level = $levels [ WP_DEBUG_LEVEL ]; + if ( $level_ > $wp_level ) { + return false; + } + } + + // ERR, CRIT, ALERT and EMERG + if ( 3 >= $level_ ) { + wp_die( '<h1>Error:</h1>' . '<p>' . $message . '</p>' ); + exit; } - error_log( __CLASS__ . ": " . $message ); + $trace = debug_backtrace(); + $caller = $trace[1]; + $parent = $caller['function']; + + if (isset($caller['class'])) + $parent = $caller['class'] . '::' . $parent; + + return error_log( "{$parent}: {$message}" ); } + }