spacefreak86 / pyquarantine-milter

A pymilter based sendmail/postfix pre-queue quarantine filter
GNU General Public License v3.0
1 stars 0 forks source link

(non-replicable) Segfault #4

Closed alienmindbender closed 2 years ago

alienmindbender commented 4 years ago

Unfortunately, I have no clue why the milter stopped working after this error, it may has something to do with pymilter.

I still can't say whats causing this - but it always happens at "content mimetype is text/plain, converting to text/html". The emails itself can't be the cause, since restarting the milter and resending an identical message won't cause a segfault again. It just happens after some time...

[Tue Oct 15 15:54:47 2019] pyquarantine-mi[3905]: segfault at 20 ip 000000000058b62d sp 00007ff5baf87c00 error 4 in python3.6[400000+3b4000]
[Tue Oct 15 16:15:30 2019] traps: pyquarantine-mi[30844] general protection ip:7f2ef128908b sp:7f2eede16c50 error:0 in etree.cpython-36m-x86_64-linux-gnu.so[7f2ef0f4e000+50d000]
[Tue Oct 15 16:23:14 2019] pyquarantine-mi[20644]: segfault at 1d600000b0a ip 00000000004a9c58 sp 00007f33838b2de0 error 6 in python3.6[400000+3b4000]
[Tue Oct 15 16:36:30 2019] traps: pyquarantine-mi[23749] general protection ip:58a974 sp:7fbfc3ffc9b0 error:0 in python3.6[400000+3b4000]
[Mon Oct 21 13:54:55 2019] pyquarantine-mi[13125]: segfault at 1 ip 00000000006322f6 sp 00007f98f7205ac0 error 6 in python3.6[400000+3b4000]
[Tue Oct 22 14:18:15 2019] pyquarantine-mi[12125]: segfault at 2 ip 0000000000632397 sp 00007f8cbe9f5ac0 error 6 in python3.6[400000+3b4000]
[Tue Oct 22 14:38:31 2019] pyquarantine-mi[3469]: segfault at 1 ip 00000000006322f6 sp 00007ff1c4cf4ac0 error 6 in python3.6[400000+3b4000]
[Tue Oct 22 16:03:51 2019] traps: pyquarantine-mi[11660] general protection ip:7f0c9335408b sp:7f0c906e2c50 error:0 in etree.cpython-36m-x86_64-linux-gnu.so[7f0c93019000+50d000]
[Tue Oct 22 17:17:00 2019] pyquarantine-mi[7584]: segfault at 1 ip 00000000006322f6 sp 00007fa2a4c19de0 error 6 in python3.6[400000+3b4000]
spacefreak86 commented 4 years ago

Thanks to your bug report, I just realized that I forgot to escape html characters when feeding a plain/text message part to BeautifulSoup, I fixed that already. This may help already to prevent the segfault to happen.

Commit 5892d9a2b785315e967e267a212c1640432c8003

Additionally, I added a few more debug messages to narrow down the problem.

Commit 5ff72dc5e7e8c67e29e6cb8147eaa1105447341e

Currently I suspect that the segfault happens when a string containing html gets parsed during the creation of the BeautifulSoup object. I think that because the error message refers to xml.etree of pythons standard library and as far as I know BeautifulSoup is the only dependency of pyquarantine-milter which uses the xml module.

Please run the new version and post the debug output again if the problem still persists. BTW: thanks alot for your contributions, I really appreciate it.

alienmindbender commented 4 years ago

I started the milter with the commit (and added brackets) last night and it got stuck again this morning:

Oct 23 10:27:26 mail pyquarantine-milter: [pyquarantine.notifications] DEBUG: 5D3C128DB: extraction email text from original email
Oct 23 10:27:26 mail pyquarantine-milter: [pyquarantine.notifications] DEBUG: 5D3C128DB: trying to find text part of email
Oct 23 10:27:26 mail pyquarantine-milter: [pyquarantine.notifications] DEBUG: 5D3C128DB: extracting content of email text part
Oct 23 10:27:26 mail pyquarantine-milter: [pyquarantine.notifications] DEBUG: 5D3C128DB: content mimetype is text/plain, converting to text/html
Oct 23 10:27:26 mail pyquarantine-milter: [pyquarantine.notifications] DEBUG: 5D3C128DB: creating BeatufilSoup object
Oct 23 10:28:17 mail postfix/smtpd[7445]: warning: milter inet:127.0.0.1:8899: can't read SMFIC_OPTNEG reply packet header: Connection timed out
Oct 23 10:28:17 mail postfix/smtpd[7445]: warning: milter inet:127.0.0.1:8899: read error in initial handshake

However - there was no corresponding segfault this time and we got one debug message more as before.

Maybe its connected to me using "start-stop-daemon" in conjunction with the "--backround" flag. Which is kind of a last resort if a process does not detach on it's own. I have the feeling this does not happen, if its run foreground. I will keep it running in a screen session this time and see if it happens again.

