プロジェクト

全般

プロフィール

Vote #76913

完了

Some log messages are missing the "MailHandler" prefix

Admin Redmine さんが3年以上前に追加. 3年以上前に更新.

ステータス:
Closed
優先度:
通常
担当者:
-
カテゴリ:
Email receiving_29
対象バージョン:
開始日:
2022/05/09
期日:
進捗率:

0%

予定工数:
category_id:
29
version_id:
102
issue_org_id:
21226
author_id:
20632
assigned_to_id:
1
comments:
9
status_id:
5
tracker_id:
1
plus1:
0
affected_version:
closed_on:
affected_version_id:
103
ステータス-->[Closed]

説明

For email scraping we set @RAILS_ENV@ to @development@ to increase logging details. This allows us to diagnose the various scraping issues we encounter and work around them.

Other scraping failures from what I can tell include the @MailHandler:@ prefix before the error message. Either by intention, or a nice side effect, having that prefix in the log file allows for parsing of the log file by reporting scripts.

Today I encountered a scraping issue due to the contents of an email exceeding the limits of the description column. Here is an example entry in the log from that failed scraping attempt:

An unexpected error occurred when receiving email: Mysql2::Error: Data too long for column 'description' at row 1: INSERT INTO `issues` (`project_id`, `author_id`, `priority_id`, `tracker_$
Message 30130 can not be processed

This entry is missing the @MailHandler:@ prefix that I am accustomed to seeing. Is this by design or is it really missing the prefix?


journals

Could you try this patch?

<pre><code class="diff">
diff --git a/app/models/mail_handler.rb b/app/models/mail_handler.rb
--- a/app/models/mail_handler.rb
+++ b/app/models/mail_handler.rb
@@ -177,7 +177,7 @@ class MailHandler < ActionMailer::Base
end
rescue ActiveRecord::RecordInvalid => e
# TODO: send a email to the user
- logger.error e.message if logger
+ logger.error "MailHandler: #{e.message}" if logger
false
rescue MissingInformation => e
logger.error "MailHandler: missing information from #{user}: #{e.message}" if logger
</code></pre>
--------------------------------------------------------------------------------
When I saw your patch I was very optimistic that it would work, but so far I don't see any change. I applied it and confirmed that the change matches what you've shown above:

@root@help:/opt/redmine# svn diff@
<pre><code class="diff">
Index: app/models/mail_handler.rb
===================================================================
--- app/models/mail_handler.rb (revision 14618)
+++ app/models/mail_handler.rb (working copy)
@@ -177,7 +177,7 @@
end
rescue ActiveRecord::RecordInvalid => e
# TODO: send a email to the user
- logger.error e.message if logger
+ logger.error "MailHandler: #{e.message}" if logger
false
rescue MissingInformation => e
logger.error "MailHandler: missing information from #{user}: #{e.message}" if logger
</code></pre>

and then I had the script scrape the 1MB email. I looked in the log and found that the line is still missing the prefix (line break between the two entries manually added):

@root@help:/opt/redmine# grep -E 'unexpected error|can not be processed' log/development.log | cut -c 1-190@
<pre>
An unexpected error occurred when receiving email: Mysql2::Error: Data too long for column 'description' at row 1: INSERT INTO `issues` (`project_id`, `author_id`, `priority_id`, `tracker_id
Message 5696 can not be processed
</pre>

<pre>
An unexpected error occurred when receiving email: Mysql2::Error: Data too long for column 'description' at row 1: INSERT INTO `issues` (`project_id`, `author_id`, `priority_id`, `tracker_id
Message 5697 can not be processed
</pre>
--------------------------------------------------------------------------------
This is an SQL error, not a ActiveRecord::RecordInvalid error. That's why it doesn't fix your problem.
Could you try this:

<pre><code class="diff">
### Eclipse Workspace Patch 1.0
#P trunk
Index: app/models/mail_handler.rb
===================================================================
--- app/models/mail_handler.rb (revision 14858)
+++ app/models/mail_handler.rb (working copy)
@@ -54,7 +54,7 @@
def self.safe_receive(*args)
receive(*args)
rescue Exception => e
- logger.error "An unexpected error occurred when receiving email: #{e.message}" if logger
+ logger.error "MailHandler: an unexpected error occurred when receiving email: #{e.message}" if logger
return false
end
</code></pre>
--------------------------------------------------------------------------------

--------------------------------------------------------------------------------
We could use "tagged logging":http://api.rubyonrails.org/classes/ActiveSupport/TaggedLogging.html for the mail handler to make sure that everything is prepended with something like [MailHandler]. But that would apply to all log messages, including template renderings and stuff like that, making it harder to catch usefull log messages:

Current log message:

<pre>
Rendered mailer/_issue.text.erb (7.0ms)
Rendered mailer/issue_add.text.erb within layouts/mailer (13.0ms)
Rendered mailer/_issue.html.erb (6.0ms)
Rendered mailer/issue_add.html.erb within layouts/mailer (7.0ms)

Sent email "[OnlineStore - Bug #15] (Resolved) New ticket on a given project" (4ms)
bcc: jsmith@somenet.foo
MailHandler: issue #15 created by John Smith

Received mail (635.0ms)
</pre>

With tagged logging:

<pre>
[MailHandler] Rendered mailer/_issue.text.erb (7.0ms)
[MailHandler] Rendered mailer/issue_add.text.erb within layouts/mailer (12.0ms)
[MailHandler] Rendered mailer/_issue.html.erb (6.0ms)
[MailHandler] Rendered mailer/issue_add.html.erb within layouts/mailer (7.0ms)
[MailHandler]
Sent email "[OnlineStore - Bug #15] (Resolved) New ticket on a given project" (3ms)
bcc: jsmith@somenet.foo
[MailHandler] issue #15 created by John Smith
[MailHandler]
Received mail (628.0ms)
</pre>
--------------------------------------------------------------------------------
Both patches are committed in r14880.
I would still like to hear from you about the tagged logging solution.
--------------------------------------------------------------------------------
Jean-Philippe Lang wrote:
> Both patches are committed in r14880.

Thanks!

> I would still like to hear from you about the tagged logging solution.

If there is existing functionality (similar to syslog daemons) to filter on severity that could come in handy, otherwise I agree with your comment that tagging every line would make it more difficult to catch useful details.

I could see in a case where syslog functionality _is_ available that @MailHandler@ could be just one prefix used in the logging setup and that other "components" (for the lack of the correct word) would have their own prefix. Then if error messages were filtered to a separate file having the @MailHandler@ prefix on all lines might prove useful.

Is there any existing functionality like that already in Redmine?
--------------------------------------------------------------------------------
Jean-Philippe Lang wrote:
> This is an SQL error, not a ActiveRecord::RecordInvalid error. That's why it doesn't fix your problem.
> Could you try this:
>
> [...]

It worked as you expected:

<pre>
MailHandler: an unexpected error occurred when receiving email: Mysql2::Error: Data too long for column 'description' at row 1: INSERT INTO `issues` (`project_id`, `author_id`, `priority_id
</pre>

Thanks.
--------------------------------------------------------------------------------
Thanks for the feedback, I'm closing it.

Deoren Moor wrote:

> Is there any existing functionality like that already in Redmine?

Rails logger can be configured to send logs to syslog but as far as I know, everything goes a single log file by default.
--------------------------------------------------------------------------------

Admin Redmine さんが3年以上前に更新

  • カテゴリEmail receiving_29 にセット
  • 対象バージョン3.2.0_102 にセット

他の形式にエクスポート: Atom PDF

いいね!0
いいね!0