Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix missing text/plain crashes #30

Open
wants to merge 2 commits into
base: main
Choose a base branch
from

Conversation

dekimsey
Copy link

Noticed in logstash 5.3.

Some of our applications do not properly add text/plain entries to their multi-part messages. This repeatedly crashes the input plugin.

This change let's the plugin fallback if the target part cannot be decoded. That seems to address the crashes. Whether this change is Correct way to handle it I'm less certain.

Log excerpt:

12:45:01.910 [[main]<imap] DEBUG logstash.inputs.imap - Working with message_id {:message_id=>"da93f5d6-9e42-11e8-898f-8f312f094cc3@server.example.com"}
12:45:01.919 [[main]<imap] ERROR logstash.pipeline - A plugin had an unrecoverable error. Will restart this plugin.
  Plugin: <LogStash::Inputs::IMAP id=>"system_mail_input", host=>"internal-relay.example.com", user=>"catchall", password=><password>, delete=>false, expunge=>false, type=>"system-mail", fetch_count=>3, verify_cert=>false, enable_metric=>true, codec=><LogStash::Codecs::Plain id=>"plain_2dd9d3d9-8e6e-4f2c-9fdc-0387100b3101", enable_metric=>true, charset=>"UTF-8">, secure=>true, folder=>"INBOX", lowercase_headers=>true, check_interval=>300, strip_attachments=>false, content_type=>"text/plain">
  Error: Can not decode an entire message, try calling #decoded on the various fields and body or parts if it is a multipart message.
  Exception: NoMethodError
  Stack: /usr/share/logstash/vendor/bundle/jruby/1.9/gems/mail-2.6.4/lib/mail/message.rb:1903:in `decoded'
/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-imap-3.0.2/lib/logstash/inputs/imap.rb:119:in `parse_mail'
/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-imap-3.0.2/lib/logstash/inputs/imap.rb:88:in `check_mail'
org/jruby/RubyArray.java:1613:in `each'
/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-imap-3.0.2/lib/logstash/inputs/imap.rb:82:in `check_mail'
org/jruby/RubyArray.java:1653:in `each_slice'
/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-imap-3.0.2/lib/logstash/inputs/imap.rb:80:in `check_mail'
/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-imap-3.0.2/lib/logstash/inputs/imap.rb:69:in `run'
org/jruby/RubyProc.java:281:in `call'
/usr/share/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.22/lib/stud/interval.rb:20:in `interval'
/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-imap-3.0.2/lib/logstash/inputs/imap.rb:68:in `run'
/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:425:in `inputworker'
/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:419:in `start_input'
^C12:45:02.701 [SIGINT handler] WARN  logstash.runner - SIGINT received. Shutting down the agent.
12:45:02.712 [Ruby-0-Thread-3: /usr/share/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.22/lib/stud/task.rb:22] DEBUG logstash.agent - Reading config file {:config_file=>"/home/dkimsey/mail.conf"}
12:45:02.714 [Ruby-0-Thread-3: /usr/share/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.22/lib/stud/task.rb:22] DEBUG logstash.agent - no configuration change for pipeline {:pipeline=>"main"}
12:45:03.717 [LogStash::Runner] DEBUG logstash.instrument.periodicpoller.os - PeriodicPoller: Stopping

Attached are sample headers from the messages that trigger this crash:

Return-Path: <donotreply@example.com>
Delivered-To: catchall@internal-relay.example.com
Received: (qmail 7338 invoked by alias); 12 Aug 2018 09:03:46 -0000
Delivered-To: alias-example@example.com
Received: (qmail 7335 invoked from network); 12 Aug 2018 09:03:46 -0000
Received: from server.example.com (10.70.250.244)
     by internal-relay.example.com with SMTP; 12 Aug 2018 09:03:46 -0000
Date: Sun, 12 Aug 2018 10:05:29 -0500 (CDT)
From: Example Support <donotreply@example.com>
To: Example Alias <alias@example.com>
Message-ID: <269f0a38-9e41-11e8-898f-490d1f59e2cc@server.example.com>
Subject: SIEM Case Needs Update: Case #1337
MIME-Version: 1.0
Content-Type: multipart/mixed; 
    	boundary="----=_Part_14178_1287706963.1534086329342"

------=_Part_14184_1527212999.1534086352336
Content-Type: multipart/related;
    boundary="----=_Part_14185_209084662.1534086352336"

------=_Part_14185_209084662.1534086352336
Content-Type: text/html;charset=UTF-8
Content-Transfer-Encoding: 7bit

<p>html was here</p>
------=_Part_14185_209084662.1534086352336--

------=_Part_14184_1527212999.1534086352336--

Possibly related to the issue reported in #25.

Thanks for contributing to Logstash! If you haven't already signed our CLA, here's a handy link: https://www.elastic.co/contributor-agreement/

Noticed in logstash 5.3.

Some of our applications do not properly add text/plain entries to their multi-part messages. This repeatedly crashes the input plugin.

This change let's the plugin fallback if the target part cannot be decoded. That seems to address the crashes. Whether this change is Correct way to handle it I'm less certain.

Log excerpt:
```
12:45:01.910 [[main]<imap] DEBUG logstash.inputs.imap - Working with message_id {:message_id=>"da93f5d6-9e42-11e8-898f-8f312f094cc3@server.example.com"}
12:45:01.919 [[main]<imap] ERROR logstash.pipeline - A plugin had an unrecoverable error. Will restart this plugin.
  Plugin: <LogStash::Inputs::IMAP id=>"system_mail_input", host=>"internal-relay.example.com", user=>"catchall", password=><password>, delete=>false, expunge=>false, type=>"system-mail", fetch_count=>3, verify_cert=>false, enable_metric=>true, codec=><LogStash::Codecs::Plain id=>"plain_2dd9d3d9-8e6e-4f2c-9fdc-0387100b3101", enable_metric=>true, charset=>"UTF-8">, secure=>true, folder=>"INBOX", lowercase_headers=>true, check_interval=>300, strip_attachments=>false, content_type=>"text/plain">
  Error: Can not decode an entire message, try calling #decoded on the various fields and body or parts if it is a multipart message.
  Exception: NoMethodError
  Stack: /usr/share/logstash/vendor/bundle/jruby/1.9/gems/mail-2.6.4/lib/mail/message.rb:1903:in `decoded'
/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-imap-3.0.2/lib/logstash/inputs/imap.rb:119:in `parse_mail'
/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-imap-3.0.2/lib/logstash/inputs/imap.rb:88:in `check_mail'
org/jruby/RubyArray.java:1613:in `each'
/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-imap-3.0.2/lib/logstash/inputs/imap.rb:82:in `check_mail'
org/jruby/RubyArray.java:1653:in `each_slice'
/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-imap-3.0.2/lib/logstash/inputs/imap.rb:80:in `check_mail'
/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-imap-3.0.2/lib/logstash/inputs/imap.rb:69:in `run'
org/jruby/RubyProc.java:281:in `call'
/usr/share/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.22/lib/stud/interval.rb:20:in `interval'
/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-imap-3.0.2/lib/logstash/inputs/imap.rb:68:in `run'
/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:425:in `inputworker'
/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:419:in `start_input'
^C12:45:02.701 [SIGINT handler] WARN  logstash.runner - SIGINT received. Shutting down the agent.
12:45:02.712 [Ruby-0-Thread-3: /usr/share/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.22/lib/stud/task.rb:22] DEBUG logstash.agent - Reading config file {:config_file=>"/home/dkimsey/mail.conf"}
12:45:02.714 [Ruby-0-Thread-3: /usr/share/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.22/lib/stud/task.rb:22] DEBUG logstash.agent - no configuration change for pipeline {:pipeline=>"main"}
12:45:03.717 [LogStash::Runner] DEBUG logstash.instrument.periodicpoller.os - PeriodicPoller: Stopping
```