BTW: thanks alot for your contributions, I really appreciate it.

Would love to help you with the code as well - but sadly I never got into python :-( As I said - I was looking for a milter with the exact(!) featureset. This works great in conjunction with rspamd and extends it nicely. So thank you! ;-)

alienmindbender commented 4 years ago

Still happens if run foreground... and after the last updates it happens even more frequent than before.

Sending a simple email with an attachment using mutt is only sometimes causing a lockup or segfault:

From sender@domain.tld Thu Oct 24 12:02:14 2019
Date: Thu, 24 Oct 2019 12:02:14 +0200
From:   <sender@domain.tld>
To: receiver@domain.tld
Message-ID: <20191024100210.GA61908@MBP.local>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="azLHFNyN32YCQGCU"
Content-Disposition: inline
User-Agent: Mutt/1.12.2 (2019-09-21)
Status: RO
Content-Length: 213480
Lines: 2935

--azLHFNyN32YCQGCU
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline

--azLHFNyN32YCQGCU
Content-Type: application/octet-stream
Content-Disposition: attachment; filename="doc_mit_virus(emoted).doc"
Content-Transfer-Encoding: base64

[stripped]

--azLHFNyN32YCQGCU--

Sending an email using thunderbird instead causes very often a lockup or segfault:

To: Receiver <receiver@domain.tld>
From: Sender <sender@domain.tld>
Autocrypt: addr=sender@domain.tld; prefer-encrypt=mutual; keydata=
 mQINBFlt9RMBEACsakgJX2GpBq7fB4esCZOWqzEHvPJtq5+dcJt/SBaV2ivVcybpa+uYlF2C
 IEoCayeIl2yEci0ZBZFLX7rxUleAPojtGinSWZEt2N0uulR/Pkjmhw5b7Gwq+0X9WUYSFOFp
 ipagNPTn0VaVNmMaEggooj6I3E5Ky3TnfP5jyqxNQwTdFAojvL/n8wxMeFiDiGzU41gQAryn
 J8pxW3e5bdq2NixRy1glz8SsVqBEfKub3rwFOtAqHJ0q9BRtxwTWZaFGokpIa4XrWIHZX/W/
[stripped]
 kJp3EeN9Q9YRyJee5v4OI28EyCJfD9h7pSh3iJI1cXl3hfdgdI2fC6fId+fXGChSTX7M7+i7
 E8TqZlhlm5hztRU47WbYfIzoglsQWbDluNo9DmJEj4NhEWsWAQNDGCqUF3eZ3VhC9GHht8A7
 Vp3sT4DJsStbOf0q/MlzbZlguRWf9jNYb5GtjkC5GvuDh7lVBEfk1NJIOaN1H83eRr3hYrTF
 FUBj+hy73OTxfA==
Message-ID: <268e8fa6-4d7f-5910-8139-7a8460739da2@domain.tld>
Date: Thu, 24 Oct 2019 12:08:03 +0200
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.14; rv:68.0)
 Gecko/20100101 Thunderbird/68.1.2
MIME-Version: 1.0
Content-Type: multipart/mixed;
 boundary="------------4C1B785E850DA8481E274691"

This is a multi-part message in MIME format.
--------------4C1B785E850DA8481E274691
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: 7bit

--------------4C1B785E850DA8481E274691
Content-Type: application/msword; x-mac-type="0"; x-mac-creator="0";
 name="doc_mit_virus(emoted).doc"
Content-Transfer-Encoding: base64
Content-Disposition: attachment;
 filename="doc_mit_virus(emoted).doc"

[stripped]
--------------4C1B785E850DA8481E274691--

Kernel messages are the same:

[Thu Oct 24 10:23:36 2019] python3[1508]: segfault at 7ff909c1fe48 ip 00007ff909c1fe48 sp 00007ff908bdc858 error 15
[Thu Oct 24 10:37:58 2019] traps: python3[6168] general protection ip:7f3b1d3d108b sp:7f3b13ffc790 error:0 in etree.cpython-36m-x86_64-linux-gnu.so[7f3b1d096000+50d000]
[Thu Oct 24 10:51:00 2019] python3[3589]: segfault at 10 ip 000000000050cd07 sp 00007f1480cc3710 error 4 in python3.6[400000+3b4000]
[Thu Oct 24 10:52:04 2019] traps: python3[13446] general protection ip:58a974 sp:7f24305384f0 error:0 in python3.6[400000+3b4000]
[Thu Oct 24 10:59:54 2019] traps: python3[3132] general protection ip:58a974 sp:7fda03ee29b0 error:0 in python3.6[400000+3b4000]
[Thu Oct 24 11:54:34 2019] python3[3807]: segfault at 4000000670 ip 00000000004a9c58 sp 00007fe3eae44100 error 6 in python3.6[400000+3b4000]
[Thu Oct 24 11:59:58 2019] python3[25860]: segfault at 4000000670 ip 00000000004a9c58 sp 00007f853e40c100 error 6 in python3.6[400000+3b4000]
[Thu Oct 24 12:02:33 2019] python3[1747]: segfault at 4000000670 ip 00000000004a9c58 sp 00007fa46daa8100 error 6 in python3.6[400000+3b4000]

Once I got this:

2019-10-24 10:48:22 pyquarantine-milter[pyquarantine.notifications]: [DEBUG] 0F801181D1: content mimetype is text/plain, converting to text/html
2019-10-24 10:48:22 pyquarantine-milter[pyquarantine.notifications]: [DEBUG] 0F801181D1: creating BeatufilSoup object
2019-10-24 10:48:22 pyquarantine-milter[pyquarantine]: [INFO] 181F1205D7: adding to quarantine 'virusmail' for: receiver@domain.tld
Fatal Python error: GC object already tracked

Current thread 0x00007f14814c5700 (most recent call first):
  File "/uSegmentation fault
spacefreak86 commented 4 years ago

I still expect the problem within the lxml library. So I added an option to switch the html parser implementation.

Commit 7020c53b28deecd2546386bf8b18efb97f4d67da

Please run the milter with the following configuration option: notification_email_parser_lib = html.parser

alienmindbender commented 4 years ago

1271 mails passed the milter with notification_email_parser_lib = html.parser without a hiccup since saturday. 👍🏽

spacefreak86 commented 4 years ago

Great :-) So the bug is in your currently installed lxml library.

I see two possibilities:

Unfortunately, I don't have the ability to find that out exactly, because I am running the whole thing on Gentoo and I was unable to reproduce this error.

If you want this problem to get fixed, you have to open a bug report for Ubuntu or at the project website of lxml. I think it is worth to try that, because the performance of the lxml parser library is much better than html.parser.

I will keep this bug report opened for a while. If no segfaults occur within the next week, I will close it.

alienmindbender commented 4 years ago

I'am not using the packages from the official ubuntu repos, but the one provided by PyPi.

I tried a couple of different versions of lxml, all produce an error sooner or later. Sometimes the given error changes - like: Fatal Python error: PyThreadState_Delete: NULL interp. I even compiled all packages using --no-binary to no avail...

Maybe you can make some sense of the backtraces? If it's indeed an lxml error, I'am happy to report it upsteam.

gdb

(gdb) run /usr/local/bin/pyquarantine-milter -s inet:8899@127.0.0.1 -c /etc/pyquarantine/pyquarantine.conf -d
Starting program: /usr/bin/python3.6 /usr/local/bin/pyquarantine-milter -s inet:8899@127.0.0.1 -c /etc/pyquarantine/pyquarantine.conf -d
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
2019-10-29 12:09:20 pyquarantine-milter[pyquarantine.run]: [INFO] PyQuarantine-Milter starting
[...]
[New Thread 0x7ffff2784700 (LWP 6450)]
[New Thread 0x7ffff1f83700 (LWP 6451)]
[New Thread 0x7ffff1782700 (LWP 6452)]
[New Thread 0x7ffff0f81700 (LWP 6453)]
[...]
2019-10-29 12:11:03 pyquarantine-milter[pyquarantine.notifications]: [DEBUG] C312828951: trying to create BeatufilSoup object with parser lib lxml, text length is 4588 bytes

Thread 4 "python3.6" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7ffff1782700 (LWP 6452)]
0x00007ffff43f108b in __pyx_f_4lxml_5etree__handleSaxTargetStartNoNs.4645 () from /usr/local/lib/python3.6/dist-packages/lxml/etree.cpython-36m-x86_64-linux-gnu.so

(gdb) bt

