improved logging

This reverts commit 0f5ba218f6.

mailstream/mailstream.php

@@ -106,12 +106,40 @@ function mailstream_send_hook(array $data)
 
 	$user = User::getById($item['uid']);
 	if (empty($user)) {
-		Logger::error('could not find user', ['uid' => $item['uid']]);
+		Logger::error('mailstream_send_hook could not find user', ['uid' => $item['uid']]);
 		return;
 	}
 
-	if (!mailstream_send($data['message_id'], $item, $user)) {
-		Logger::debug('send failed, will retry', $data);
+	$author = DBA::selectFirst('contact', ['nick', 'blocked', 'uri-id'], ['id' => $data['author-id'], 'self' => false]);
+	if (!DBA::isResult($author)) {
+		Logger::error('mailstream_send_hook could not find author', ['guid' => $item['guid'], 'author-id' => $data['author-id']]);
+		return;
+	}
+	if ($author['blocked']) {
+		Logger::info('mailstream_send_hook author is blocked', ['guid' => $item['guid'], 'author-id' => $data['author-id']]);
+		return;
+	}
+	$collapsed = false;
+	$user_contact = DBA::selectFirst('user-contact', ['cid', 'blocked', 'ignored', 'collapsed'], ['uid' => $item['uid'], 'uri-id' => $item['author-uri-id']]);
+	if (!DBA::isResult($user_contact)) {
+		$user_contact = DBA::selectFirst('user-contact', ['cid', 'blocked', 'ignored', 'collapsed'], ['uid' => $item['uid'], 'cid' => $item['author-id']]);
+	}
+	if (DBA::isResult($user_contact)) {
+		if ($user_contact['blocked']) {
+			Logger::info('mailstream_send_hook author is blocked', ['guid' => $item['guid'], 'cid' => $user_contact['cid']]);
+			return;
+		}
+		if ($user_contact['ignored']) {
+			Logger::info('mailstream_send_hook author is ignored', ['guid' => $item['guid'], 'cid' => $user_contact['cid']]);
+			return;
+		}
+		if ($user_contact['collapsed']) {
+			$collapsed = true;
+		}
+	}
+
+	if (!mailstream_send($data['message_id'], $item, $user, $collapsed)) {
+		Logger::debug('mailstream_send_hook send failed, will retry', $data);
 		if (!Worker::defer()) {
 			Logger::error('failed and could not defer', $data);
 		}
@@ -133,8 +161,8 @@ function mailstream_post_hook(array &$item)
 		return;
 	}
 	if (!DI::pConfig()->get($item['uid'], 'mailstream', 'enabled')) {
-		Logger::debug('mailstream: not enabled for item ' . $item['id'] . ' uid ' . $item['uid']);
-		// return;
+		Logger::debug('mailstream: not enabled.', ['item' => $item['id'], ' uid ' => $item['uid']]);
+		return;
 	}
 	if (!$item['contact-id']) {
 		Logger::debug('no contact-id', ['item' => $item['id']]);
@@ -164,6 +192,7 @@ function mailstream_post_hook(array &$item)
 	$send_hook_data = [
 		'uid' => $item['uid'],
 		'contact-id' => $item['contact-id'],
+		'author-id' => $item['author-id'],
 		'uri' => $item['uri'],
 		'message_id' => $message_id,
 		'tries' => 0,
@@ -350,10 +379,11 @@ function mailstream_subject(array $item): string
  * @param string $message_id ID of the message (RFC 1036)
  * @param array  $item       content of the item
  * @param array  $user       results from the user table
+ * @param bool   $collapsed  true if the content should be hidden
  *
  * @return bool True if this message has been completed.  False if it should be retried.
  */
-function mailstream_send(string $message_id, array $item, array $user): bool
+function mailstream_send(string $message_id, array $item, array $user, bool $collapsed): bool
 {
 	if (!is_array($item)) {
 		Logger::error('item is empty', ['message_id' => $message_id]);
@@ -371,10 +401,16 @@ function mailstream_send(string $message_id, array $item, array $user): bool
 
 	require_once(dirname(__file__) . '/phpmailer/class.phpmailer.php');
 
-	$item['body'] = Post\Media::addAttachmentsToBody($item['uri-id'], $item['body']);
+	if ($collapsed) {
+		$item['body'] = DI::l10n()->t('Content from %s is collapsed', $item['author-name']);
+	} else {
+		$item['body'] = Post\Media::addAttachmentsToBody($item['uri-id'], $item['body']);
+	}
 
 	$attachments = [];
-	mailstream_do_images($item, $attachments);
+	if (!$collapsed) {
+		mailstream_do_images($item, $attachments);
+	}
 	$frommail = DI::config()->get('mailstream', 'frommail');
 	if ($frommail == '') {
 		$frommail = 'friendica@localhost.local';
@@ -429,9 +465,9 @@ function mailstream_send(string $message_id, array $item, array $user): bool
 			'address' => $address
 		]);
 	} catch (phpmailerException $e) {
-		Logger::debug('PHPMailer exception sending message', ['id' => $message_id, 'error' => $e->errorMessage()]);
+		Logger::debug('mailstream_send PHPMailer exception sending message', ['item uri' => $item['uri'], 'message_id' => $message_id, 'error' => $e->errorMessage()]);
 	} catch (Exception $e) {
-		Logger::debug('exception sending message', ['id' => $message_id, 'error' => $e->getMessage()]);
+		Logger::debug('mailstream_send exception sending message', ['item uri' => $item['uri'], 'message_id' => $message_id, 'error' => $e->errorMessage()]);
 	}
 
 	return true;

retriever/retriever.php

@@ -143,7 +143,6 @@ $retriever_item_count = 0;
  * @param int $max_items Maximum number of items to retrieve in this call
  */
 function retriever_retrieve_items(int $max_items) {
-	Logger::debug('@@@ retriever_retrieve_items started');
 	global $retriever_item_count;
 
 	$retriever_schedule = array(array(1,'minute'),
@@ -166,7 +165,7 @@ function retriever_retrieve_items(int $max_items) {
 	$retrieve_items = $max_items - $retriever_item_count;
 	do {
 		Logger::debug('retriever_retrieve_items: asked for maximum ' . $max_items . ', already retrieved ' . intval($retriever_item_count) . ', retrieve ' . $retrieve_items);
-		$retriever_resources = DBA::selectToArray('retriever_resource', [], ['`completed` IS NULL AND (`last-try` IS NULL OR ' . implode($schedule_clauses, ' OR ') . ')'], ['order' => ['last-try' => 0], 'limit' => $retrieve_items]);
+		$retriever_resources = DBA::selectToArray('retriever_resource', [], ['`completed` IS NULL AND (`last-try` IS NULL OR ' . implode(' OR ', $schedule_clauses) . ')'], ['order' => ['last-try' => 0], 'limit' => $retrieve_items]);
 		if (!is_array($retriever_resources)) {
 			break;
 		}
@@ -182,7 +181,6 @@ function retriever_retrieve_items(int $max_items) {
 	}
 	while ($retrieve_items > 0);
 	Logger::debug('retriever_retrieve_items: finished retrieving items');
-	Logger::debug('@@@ retriever_retrieve_items finished');
 }
 
 /**
@@ -191,11 +189,9 @@ function retriever_retrieve_items(int $max_items) {
  * @param int $max_items Maximum number of items to retrieve in this call
  */
 function retriever_clean_up_completed_resources(int $max_items) {
-	Logger::debug('@@@ retriever_clean_up_completed_resources started');
 	// TODO: figure out how to do this with DBA module
 	$r = DBA::p("SELECT retriever_resource.`id` as resource, retriever_item.`id` as item FROM retriever_resource, retriever_item, retriever_rule WHERE retriever_item.`finished` = 0 AND retriever_item.`resource` = retriever_resource.`id` AND retriever_resource.`completed` IS NOT NULL AND retriever_item.`contact-id` = retriever_rule.`contact-id` AND retriever_item.`item-uid` = retriever_rule.`uid` LIMIT $max_items");
 	if (!DBA::isResult($r)) {
-		Logger::debug('@@@ retriever_clean_up_completed_resources nothing to do');
 		return;
 	}
 	Logger::debug('retriever_clean_up_completed_resources: items waiting even though resource has completed: ' . DBA::numRows($r));
@@ -221,7 +217,6 @@ function retriever_clean_up_completed_resources(int $max_items) {
 		DBA::update('retriever_item', ['finished' => 1], ['id' => intval($retriever_item['id'])], ['finished' => 0]);
 		retriever_check_item_completed($item);
 	}
-	Logger::debug('@@@ retriever_clean_up_completed_resources finished');
 }
 
 /**
@@ -453,7 +448,9 @@ function retriever_on_item_insert(array $retriever, array &$item) {
 	}
 
 	$resource = add_retriever_resource($url, $item['uid'], $item['contact-id']);
-	$retriever_item_id = add_retriever_item($item, $resource);
+	if (is_array($resource)) {
+		$retriever_item_id = add_retriever_item($item, $resource);
+	}
 }
 
 /**
@@ -665,12 +662,16 @@ function retriever_extract(DOMDocument $doc, array $retriever) {
  * @return DOMDocument New DOM document with global URLs
  */
 function retriever_globalise_urls(DOMDocument $doc, array $resource) {
-	$components = parse_url($resource['redirect-url']);
-        if (!array_key_exists('scheme', $components) || !array_key_exists('host', $components) || !array_key_exists('path', $components)) {
+	$url = $resource['redirect-url'];
+	if ($url == "") {
+		$url = $resource['url'];
+	}
+	$components = parse_url($url);
+	if (!array_key_exists('scheme', $components) || !array_key_exists('host', $components) || !array_key_exists('path', $components)) {
 		return $doc;
-        }
+	}
 	$rooturl = $components['scheme'] . "://" . $components['host'];
-	$dirurl = $rooturl . dirname($components['path']) . "/";
+	$dirurl = $rooturl . dirname($components['path']);
 	$params = array('$dirurl' => $dirurl, '$rooturl' => $rooturl);
 	$fix_urls_template = Renderer::getMarkupTemplate('fix-urls.tpl', 'addon/retriever/');
 	$fix_urls_xslt = Renderer::replaceMacros($fix_urls_template, $params);
@@ -699,9 +700,6 @@ function retriever_get_body(array $item) {
 		Logger::warning('retriever_get_body: item-content uri-id ' . $item['uri-id'] . ' has no body');
 		return $item['body'];
 	}
-	if ($content['body'] != $item['body']) {
-		Logger::warning('@@@ this is probably bad @@@ content: ' . $content['body'] . ' @@@ item: ' . $item['body']);
-	}
 	return $content['body'];
 }
 
@@ -748,12 +746,15 @@ function retrieve_images(array &$item) {
 		}
 		if (strpos($url, (string)(DI::baseUrl())) === FALSE) {
 			$resource = add_retriever_resource($url, $item['uid'], $item['contact-id'], true);
+			if (!is_array($resource)) {
+				Logger::error('retrieve_images: could not add resource', ['url' => $url, 'uid' => $item['uid'], 'contact-id' => $item['contact-id']]);
+				continue;
+			}
 			if (!$resource['completed']) {
 				add_retriever_item($item, $resource);
+				continue;
 			}
-			else {
-				retriever_transform_images($item, $resource);
-			}
+			retriever_transform_images($item, $resource);
 		}
 	}
 }
@@ -783,7 +784,7 @@ function retriever_check_item_completed(array &$item)
  * @param array $resource The resource that has just been completed
  */
 function retriever_apply_completed_resource_to_item(array $retriever, array &$item, array $resource) {
-	Logger::debug('retriever_apply_completed_resource_to_item: retriever ' . ($retriever ? $retriever['id'] : 'none') . ' resource ' . $resource['url'] . ' plink ' . $item['plink']);
+	Logger::debug('retriever_apply_completed_resource_to_item', ['retriever' => $retriever ? $retriever['id'] : 'none', 'resource' => $resource['url'], 'plink' => $item['plink']]);
 	if (strpos($resource['type'], 'image') !== false) {
 		retriever_transform_images($item, $resource);
 	}
@@ -832,12 +833,12 @@ function retriever_transform_images(array &$item, array $resource) {
 		return;
 	}
 	try {
-		$photo = Photo::store($image, $uid, $cid, $rid, $filename, $album, 0, 0, "", "", "", "", $desc);
+		$photo = Photo::store($image, $uid, $cid, $rid, $filename, $album, $scale, Photo::DEFAULT, '', '', '', '', $desc);
 	} catch (Exception $e) {
 		Logger::error('retriever_transform_images: unable to store photo ' . $resource['url'] . ' error: ' . $e->getMessage());
 		return;
 	}
-	$new_url = DI::baseUrl() . '/photo/' . $rid . '-0.' . $image->getExt();
+	$new_url = DI::baseUrl() . '/photo/' . $rid . '-0' . $image->getExt();
 	if (!strlen($new_url)) {
 		Logger::warning('retriever_transform_images: no replacement URL for image ' . $resource['url']);
 		return;

retriever/templates/fix-urls.tpl

@@ -14,7 +14,7 @@
 
   <xsl:template match="*/@src[starts-with(.,'.')]">
     <xsl:attribute name="src">
-      <xsl:value-of select="concat('{{$dirurl}}',.)"/>
+      <xsl:value-of select="concat('{{$dirurl}}/',.)"/>
     </xsl:attribute>
   </xsl:template>
   <xsl:template match="*/@src[starts-with(.,'/')]">
@@ -22,5 +22,10 @@
       <xsl:value-of select="concat('{{$rooturl}}',.)"/>
     </xsl:attribute>
   </xsl:template>
+  <xsl:template match="*/@src[not(starts-with(.,'/')) and not(contains(.,':'))]">
+    <xsl:attribute name="src">
+      <xsl:value-of select="concat('{{$dirurl}}',.)"/>
+    </xsl:attribute>
+  </xsl:template>
 
 </xsl:stylesheet>