[Dovecot] 2.1.12: Panic: file solr-connection.c: line 547 (solr_connection_post_more)
Hi all,
I am having a problem indexing one of my mailboxes using the solr fts backend in dovecot 2.1.12 For many mailboxes it works just fine, but on one mailbox I currently always get a panic.
solr setup: Java: icedtea 6.1.11.5 Solr: 3.6.2 running in tomcat 7.0.32
Command to reproduce error: doveadm index -u my@user badmailbox
I already noticed that there have been some solr backend fixes just before 2.1.21 release... Is this another bug in the backend? Any idea?
IMO relevant logs line parts: java.io.CharConversionException: Invalid UTF-8 start byte 0xf8 (at char #483989, byte #532382)
complete dovecot log: doveadm(my@user): Error: fts_solr: Invalid XML input at 85:198: mismatched tag (near: <html><head><title>Apache Tomcat/7.0.32-gentoo - Error report</title><style><!--H1 {font-family:Tahoma,Arial,sans-serif;color:wh) doveadm(my@user): Panic: file solr-connection.c: line 547 (solr_connection_post_more): assertion failed: (maxfd >= 0) doveadm(my@user): Error: Raw backtrace: /usr/lib64/dovecot/libdovecot.so.0(+0x4bcdb) [0x34fbd53ecdb] -> /usr/lib64/dovecot/libdovecot.so.0(default_fatal_handler+0x3a) [0x34fbd53edb8] -> /usr/lib64/dovecot/libdovecot.so.0(i_fatal+0) [0x34fbd50eeac] -> /usr/lib64/dovecot/lib21_fts_solr_plugin.so(solr_connection_post_more+0x2a4) [0x34fbba81072] -> /usr/lib64/dovecot/lib21_fts_solr_plugin.so(+0x40a5) [0x34fbba7d0a5] -> /usr/lib64/dovecot/lib20_fts_plugin.so(fts_build_mail+0x462) [0x34fbbc8d6dc] -> /usr/lib64/dovecot/lib20_fts_plugin.so(+0xd8c2) [0x34fbbc928c2] -> doveadm(+0x17a30) [0x264ecb7a30] -> doveadm(+0x13a45) [0x264ecb3a45] -> doveadm(+0x14762) [0x264ecb4762] -> doveadm(doveadm_mail_try_run+0x173) [0x264ecb4cfd] -> doveadm(main+0x3e9) [0x264ecbd0d5] -> /lib64/libc.so.6(__libc_start_main+0xfd) [0x34fbd16a48d] -> doveadm(+0x13809) [0x264ecb3809] Aborted
complete java exception: Dec 31, 2012 4:12:58 AM org.apache.solr.core.SolrCore execute INFO: [] webapp=/solr-web path=/update params={} status=500 QTime=118 Dec 31, 2012 4:12:58 AM org.apache.solr.common.SolrException log SEVERE: java.lang.RuntimeException: [was class java.io.CharConversionException] Invalid UTF-8 start byte 0xf8 (at char #483989, byte #532382) at com.ctc.wstx.util.ExceptionUtil.throwRuntimeException(ExceptionUtil.java:18) at com.ctc.wstx.sr.StreamScanner.throwLazyError(StreamScanner.java:731) at com.ctc.wstx.sr.BasicStreamReader.safeFinishToken(BasicStreamReader.java:3657) at com.ctc.wstx.sr.BasicStreamReader.getText(BasicStreamReader.java:809) at org.apache.solr.handler.XMLLoader.readDoc(XMLLoader.java:315) at org.apache.solr.handler.XMLLoader.processUpdate(XMLLoader.java:156) at org.apache.solr.handler.XMLLoader.load(XMLLoader.java:79) at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:58) at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129) at org.apache.solr.core.SolrCore.execute(SolrCore.java:1376) at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:365) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:260) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Unknown Source) at org.apache.catalina.core.ApplicationFilterChain.doFilter(Unknown Source) at org.apache.catalina.core.StandardWrapperValve.invoke(Unknown Source) at org.apache.catalina.core.StandardContextValve.invoke(Unknown Source) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(Unknown Source) at org.apache.catalina.core.StandardHostValve.invoke(Unknown Source) at org.apache.catalina.valves.ErrorReportValve.invoke(Unknown Source) at org.apache.catalina.valves.AccessLogValve.invoke(Unknown Source) at org.apache.catalina.core.StandardEngineValve.invoke(Unknown Source) at org.apache.catalina.connector.CoyoteAdapter.service(Unknown Source) at org.apache.coyote.http11.AbstractHttp11Processor.process(Unknown Source) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(Unknown Source) at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(Unknown Source) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:679) Caused by: java.io.CharConversionException: Invalid UTF-8 start byte 0xf8 (at char #483989, byte #532382) at com.ctc.wstx.io.UTF8Reader.reportInvalidInitial(UTF8Reader.java:302) at com.ctc.wstx.io.UTF8Reader.read(UTF8Reader.java:188) at com.ctc.wstx.io.ReaderSource.readInto(ReaderSource.java:84) at com.ctc.wstx.io.BranchingReaderSource.readInto(BranchingReaderSource.java:57) at com.ctc.wstx.sr.StreamScanner.loadMore(StreamScanner.java:992) at com.ctc.wstx.sr.BasicStreamReader.readTextSecondary(BasicStreamReader.java:4628) at com.ctc.wstx.sr.BasicStreamReader.readCoalescedText(BasicStreamReader.java:4126) at com.ctc.wstx.sr.BasicStreamReader.finishToken(BasicStreamReader.java:3701) at com.ctc.wstx.sr.BasicStreamReader.safeFinishToken(BasicStreamReader.java:3649) ... 25 more
TIA -Marc
[*] sys4 AG
http://sys4.de, +49 (89) 30 90 46 64 Franziskanerstraße 15, 81669 München
Sitz der Gesellschaft: München, Amtsgericht München: HRB 199263 Vorstand: Patrick Ben Koetter, Axel von der Ohe, Marc Schiffbauer Aufsichtsratsvorsitzender: Joerg Heidrich
solr setup: Java: icedtea 6.1.11.5 Solr: 3.6.2 running in tomcat 7.0.32
I am running solr on Tomcat 6.
complete dovecot log: doveadm(my@user): Error: fts_solr: Invalid XML input at 85:198: mismatched tag (near: <html><head><title>Apache Tomcat/7.0.32-gentoo - Error report</title><style><!--H1 {font-family:Tahoma,Arial,sans-serif;color:wh)
Looks strange :) Did you investigate this XML thing?
complete java exception: Dec 31, 2012 4:12:58 AM org.apache.solr.core.SolrCore execute INFO: [] webapp=/solr-web path=/update params={} status=500 QTime=118
status 500. Internal server error? Do you have entries in Apache error.log?
-- -Christian Rößner
-- [*] sys4 AG Franziskanerstraße 15 Telefon +49 89 3090 4664 81669 München Telefax +49 89 3090 4666
Sitz der Gesellschaft: München, Amtsgericht München: HRB 199263 Vorstand: Patrick Ben Koetter, Axel von der Ohe, Marc Schiffbauer Aufsichtsratsvorsitzender: Joerg Heidrich
Am Mittwoch, 2. Januar 2013, 15:16:45 schrieb Christian Rößner:
solr setup: Java: icedtea 6.1.11.5 Solr: 3.6.2 running in tomcat 7.0.32
I am running solr on Tomcat 6.
complete dovecot log: doveadm(my@user): Error: fts_solr: Invalid XML input at 85:198: mismatched tag (near: <html><head><title>Apache Tomcat/7.0.32-gentoo - Error report</title><style><!--H1 {font-family:Tahoma,Arial,sans-serif;color:wh) Looks strange :) Did you investigate this XML thing?
Well this is just the Tomcat Error-Message that dovecot seems to be trying to interprete as XML-Answer here.
complete java exception: Dec 31, 2012 4:12:58 AM org.apache.solr.core.SolrCore execute INFO: [] webapp=/solr-web path=/update params={} status=500 QTime=118
status 500. Internal server error? Do you have entries in Apache error.log?
My /var/log/tomcat-7/* does not contain any other message.
-- [*] sys4 AG
http://sys4.de, +49 (89) 30 90 46 64 Franziskanerstraße 15, 81669 München
Sitz der Gesellschaft: München, Amtsgericht München: HRB 199263 Vorstand: Patrick Ben Koetter, Axel von der Ohe, Marc Schiffbauer Aufsichtsratsvorsitzender: Joerg Heidrich
Am 02.01.2013 um 17:57 schrieb Marc Schiffbauer <m@sys4.de>:
status 500. Internal server error? Do you have entries in Apache error.log?
My /var/log/tomcat-7/* does not contain any other message.
sorry, my fault. Dovecot connects directly to Tomcat, yes.
I have tried to reproduce this here on Ubuntu 10.04 with indexing all users INBOXes, but that succeeds. So currently I have no further idea.
-Christian Rößner
-- [*] sys4 AG
http://sys4.de, +49 (89) 30 90 46 64 Franziskanerstraße 15, 81669 München
Sitz der Gesellschaft: München, Amtsgericht München: HRB 199263 Vorstand: Patrick Ben Koetter, Axel von der Ohe, Marc Schiffbauer Aufsichtsratsvorsitzender: Joerg Heidrich
On 31.12.2012, at 5.23, Marc Schiffbauer <m@sys4.de> wrote:
I am having a problem indexing one of my mailboxes using the solr fts backend in dovecot 2.1.12 For many mailboxes it works just fine, but on one mailbox I currently always get a panic. .. SEVERE: java.lang.RuntimeException: [was class java.io.CharConversionException] Invalid UTF-8 start byte 0xf8 (at char #483989, byte #532382)
Looks like the same issue I was trying to debug with the other guy also, but I couldn't figure out how that happens. Dovecot shouldn't be sending such data to Solr. Can you record the TCP traffic between Dovecot and Solr when this happens, and send it to me?
Am Freitag, 4. Januar 2013, 05:21:37 schrieb Timo Sirainen:
On 31.12.2012, at 5.23, Marc Schiffbauer <m@sys4.de> wrote:
I am having a problem indexing one of my mailboxes using the solr fts backend in dovecot 2.1.12 For many mailboxes it works just fine, but on one mailbox I currently always get a panic. ..
SEVERE: java.lang.RuntimeException: [was class java.io.CharConversionException] Invalid UTF-8 start byte 0xf8 (at char #483989, byte #532382) Looks like the same issue I was trying to debug with the other guy also, but I couldn't figure out how that happens. Dovecot shouldn't be sending such data to Solr. Can you record the TCP traffic between Dovecot and Solr when this happens, and send it to me?
I have now captured the network traffic and I think the culprit is a mail sent by the logcheck service via the local nullmailer MTA. The message contains a postgresql log where a big amount of garbage has been recorded that has been tried to execute in postgres which it denied to do.
This looks a bit like that:
<doc><field name="uid">68058</field><field name="box">a8ca17d0b2a8e8540c196f21010a26e1</field><field name="user">xxxx@xxxxxxxxxxx.net</field><field name="id">68058/a8ca17d0b2a8e8540c196f21010a26e1/xxxx@xxxxxxxxxxx.net</field><field name="body"> Security Violations
Jan 12 23:16:00 pluto postgres[18413]: [11-577] ? 5l#027�g�x�v#017�~�]�j#006�#037�Í<9b>�!=l#037�My�i�Z�v�#&K#024t#002N�?�<�xM�ip�Y9×<89>f�#015� Jan 12 23:23:06 pluto postgres[2573]: [3-1] LOG: received fast shutdown request Jan 12 23:24:01 pluto postgres[21886]: [3-1] LOG: received fast shutdown request Jan 12 23:25:32 pluto postgres[22397]: [3-1] LOG: received fast shutdown request Jan 12 23:28:25 pluto postgres[23774]: [3-1] LOG: received smart shutdown request Jan 12 23:47:13 pluto postgres[32759]: [3-1] LOG: received fast shutdown request Jan 12 23:47:39 pluto postgres[521]: [3-1] LOG: received fast shutdown request Jan 12 23:47:48 pluto postgres[574]: [3-1] LOG: received fast shutdown request Jan 12 23:52:26 pluto postgres[644]: [3-1] LOG: received fast shutdown request Jan 12 23:16:00 pluto postgres[18413]: [11-577] ?
5l#027�g�x�v#017�~�]�j#006�#037�Í<9b>�!=l#037�My�i�Z�v�#&K#024t#002N�?�<�xM�ip�Y9×<89>f�#015�
Jan 12 23:23:06 pluto postgres[2573]: [3-1] LOG: received fast shutdown
request
Jan 12 23:24:01 pluto postgres[21886]: [3-1] LOG: received fast shutdown
request
Jan 12 23:25:32 pluto postgres[22397]: [3-1] LOG: received fast shutdown
request
Jan 12 23:28:25 pluto postgres[23774]: [3-1] LOG: received smart shutdown
request
Jan 12 23:47:13 pluto postgres[32759]: [3-1] LOG: received fast shutdown
request
Jan 12 23:47:39 pluto postgres[521]: [3-1] LOG: received fast shutdown
request
Jan 12 23:47:48 pluto postgres[574]: [3-1] LOG: received fast shutdown
request
Jan 12 23:52:26 pluto postgres[644]: [3-1] LOG: received fast shutdown
request
Unusual System Events
Jan 12 23:15:37 pluto postgres[18392]: [3-1] FATAL: database "drupal" does
not exist
Jan 12 23:16:00 pluto postgres[18413]: [3-1] ERROR: syntax error at or near
"#037" at character 1
Jan 12 23:16:00 pluto postgres[18413]: [3-2] STATEMENT:
Jan 12 23:16:00 pluto postgres[18413]: [3-3]
#037�#010�"�6�5mVIp�#027�N�Û<9b>_?�u�o6y�8�#023�go#177�#0370�sqÔ<94>�_�վ�7�Å<8b>#177#177�wڿ�6z�R8#004�#003#024�w�A\�+-.#023�Î<9e>�d�,M�k�?J�-
Jan 12 23:16:00 pluto postgres[18413]: [3-4] �b�5/#033H#036�^h�|
ݿ�_#177�r�bf�w�'�#0374�?�?L�ӻ�~�A�O�#007�5�D�#177�_�|
�|�#007ت#025�i^60
[...]
As the traffic contains other sensitive information I will sent you the complete files offlist, I hope thats ok for you.
TIA -Marc
[*] sys4 AG
http://sys4.de, +49 (89) 30 90 46 64 Franziskanerstraße 15, 81669 München
Sitz der Gesellschaft: München, Amtsgericht München: HRB 199263 Vorstand: Patrick Ben Koetter, Axel von der Ohe, Marc Schiffbauer Aufsichtsratsvorsitzender: Joerg Heidrich
On Mon, 2012-12-31 at 04:23 +0100, Marc Schiffbauer wrote:
IMO relevant logs line parts: java.io.CharConversionException: Invalid UTF-8 start byte 0xf8 (at char #483989, byte #532382)
Am Freitag, 4. Januar 2013, 23:26:13 schrieb Timo Sirainen:
On Mon, 2012-12-31 at 04:23 +0100, Marc Schiffbauer wrote:
IMO relevant logs line parts: java.io.CharConversionException: Invalid UTF-8 start byte 0xf8 (at char #483989, byte #532382) Fixed: http://hg.dovecot.org/dovecot-2.1/rev/7be4709aab5e
Many thanks Timo, I applied the patch against my 2.1.12 installation, seems to works like a charm now!
-Marc
[*] sys4 AG
http://sys4.de, +49 (89) 30 90 46 64 Franziskanerstraße 15, 81669 München
Sitz der Gesellschaft: München, Amtsgericht München: HRB 199263 Vorstand: Patrick Ben Koetter, Axel von der Ohe, Marc Schiffbauer Aufsichtsratsvorsitzender: Joerg Heidrich
Quote: Timo Sirainen <tss@iki.fi>：
On Mon, 2012-12-31 at 04:23 +0100, Marc Schiffbauer wrote:
IMO relevant logs line parts: java.io.CharConversionException: Invalid UTF-8 start byte 0xf8 (at
char #483989, byte #532382)
I have another problem with same error. dovecot-2.1.12 + patch (01550514f189,172295f5a78b,339e654f371e,7be4709aab5e) Solr-3.6.0 + Jetty-6.1
# doveadm index -u hiromi badmbox
doveadm(hiromi): Error: fts_solr: Indexing failed: 400 Invalid UTF-8
start byte 0xf8 (at char #1681, byte #-1)
SEVERE: org.apache.solr.common.SolrException: Invalid UTF-8 start byte
0xf8 (at char #1681, byte #-1)
at org.apache.solr.handler.XMLLoader.load(XMLLoader.java:81)
at
org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:58)
...
Caused by: java.io.CharConversionException: Invalid UTF-8 start byte
0xf8 (at char #1681, byte #-1)
at
com.ctc.wstx.io.UTF8Reader.reportInvalidInitial(UTF8Reader.java:302)
at com.ctc.wstx.io.UTF8Reader.read(UTF8Reader.java:188)
...
Timo, I will send captured data by personal mail.
Hiromi KIMURA http://www.tac.tsukuba.ac.jp/~hiromi/ PGP Fingerprint16 = 2A 27 2E 46 9E 75 4E 3D E3 FD 5A DC 2A AA 3A 2E
This bug was fixed ! http://hg.dovecot.org/dovecot-2.1/rev/fa9387588430
Thanks Timo.
Quote: Hiromi Kimura <hiromi@tac.tsukuba.ac.jp>：
Quote: Timo Sirainen <tss@iki.fi>：
On Mon, 2012-12-31 at 04:23 +0100, Marc Schiffbauer wrote:
IMO relevant logs line parts: java.io.CharConversionException: Invalid UTF-8 start byte 0xf8 (at
char #483989, byte #532382)I have another problem with same error. dovecot-2.1.12 + patch (01550514f189,172295f5a78b,339e654f371e,7be4709aab5e) Solr-3.6.0 + Jetty-6.1
# doveadm index -u hiromi badmbox doveadm(hiromi): Error: fts_solr: Indexing failed: 400 Invalid UTF-8
start byte 0xf8 (at char #1681, byte #-1)SEVERE: org.apache.solr.common.SolrException: Invalid UTF-8 start
byte 0xf8 (at char #1681, byte #-1) at org.apache.solr.handler.XMLLoader.load(XMLLoader.java:81) at
org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:58) ... Caused by: java.io.CharConversionException: Invalid UTF-8 start byte
0xf8 (at char #1681, byte #-1) at
com.ctc.wstx.io.UTF8Reader.reportInvalidInitial(UTF8Reader.java:302) at com.ctc.wstx.io.UTF8Reader.read(UTF8Reader.java:188) ...Timo, I will send captured data by personal mail.
Hiromi KIMURA http://www.tac.tsukuba.ac.jp/~hiromi/ PGP Fingerprint16 = 2A 27 2E 46 9E 75 4E 3D E3 FD 5A DC 2A AA 3A 2E
-=-=-=-=- Hiromi KIMURA http://www.tac.tsukuba.ac.jp/~hiromi/ PGP Fingerprint16 = 2A 27 2E 46 9E 75 4E 3D E3 FD 5A DC 2A AA 3A 2E
participants (4)
-
Christian Rößner
-
Hiromi Kimura
-
Marc Schiffbauer
-
Timo Sirainen