#0  0x00007ffff43f108b in __pyx_f_4lxml_5etree__handleSaxTargetStartNoNs.4645 () from /usr/local/lib/python3.6/dist-packages/lxml/etree.cpython-36m-x86_64-linux-gnu.so
#1  0x00007ffff42d1370 in htmlParseStartTag () from /usr/local/lib/python3.6/dist-packages/lxml/etree.cpython-36m-x86_64-linux-gnu.so
#2  0x00007ffff42d39c1 in htmlParseChunk () from /usr/local/lib/python3.6/dist-packages/lxml/etree.cpython-36m-x86_64-linux-gnu.so
#3  0x00007ffff42d4718 in __pyx_f_4lxml_5etree_11_FeedParser_feed.8014 () from /usr/local/lib/python3.6/dist-packages/lxml/etree.cpython-36m-x86_64-linux-gnu.so
#4  0x00007ffff42d5f4e in __pyx_pw_4lxml_5etree_11_FeedParser_1feed () from /usr/local/lib/python3.6/dist-packages/lxml/etree.cpython-36m-x86_64-linux-gnu.so
#5  0x00007ffff42f5ddf in __Pyx_CyFunction_CallAsMethod.7585 () from /usr/local/lib/python3.6/dist-packages/lxml/etree.cpython-36m-x86_64-linux-gnu.so
#6  0x00000000005aa69c in _PyObject_FastCallDict (kwargs=<optimized out>, nargs=2, args=0x7fffe401b1d0, func=<cython_function_or_method at remote 0x7ffff3eabb10>) at ../Objects/tupleobject.c:131
#7  _PyObject_FastCallKeywords () at ../Objects/abstract.c:2496
#8  0x000000000050ab53 in call_function.lto_priv () at ../Python/ceval.c:4875
#9  0x000000000050c549 in _PyEval_EvalFrameDefault () at ../Python/ceval.c:3335
#10 0x0000000000509ce8 in PyEval_EvalFrameEx (throwflag=0,
    f=Frame 0x7fffe401b038, for file /usr/local/lib/python3.6/dist-packages/bs4/builder/_lxml.py, line 294, in feed (self=<LXMLTreeBuilder(_default_parser=None, soup=<BeautifulSoup(element_classes={}, builder=<...>, is_xml=False, known_xml=False, _namespaces={'xml': 'http://www.w3.org/XML/1998/namespace'}, parse_only=None, markup=b'<html>\n  <head>\n\n    <meta http-equiv="content-type" content="text/html; charset=UTF-8">\n  </head>\n  <body>\n    <h1>Lorem Ipsum</h1>\n    <h4>"Neque porro quisquam est qui dolorem ipsum quia dolor sit amet,\n      consectetur, adipisci velit..."</h4>\n    <h5>"There is no one who loves pain itself, who seeks after it and\n      wants to have it, simply because it is pain..."</h5>\n    <hr>\n    <div id="Content">\n      <div class="boxed">\n        <div id="lipsum">\n          <p>\n            Lorem ipsum dolor sit amet, consectetur adipiscing elit.\n            Proin lobortis quis est et imperdiet. Curabitur sagittis\n            erat non velit scelerisque, lobortis commodo sapien...(truncated)) at ../Python/ceval.c:754
#11 _PyFunction_FastCall (globals=<optimized out>, nargs=140737018703928, args=<optimized out>, co=<optimized out>) at ../Python/ceval.c:4933
#12 fast_function.lto_priv () at ../Python/ceval.c:4968
#13 0x000000000050aa1d in call_function.lto_priv () at ../Python/ceval.c:4872
#14 0x000000000050c549 in _PyEval_EvalFrameDefault () at ../Python/ceval.c:3335
#15 0x0000000000509ce8 in PyEval_EvalFrameEx (throwflag=0,
    f=Frame 0x7ffff0743708, for file /usr/local/lib/python3.6/dist-packages/bs4/__init__.py, line 382, in _feed (self=<BeautifulSoup(element_classes={}, builder=<LXMLTreeBuilder(_default_parser=None, soup=<...>, nsmaps=[{'http://www.w3.org/XML/1998/namespace': 'xml'}], cdata_list_attributes={'*': ['class', 'accesskey', 'dropzone'], 'a': ['rel', 'rev'], 'link': ['rel', 'rev'], 'td': ['headers'], 'th': ['headers'], 'form': ['accept-charset'], 'object': ['archive'], 'area': ['rel'], 'icon': ['sizes'], 'iframe': ['sandbox'], 'output': ['for']}, preserve_whitespace_tags={'pre', 'textarea'}, store_line_numbers=False, processing_instruction_class=<type at remote 0xce53e8>, parser=<lxml.etree.HTMLParser at remote 0x7ffff0751178>) at remote 0x7ffff06c8588>, is_xml=False, known_xml=False, _namespaces={'xml': 'http://www.w3.org/XML/1998/namespace'}, parse_only=None, markup=b'<html>\n  <head>\n\n    <meta http-equiv="content-type" content="text/html; charset=UTF-8">\n  </head>\n  <body>\n    <h1>Lorem Ipsum</h1>\n    <h4>"Nequ...(truncated)) at ../Python/ceval.c:754
#16 _PyFunction_FastCall (globals=<optimized out>, nargs=140737227536136, args=<optimized out>, co=<optimized out>) at ../Python/ceval.c:4933
#17 fast_function.lto_priv () at ../Python/ceval.c:4968
#18 0x000000000050aa1d in call_function.lto_priv () at ../Python/ceval.c:4872
#19 0x000000000050c549 in _PyEval_EvalFrameDefault () at ../Python/ceval.c:3335
#20 0x00000000005081d5 in PyEval_EvalFrameEx (throwflag=0,
    f=Frame 0x7fffe40188c8, for file /usr/local/lib/python3.6/dist-packages/bs4/__init__.py, line 313, in __init__ (self=<BeautifulSoup(element_classes={}, builder=<LXMLTreeBuilder(_default_parser=None, soup=<...>, nsmaps=[{'http://www.w3.org/XML/1998/namespace': 'xml'}], cdata_list_attributes={'*': ['class', 'accesskey', 'dropzone'], 'a': ['rel', 'rev'], 'link': ['rel', 'rev'], 'td': ['headers'], 'th': ['headers'], 'form': ['accept-charset'], 'object': ['archive'], 'area': ['rel'], 'icon': ['sizes'], 'iframe': ['sandbox'], 'output':
#21 _PyEval_EvalCodeWithName.lto_priv.1836 () at ../Python/ceval.c:4166
#22 0x0000000000509647 in _PyFunction_FastCallDict () at ../Python/ceval.c:5084
#23 0x00000000005951c1 in _PyObject_FastCallDict (kwargs=0x0, nargs=3, args=0x7ffff1780af0, func=<function at remote 0x7ffff4816f28>) at ../Objects/abstract.c:2310
#24 _PyObject_Call_Prepend (kwargs=0x0, args=<optimized out>, obj=<optimized out>, func=<function at remote 0x7ffff4816f28>) at ../Objects/abstract.c:2373
#25 method_call.lto_priv () at ../Objects/classobject.c:314
#26 0x000000000054a11f in PyObject_Call (kwargs=0x0,
    args=(b'<html>\n  <head>\n\n    <meta http-equiv="content-type" content="text/html; charset=UTF-8">\n  </head>\n  <body>\n    <h1>Lorem Ipsum</h1>\n    <h4>"Neque porro quisquam est qui dolorem ipsum quia dolor sit amet,\n      consectetur, adipisci velit..."</h4>\n    <h5>"There is no one who loves pain itself, who seeks after it and\n      wants to have it, simply because it is pain..."</h5>\n    <hr>\n    <div id="Content">\n      <div class="boxed">\n        <div id="lipsum">\n          <p>\n            Lorem ipsum dolor sit amet, consectetur adipiscing elit.\n            Proin lobortis quis est et imperdiet. Curabitur sagittis\n            erat non velit scelerisque, lobortis commodo sapien\n            ullamcorper. Morbi mollis venenatis dictum. Etiam euismod\n            urna in mi sagittis, in cursus eros mollis. Aenean convallis\n            elit pretium quam mollis iaculis. Vestibulum sed sodales\n            tortor. Donec at convallis diam. Etiam egestas interdum\n            egestas. Pellentesque a bib...(truncated),
    func=<method at remote 0x7ffff4990388>) at ../Objects/abstract.c:2261
#27 slot_tp_init () at ../Objects/typeobject.c:6420
#28 0x0000000000551761 in type_call.lto_priv () at ../Objects/typeobject.c:915
#29 0x00000000005aa69c in _PyObject_FastCallDict (kwargs=<optimized out>, nargs=2, args=0x7ffff07483f0, func=<type at remote 0xd6df58>) at ../Objects/tupleobject.c:131
#30 _PyObject_FastCallKeywords () at ../Objects/abstract.c:2496
#31 0x000000000050ab53 in call_function.lto_priv () at ../Python/ceval.c:4875
#32 0x000000000050c549 in _PyEval_EvalFrameDefault () at ../Python/ceval.c:3335
#33 0x0000000000509ce8 in PyEval_EvalFrameEx (throwflag=0,
    f=Frame 0x7ffff0748240, for file /usr/local/lib/python3.6/dist-packages/pyquarantine/notifications.py, line 240, in get_text (self=<EMailNotification(quarantine_name='virusmail', global_config={'quarantines': 'virusmail', 'preferred_quarantine_action': 'last'}, config={'ignore_hosts': '10.0.0.0/8,172.16.0.0/12,192.168.0.0/16', 'regex': '^X-Virus-Status: Infected.*', 'smtp_host': '127.0.0.1', 'smtp_port': '10025', 'quarantine_type': 'file', 'quarantine_directory': '/var/virusmails/', 'action': 'discard', 'reject_reason': 'Message rejected', 'notification_type': 'email', 'notification_email_envelope_from': 'noreply@domain.tld', 'notification_email_from': 'Virus Alert <noreply@domain.tld>', 'notification_email_subject': 'Virus quarantine notification', 'notification_email_template': 'templates/notification.template', 'notification_email_strip_images': 'False', 'notification_email_replacement_img': 'templates/removed.png', 'notification_email_embedded_imgs': 'templates/random.png', 'whitelist_type': 'none',...(truncated)) at ../Python/ceval.c:754
#34 _PyFunction_FastCall (globals=<optimized out>, nargs=140737227555392, args=<optimized out>, co=<optimized out>) at ../Python/ceval.c:4933
#35 fast_function.lto_priv () at ../Python/ceval.c:4968
#36 0x000000000050aa1d in call_function.lto_priv () at ../Python/ceval.c:4872
#37 0x000000000050c549 in _PyEval_EvalFrameDefault () at ../Python/ceval.c:3335
#38 0x00000000005081d5 in PyEval_EvalFrameEx (throwflag=0,
    f=Frame 0x7ffff0748048, for file /usr/local/lib/python3.6/dist-packages/pyquarantine/notifications.py, line 253, in get_text_multipart (self=<EMailNotification(quarantine_name='virusmail', global_config={'quarantines': 'virusmail', 'preferred_quarantine_action': 'last'}, config={'ignore_hosts': '10.0.0.0/8,172.16.0.0/12,192.168.0.0/16', 'regex': '^X-Virus-Status: Infected.*', 'smtp_host': '127.0.0.1', 'smtp_port': '10025', 'quarantine_type': 'file', 'quarantine_directory': '/var/virusmails/', 'action': 'discard', 'reject_reason':
#39 _PyEval_EvalCodeWithName.lto_priv.1836 () at ../Python/ceval.c:4166
#40 0x000000000050a020 in fast_function.lto_priv () at ../Python/ceval.c:4992
#41 0x000000000050aa1d in call_function.lto_priv () at ../Python/ceval.c:4872
#42 0x000000000050c549 in _PyEval_EvalFrameDefault () at ../Python/ceval.c:3335
#43 0x0000000000509ce8 in PyEval_EvalFrameEx (throwflag=0,
    f=Frame 0x7fffe40087c8, for file /usr/local/lib/python3.6/dist-packages/pyquarantine/notifications.py, line 307, in get_html_text_part (self=<EMailNotification(quarantine_name='virusmail', global_config={'quarantines': 'virusmail', 'preferred_quarantine_action': 'last'}, config={'ignore_hosts': '10.0.0.0/8,172.16.0.0/12,192.168.0.0/16', 'regex': '^X-Virus-Status: Infected.*', 'smtp_host': '127.0.0.1', 'smtp_port': '10025', 'quarantine_type': 'file', 'quarantine_directory': '/var/virusmails/', 'action': 'discard', 'reject_reason': 'Message rejected', 'notification_type': 'email', 'notification_email_envelope_from': 'noreply@domain.tld', 'notification_email_from': 'Virus Alert <noreply@domain.tld>', 'notification_email_subject': 'Virus quarantine notification', 'notification_email_template': 'templates/notification.template', 'notification_email_strip_images': 'False', 'notification_email_replacement_img': 'templates/removed.png', 'notification_email_embedded_imgs': 'templates/random.png', 'whitelist_type...(truncated)) at ../Python/ceval.c:754
#44 _PyFunction_FastCall (globals=<optimized out>, nargs=140737018628040, args=<optimized out>, co=<optimized out>) at ../Python/ceval.c:4933
#45 fast_function.lto_priv () at ../Python/ceval.c:4968
#46 0x000000000050aa1d in call_function.lto_priv () at ../Python/ceval.c:4872
#47 0x000000000050c549 in _PyEval_EvalFrameDefault () at ../Python/ceval.c:3335
#48 0x00000000005081d5 in PyEval_EvalFrameEx (throwflag=0,
    f=Frame 0x7fffe4006a18, for file /usr/local/lib/python3.6/dist-packages/pyquarantine/notifications.py, line 337, in notify (self=<EMailNotification(quarantine_name='virusmail', global_config={'quarantines': 'virusmail', 'preferred_quarantine_action': 'last'}, config={'ignore_hosts': '10.0.0.0/8,172.16.0.0/12,192.168.0.0/16', 'regex': '^X-Virus-Status: Infected.*', 'smtp_host': '127.0.0.1', 'smtp_port': '10025', 'quarantine_type': 'file', 'quarantine_directory': '/var/virusmails/', 'action': 'discard', 'reject_reason': 'Message rejected', 'notification_type': 'email', 'notification_email_envelope_from': 'noreply@domain.tld', 'notification_email_from': 'Virus Alert <noreply@domain.tld>', 'notification_email_subject': 'Virus quarantine notification', 'notification_email_template': 'templates/notification.template', 'notification_email_strip_images': 'False', 'notification_email_replacement_img': 'templates/removed.png', 'notification_email_embedded_imgs': 'templates/random.png', 'whitelist_type': 'none', '...(truncated)) at ../Python/ceval.c:754
#49 _PyEval_EvalCodeWithName.lto_priv.1836 () at ../Python/ceval.c:4166
#50 0x000000000050a020 in fast_function.lto_priv () at ../Python/ceval.c:4992
#51 0x000000000050aa1d in call_function.lto_priv () at ../Python/ceval.c:4872
#52 0x000000000050c549 in _PyEval_EvalFrameDefault () at ../Python/ceval.c:3335
#53 0x00000000005081d5 in PyEval_EvalFrameEx (throwflag=0,
    f=Frame 0x7fffe4003668, for file /usr/local/lib/python3.6/dist-packages/pyquarantine/__init__.py, line 334, in eom (quarantines=[({'ignore_hosts': '10.0.0.0/8,172.16.0.0/12,192.168.0.0/16', 'regex': '^X-Virus-Status: Infected.*', 'smtp_host': '127.0.0.1', 'smtp_port': '10025', 'quarantine_type': 'file', 'quarantine_directory': '/var/virusmails/', 'action': 'discard', 'reject_reason': 'Message rejected', 'notification_type': 'email', 'notification_email_envelope_from': 'noreply@domain.tld', 'notification_email_from': 'Virus Alert <noreply@domain.tld>', 'notification_email_subject': 'Virus quarantine notification', 'notification_email_template': 'templates/notification.template', 'notification_email_strip_images': 'False', 'notification_email_replacement_img': 'templates/removed.png', 'notification_email_embedded_imgs': 'templates/random.png', 'whitelist_type': 'none', 'whitelist_db_connection': 'mysql://user:password@localhost/database', 'whitelist_db_table': 'whitelist', 'name': 'virusmail', 'index': 0,...(truncated)) at ../Python/ceval.c:754
#54 _PyEval_EvalCodeWithName.lto_priv.1836 () at ../Python/ceval.c:4166
#55 0x000000000050a020 in fast_function.lto_priv () at ../Python/ceval.c:4992
#56 0x000000000050aa1d in call_function.lto_priv () at ../Python/ceval.c:4872
#57 0x000000000050c549 in _PyEval_EvalFrameDefault () at ../Python/ceval.c:3335
#58 0x00000000005081d5 in PyEval_EvalFrameEx (throwflag=0, f=Frame 0x7ffff07411f0, for file /usr/local/lib/python3.6/dist-packages/Milter/__init__.py, line 772, in <lambda> (ctx=<milter.Context at remote 0x7ffff7ea9c10>)) at ../Python/ceval.c:754
#59 _PyEval_EvalCodeWithName.lto_priv.1836 () at ../Python/ceval.c:4166
#60 0x000000000058952b in PyEval_EvalCodeEx (closure=<optimized out>, kwdefs=<optimized out>, defcount=0, defs=0x0, kwcount=0, kws=0x0, argcount=<optimized out>, args=0x7ffff7e4fca0, locals=0x0, globals=<optimized out>, _co=<optimized out>) at ../Python/ceval.c:4187
#61 function_call.lto_priv () at ../Objects/funcobject.c:604
#62 0x00000000005a04ce in PyObject_Call () at ../Objects/abstract.c:2261
#63 0x00007ffff675dbd9 in _generic_wrapper (self=0x7ffff7ea9c10, cb=<function at remote 0x7ffff27b4620>, arglist=(<milter.Context at remote 0x7ffff7ea9c10>,)) at miltermodule.c:493
#64 0x00007ffff6545312 in ?? () from /usr/lib/x86_64-linux-gnu/libmilter.so.1.0.1
#65 0x00007ffff65456c2 in mi_engine () from /usr/lib/x86_64-linux-gnu/libmilter.so.1.0.1
#66 0x00007ffff654810a in ?? () from /usr/lib/x86_64-linux-gnu/libmilter.so.1.0.1
#67 0x00007ffff77cc6db in start_thread (arg=0x7ffff1782700) at pthread_create.c:463
#68 0x00007ffff7b0588f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

(gdb) py-bt

Traceback (most recent call first):
  File "/usr/local/lib/python3.6/dist-packages/bs4/builder/_lxml.py", line 294, in feed
    self.parser.feed(markup)
  File "/usr/local/lib/python3.6/dist-packages/bs4/__init__.py", line 382, in _feed
    self.builder.feed(self.markup)
  File "/usr/local/lib/python3.6/dist-packages/bs4/__init__.py", line 313, in __init__
    self._feed()
  File "/usr/local/lib/python3.6/dist-packages/pyquarantine/notifications.py", line 240, in get_text
    soup = BeautifulSoup(text, self.parser_lib)
  File "/usr/local/lib/python3.6/dist-packages/pyquarantine/notifications.py", line 253, in get_text_multipart
    soup = self.get_text(queueid, part)
  File "/usr/local/lib/python3.6/dist-packages/pyquarantine/notifications.py", line 307, in get_html_text_part
    soup = self.get_text_multipart(queueid, msg)
  File "/usr/local/lib/python3.6/dist-packages/pyquarantine/notifications.py", line 337, in notify
    queueid, email.message_from_binary_file(fp))
  File "/usr/local/lib/python3.6/dist-packages/pyquarantine/__init__.py", line 334, in eom
    subgroups, named_subgroups)
  File "/usr/local/lib/python3.6/dist-packages/Milter/__init__.py", line 772, in <lambda>
    milter.set_eom_callback(lambda ctx: ctx.getpriv().eom())

(gdb) info threads

  Id   Target Id         Frame
  1    Thread 0x7ffff7fe7740 (LWP 6445) "python3.6" 0x00007ffff7af8bf9 in __GI___poll (fds=0x7fffffffd998, nfds=1, timeout=5000) at ../sysdeps/unix/sysv/linux/poll.c:29
  2    Thread 0x7ffff2784700 (LWP 6450) "python3.6" 0x00007ffff7a2426c in __GI___sigtimedwait (set=<optimized out>, set@entry=0x7ffff2783e40, info=info@entry=0x7ffff2783d80, timeout=timeout@entry=0x0) at ../sysdeps/unix/sysv/linux/sigtimedwait.c:42
  3    Thread 0x7ffff1f83700 (LWP 6451) "python3.6" 0x00007ffff7af8bf9 in __GI___poll (fds=0x7fffec000b20, nfds=1, timeout=10000) at ../sysdeps/unix/sysv/linux/poll.c:29
* 4    Thread 0x7ffff1782700 (LWP 6452) "python3.6" 0x00007ffff43f108b in __pyx_f_4lxml_5etree__handleSaxTargetStartNoNs.4645 () from /usr/local/lib/python3.6/dist-packages/lxml/etree.cpython-36m-x86_64-linux-gnu.so
  5    Thread 0x7ffff0f81700 (LWP 6453) "python3.6" 0x00007ffff77d2f85 in futex_abstimed_wait_cancelable (private=<optimized out>, abstime=0x7ffff0f80e90, expected=0, futex_word=0x7ffff674e1a0) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
  6    Thread 0x7fffe3fff700 (LWP 6464) "python3.6" 0x00007ffff77d56d6 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x7fffdc0011b0) at ../sysdeps/unix/sysv/linux/futex-internal.h:205

(gdb) py-list

 289
 290        def feed(self, markup):
 291            encoding = self.soup.original_encoding
 292            try:
 293                self.parser = self.parser_for(encoding)
>294                self.parser.feed(markup)
 295                self.parser.close()
 296            except (UnicodeDecodeError, LookupError, etree.ParserError) as e:
 297                raise ParserRejectedMarkup(e)
 298
 299

(gdb) thread apply all py-list

 Thread 6 (Thread 0x7fffe3fff700 (LWP 6464)):
 290            self._waiters.append(waiter)
 291            saved_state = self._release_save()
 292            gotit = False
 293            try:    # restore state no matter what (e.g., KeyboardInterrupt)
 294                if timeout is None:
>295                    waiter.acquire()
 296                    gotit = True
 297                else:
 298                    if timeout > 0:
 299                        gotit = waiter.acquire(True, timeout)
 300                    else:

Thread 5 (Thread 0x7ffff0f81700 (LWP 6453)):
Unable to locate gdb frame for python bytecode interpreter

Thread 4 (Thread 0x7ffff1782700 (LWP 6452)):
 289
 290        def feed(self, markup):
 291            encoding = self.soup.original_encoding
 292            try:
 293                self.parser = self.parser_for(encoding)
>294                self.parser.feed(markup)
 295                self.parser.close()
 296            except (UnicodeDecodeError, LookupError, etree.ParserError) as e:
 297                raise ParserRejectedMarkup(e)
 298
 299

Thread 3 (Thread 0x7ffff1f83700 (LWP 6451)):
---Type <return> to continue, or q <return> to quit---
Unable to locate gdb frame for python bytecode interpreter

Thread 2 (Thread 0x7ffff2784700 (LWP 6450)):
Unable to locate gdb frame for python bytecode interpreter

Thread 1 (Thread 0x7ffff7fe7740 (LWP 6445)):
 793      # processed.  It's safer to shutdown sendmail, kill the filter process,
 794      # restart the filter, and then restart sendmail.
 795      milter.opensocket(rmsock)
 796      start_seq = _seq
 797      try:
>798        milter.main()
 799      except milter.error:
 800        if start_seq == _seq: raise # couldn't start
 801        # milter has been running for a while, but now it can't start new threads
 802        raise milter.error("out of thread resources")
 803
alienmindbender commented 4 years ago

Note: I recompiled lxml with static dependencies:

libiconv-1.16
libxml2-2.9.9
libxslt-1.1.33
zlib-1.2.11

using the lxmls master branch (4.5.0a0). After "some" emails (last time about 210) the milter hangs at trying to create BeatufilSoup object with parser lib lxml, text length is 4588 bytes.

spacefreak86 commented 4 years ago

Unfortunately, the backtraces don't make sense to me, but I guess that the problem occurs, if lxml is used in a multithreaded environment. Like you told, the problem is not related to a specific content, as the same e-mail does not cause a segfault after restarting the milter.

It would be great if you could report this bug upstream.

spacefreak86 commented 4 years ago

Did you report the bug to the lxml developers? If yes, it would be nice if you could post a reference here.

alienmindbender commented 4 years ago

I have to admit... I just posted a couple of minutes ago on the mailing list. I will get back to you asap there is some feedback!

alienmindbender commented 4 years ago

No reply on the mailing list so far :-(

spacefreak86 commented 2 years ago

Because the problem is still not reproducible, I will close this issue for now.