Attached are sample headers from the messages that trigger this crash:
```
Return-Path: <donotreply@example.com>
Delivered-To: catchall@internal-relay.example.com
Received: (qmail 7338 invoked by alias); 12 Aug 2018 09:03:46 -0000
Delivered-To: alias-example@example.com
Received: (qmail 7335 invoked from network); 12 Aug 2018 09:03:46 -0000
Received: from server.example.com (10.70.250.244)
     by internal-relay.example.com with SMTP; 12 Aug 2018 09:03:46 -0000
Date: Sun, 12 Aug 2018 10:05:29 -0500 (CDT)
From: Example Support <donotreply@example.com>
To: Example Alias <alias@example.com>
Message-ID: <269f0a38-9e41-11e8-898f-490d1f59e2cc@server.example.com>
Subject: SIEM Case Needs Update: Case #1337
MIME-Version: 1.0
Content-Type: multipart/mixed; 
    	boundary="----=_Part_14178_1287706963.1534086329342"

------=_Part_14184_1527212999.1534086352336
Content-Type: multipart/related;
    boundary="----=_Part_14185_209084662.1534086352336"

------=_Part_14185_209084662.1534086352336
Content-Type: text/html;charset=UTF-8
Content-Transfer-Encoding: 7bit

<p>html was here</p>
------=_Part_14185_209084662.1534086352336--

------=_Part_14184_1527212999.1534086352336--
```

Possibly related to the issue reported in logstash-plugins#25.
The regex doesn't always handle mulitpart messages just right. Instead letting Mail::Message do the work.
At least not in the following version:
"MIME-Version: 1.0\r\nContent-Type: multipart/mixed; \r\n\tboundary=\"----=_Part_359_73185438.1534877518980\"\r\n\r\n------=_Part_359_73185438.1534877518980\r\nContent-Type: multipart/related; \r\n\tboundary=\"----=_Part_360_37433491.1534877518980\"\r\n\r\n------=_Part_360_37433491.1534877518980\r\nContent-Type: multipart/alternative; \r\n\tboundary=\"----=_Part_361_1236413007.1534877518984\"\r\n\r\n------=_Part_361_1236413007.1534877518984\r\nContent-Type: text/plain; charset=UTF-8\r\nContent-Transfer-Encoding: 7bit\r\n\r\n\r\n"
@nrafal
Copy link

nrafal commented Sep 12, 2018

Thanks, I've tested your code, I've had the same issue and it seems to fix it.

@pemontto
Copy link
Contributor

This a much better solution than my PR #49. If this is stale, I can adopt it and work on the failing test.

Should also close #7 and #19 as duplicates

@dekimsey
Copy link
Author

@pemontto I'm fine with that. I thought this project was stale. I'm glad to see there's active development. If you are interested in resolving the failing test please do. I'm not sure I can make time at the moment to fix it. Plus our logstash instance is 5.3 :/!

Thank you!

@pemontto
Copy link
Contributor

Thanks @dekimsey all fixed and improved in #49 now thanks to your help!
I adapted the code from find_first_mime_type

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants