Topic: ClamAV fails and server freezes after several hours
==== Required information ====
- iRedMail version (check /etc/iredmail-release): 0.9.7
- Linux/BSD distribution name and version: debian 9.1
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): mysql
- Web server (Apache or Nginx): nginx
- Manage mail accounts with iRedAdmin-Pro? no
- [IMPORTANT] Related original log or error message is required if you're experiencing an issue.
====
Hi,
I just migrated my mailserver from debian 8 to a new vm which is running, therefore i followed the tutorial by iredmail.
http://www.iredmail.org/docs/migrate.to … -databases
As the instructions for amavis migration are "Export those database on old server, then import them on new server." I dont think i made a mistake there.
Around one day after server restart clamav fails and throws this error messages:
Jul 29 11:34:53 mail amavis[1373]: (01373-12) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 11:34:53 mail amavis[1373]: (01373-12) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 11:35:14 mail amavis[1373]: (01373-12) Passed CLEAN {RelayedInbound}, [167.89.73.14]:29466 [157.56.28.125] <bounces+22147-7fd5-mail=example.org@wmail2.devolutions.net> -> <mail@example.org>, Queue-ID: 5F41641000, Message-ID: <-qkfJpCcTb6A6Ym2p6g3yQ@ismtpd0029p1mdw1.sendgrid.net>, mail_id: u3yOCUCZWCp3, Hits: 1.607, size: 10782, queued_as: 4ECAF41001, dkim_sd=s1:devolutions.net, 309459 ms, Tests: [DKIM_SIGNED=0.1,DKIM_VALID=-0.1,DKIM_VALID_AU=-0.1,HTML_FONT_LOW_CONTRAST=0.001,HTML_IMAGE_RATIO_04=0.61,HTML_MESSAGE=0.001,MIME_HTML_ONLY=1.105,RCVD_IN_MSPIKE_H3=-0.01,RCVD_IN_MSPIKE_WL=-0.01,SPF_PASS=-0.001,T_REMOTE_IMAGE=0.01,URIBL_BLOCKED=0.001]
Jul 29 11:35:14 mail postfix/amavis/smtp[15560]: 5F41641000: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10024, delay=311, delays=0.92/0.04/0.02/310, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4ECAF41001)
Jul 29 16:45:37 mail amavis[1374]: (01374-12) NOTICE: reconnecting in response to: err=2006, HY000, DBD::mysql::st execute failed: MySQL server has gone away at (eval 109) line 172.
Jul 29 16:50:25 mail amavis[1374]: (01374-12) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 16:50:25 mail amavis[1374]: (01374-12) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 16:50:42 mail amavis[1374]: (01374-12) Passed CLEAN {RelayedInbound}, [185.84.6.100]:47946 [2a05:a1c0:0:de::2] <forum@dd-wrt.com> -> <mail@example.org>, Queue-ID: 3D17240877, Message-ID: <630f5e47ec33bb80566f3f4645e165ad@www.dd-wrt.com>, mail_id: C37TaRw-vnC8, Hits: -0.1, size: 2149, queued_as: B794740878, dkim_sd=mikd:dd-wrt.com, 305490 ms, Tests: [DKIM_SIGNED=0.1,DKIM_VALID=-0.1,DKIM_VALID_AU=-0.1,SPF_PASS=-0.001,URIBL_BLOCKED=0.001]
Jul 29 16:50:42 mail postfix/amavis/smtp[19042]: 3D17240877: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10024, delay=306, delays=0.12/0.02/0.02/306, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as B794740878)
Jul 29 18:06:18 mail amavis[1373]: (01373-13) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:06:18 mail amavis[1373]: (01373-13) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 18:06:34 mail amavis[1373]: (01373-13) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:52043 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: 8E4A240878, mail_id: k_Qg39nYBmtU, Hits: -0.86, size: 737, queued_as: 46B7740886, dkim_new=dkim:example.org, 303555 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:06:34 mail postfix/amavis/smtp[19882]: 8E4A240878: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=304, delays=0.22/0.02/0.02/304, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 46B7740886)
Jul 29 18:06:49 mail amavis[1374]: (01374-13) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:06:49 mail amavis[1374]: (01374-13) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 18:07:04 mail amavis[1374]: (01374-13) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:52271 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: 179CF4087B, mail_id: 5mRXS2-icOw4, Hits: -0.86, size: 724, queued_as: 7D8D640887, dkim_new=dkim:example.org, 303250 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:07:04 mail postfix/amavis/smtp[19884]: 179CF4087B: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=304, delays=0.18/0.07/0.04/303, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 7D8D640887)
Jul 29 18:11:22 mail amavis[1373]: (01373-14) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:11:22 mail amavis[1373]: (01373-14) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 18:11:40 mail amavis[1373]: (01373-14) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:53395 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: 2AEC24087C, mail_id: PEDndGyDGtEQ, Hits: -0.86, size: 748, queued_as: 0B3A54088C, dkim_new=dkim:example.org, 305692 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:11:40 mail postfix/amavis/smtp[19882]: 2AEC24087C: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=423, delays=0.16/117/0.04/306, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 0B3A54088C)
Jul 29 18:11:52 mail amavis[1374]: (01374-14) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:11:52 mail amavis[1374]: (01374-14) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 18:12:08 mail amavis[1374]: (01374-14) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:53396 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: 799094087D, mail_id: 1O8bNs8c065Z, Hits: -0.86, size: 743, queued_as: BEF954088C, dkim_new=dkim:example.org, 304212 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:12:08 mail postfix/amavis/smtp[19884]: 799094087D: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=451, delays=0.13/147/0.01/304, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as BEF954088C)
Jul 29 18:16:28 mail amavis[1373]: (01373-15) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:16:28 mail amavis[1373]: (01373-15) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 18:16:46 mail amavis[1373]: (01373-15) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:53400 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: DE23640880, mail_id: O9EBJODWbSBM, Hits: -0.86, size: 737, queued_as: 208AD40894, dkim_new=dkim:example.org, 306002 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:16:46 mail postfix/amavis/smtp[19882]: DE23640880: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=728, delays=0.12/422/0.02/306, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 208AD40894)
Jul 29 18:16:56 mail amavis[1374]: (01374-15) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:16:56 mail amavis[1374]: (01374-15) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 18:17:13 mail amavis[1374]: (01374-15) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:53630 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: 47FBE40881, mail_id: BsxgjnE1UxLM, Hits: -0.86, size: 735, queued_as: 5467340894, dkim_new=dkim:example.org, 304538 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:17:13 mail postfix/amavis/smtp[19884]: 47FBE40881: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=725, delays=0.14/420/0.02/305, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 5467340894)
Jul 29 18:21:34 mail amavis[1373]: (01373-16) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:21:34 mail amavis[1373]: (01373-16) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 18:21:51 mail amavis[1373]: (01373-16) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:53639 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: 9BEA240882, mail_id: Xglu9TVwEv23, Hits: -0.86, size: 734, queued_as: 5A53340881, dkim_new=dkim:example.org, 305201 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:21:51 mail postfix/amavis/smtp[19882]: 9BEA240882: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=1003, delays=0.12/697/0.01/305, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 5A53340881)
Jul 29 18:22:01 mail amavis[1374]: (01374-16) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:22:01 mail amavis[1374]: (01374-16) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 18:22:17 mail amavis[1374]: (01374-16) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:53876 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: 14D2240885, mail_id: jvJM2uchBKGp, Hits: -0.86, size: 724, queued_as: D00C940881, dkim_new=dkim:example.org, 304452 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:22:17 mail postfix/amavis/smtp[19884]: 14D2240885: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=999, delays=0.16/694/0.03/304, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as D00C940881)
Jul 29 18:26:39 mail amavis[1373]: (01373-17) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:26:39 mail amavis[1373]: (01373-17) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 18:26:55 mail amavis[1373]: (01373-17) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:54300 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: 0BB4440886, mail_id: iZE9RGX-gBXG, Hits: -0.86, size: 737, queued_as: 0F37240881, dkim_new=dkim:example.org, 303666 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:26:55 mail postfix/amavis/smtp[19882]: 0BB4440886: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=1210, delays=0.16/906/0.01/304, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 0F37240881)
Jul 29 18:27:06 mail amavis[1374]: (01374-17) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:27:06 mail amavis[1374]: (01374-17) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 18:27:20 mail amavis[1374]: (01374-17) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:54563 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: D98E940887, mail_id: f2FdoSGQo5hl, Hits: -0.86, size: 748, queued_as: 6F3FE40881, dkim_new=dkim:example.org, 302555 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:27:20 mail postfix/amavis/smtp[19884]: D98E940887: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=1200, delays=0.13/897/0.01/303, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 6F3FE40881)
Jul 29 18:31:43 mail amavis[1373]: (01373-18) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:31:43 mail amavis[1373]: (01373-18) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 18:31:58 mail amavis[1373]: (01373-18) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:54564 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: 450AB4088A, mail_id: B402jZw2yq8f, Hits: -0.86, size: 743, queued_as: E533A40881, dkim_new=dkim:example.org, 303844 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:31:58 mail postfix/amavis/smtp[19882]: 450AB4088A: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=1478, delays=0.12/1174/0.01/304, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as E533A40881)
Jul 29 18:32:08 mail amavis[1374]: (01374-18) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:32:08 mail amavis[1374]: (01374-18) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 18:32:23 mail amavis[1374]: (01374-18) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:55170 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: BEFE94088B, mail_id: jI1J9EjraJlx, Hits: -0.86, size: 699, queued_as: 4741140881, dkim_new=dkim:example.org, 302790 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:32:23 mail postfix/amavis/smtp[19884]: BEFE94088B: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=1412, delays=0.14/1109/0.01/303, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4741140881)
Jul 29 18:36:47 mail amavis[1373]: (01373-19) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:36:47 mail amavis[1373]: (01373-19) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 18:37:02 mail amavis[1373]: (01373-19) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:57080 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: C0B954088C, mail_id: 2QCRyE4DpUxW, Hits: -0.86, size: 735, queued_as: 2022240881, dkim_new=dkim:example.org, 303161 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:37:02 mail postfix/amavis/smtp[19882]: C0B954088C: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=1414, delays=0.16/1111/0.01/303, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 2022240881)
Jul 29 18:37:11 mail amavis[1374]: (01374-19) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:37:11 mail amavis[1374]: (01374-19) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 18:37:26 mail amavis[1374]: (01374-19) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:57085 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: 232464088F, mail_id: R5MhnKP0FkAv, Hits: -0.86, size: 724, queued_as: ECC5640881, dkim_new=dkim:example.org, 303633 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:37:27 mail postfix/amavis/smtp[19884]: 232464088F: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=1439, delays=0.13/1135/0.02/304, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as ECC5640881)
Jul 29 18:41:50 mail amavis[1373]: (01373-20) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:41:50 mail amavis[1373]: (01373-20) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 18:42:05 mail amavis[1373]: (01373-20) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:57086 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: 7365240890, mail_id: t8C6WRwh8K1q, Hits: -0.86, size: 734, queued_as: 5669340881, dkim_new=dkim:example.org, 303178 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:42:05 mail postfix/amavis/smtp[19882]: 7365240890: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=1717, delays=0.13/1414/0.01/303, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 5669340881)
Jul 29 18:42:15 mail amavis[1374]: (01374-20) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 18:42:15 mail amavis[1374]: (01374-20) (!)WARN: all primary virus scanners failed, considering backups
In this time I still recieve Mails, but then the log changes to this (still recieving mails)
Jul 29 18:42:30 mail amavis[1374]: (01374-20) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [*ip*]:57324 [*ip*] <status@example.org> -> <mail@example.org>, Queue-ID: D424740891, mail_id: 4EjJQhSLspf0, Hits: -0.86, size: 686, queued_as: 79C5940881, dkim_new=dkim:example.org, 303512 ms, Tests: [ALL_TRUSTED=-1,MISSING_MID=0.14]
Jul 29 18:42:30 mail postfix/amavis/smtp[19884]: D424740891: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10026, delay=1712, delays=0.13/1408/0.01/304, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 79C5940881)
Jul 29 19:15:26 mail postfix/amavis/smtp[20843]: A663040881: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.74, delays=0.49/0.03/0.04/0.17, dsn=4.4.2, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while sending end of data -- message may be sent more than once)
Jul 29 19:29:12 mail amavis[20473]: (20473-01) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 19:29:12 mail amavis[20473]: (20473-01) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 19:29:28 mail postfix/amavis/smtp[20939]: A663040881: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10024, delay=844, delays=539/0.04/0.02/304, dsn=4.4.2, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while sending end of data -- message may be sent more than once)
Jul 29 19:49:13 mail amavis[20845]: (20845-01) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 19:49:13 mail amavis[20845]: (20845-01) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 19:49:29 mail postfix/amavis/smtp[21175]: A663040881: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10024, delay=2044, delays=1740/0.07/0.03/304, dsn=4.4.2, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while sending end of data -- message may be sent more than once)
Jul 29 20:29:15 mail amavis[20987]: (20987-01) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 20:29:15 mail amavis[20987]: (20987-01) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 20:44:27 mail postfix/amavis/smtp[21600]: A663040881: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10024, delay=5342, delays=4141/0.09/0.02/1200, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jul 29 21:59:17 mail amavis[21224]: (21224-01) (!)ClamAV-clamd av-scanner FAILED: run_av error: ask_daemon_internal: Exceeded allowed time at (eval 114) line 611.\n
Jul 29 21:59:17 mail amavis[21224]: (21224-01) (!)WARN: all primary virus scanners failed, considering backups
Jul 29 21:59:33 mail postfix/amavis/smtp[22578]: A663040881: to=<mail@example.org>, relay=127.0.0.1[127.0.0.1]:10024, delay=9848, delays=9543/0.04/0.03/304, dsn=4.4.2, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while sending end of data -- message may be sent more than once)
The last message logged in mail.log is this
Jul 29 23:09:29 mail postfix/qmgr[1313]: A663040881: from=<bounce-md_30850198.597cc2a5.v1-9cd96d09810f4ab1b44b0177d1db810b@mandrillapp.com>, size=3635, nrcpt=1 (queue active)
which does not look bad, but after this the log ends (no clamav message or whatsoever)
In my monitoring i can see that cpu usage goes very high (up to 10!, the vm got 2 cores..)
As I saw that i wanted to connect via ssh to my server but it was already too late, server froze.
Heres the syslog:
Jul 29 23:10:01 mail CRON[23429]: (sogo) CMD (/usr/sbin/sogo-tool expire-sessions 30 >/dev/null 2>&1; /usr/sbin/sogo-ealarms-notify >/dev/null 2>&1)
Jul 29 23:11:01 mail CRON[23438]: (sogo) CMD (/usr/sbin/sogo-tool expire-sessions 30 >/dev/null 2>&1; /usr/sbin/sogo-ealarms-notify >/dev/null 2>&1)
Jul 29 23:12:01 mail CRON[23447]: (sogo) CMD (/usr/sbin/sogo-tool expire-sessions 30 >/dev/null 2>&1; /usr/sbin/sogo-ealarms-notify >/dev/null 2>&1)
Jul 29 23:13:01 mail CRON[23456]: (sogo) CMD (/usr/sbin/sogo-tool expire-sessions 30 >/dev/null 2>&1; /usr/sbin/sogo-ealarms-notify >/dev/null 2>&1)
Jul 29 23:14:01 mail CRON[23464]: (sogo) CMD (/usr/sbin/sogo-tool expire-sessions 30 >/dev/null 2>&1; /usr/sbin/sogo-ealarms-notify >/dev/null 2>&1)
Jul 29 23:14:08 mail kernel: [117315.635752] sshd[708]: segfault at 26f6001 ip 00007fe3ffb043db sp 00007ffc2a3e1be8 error 4 in libc-2.24.so[7fe3ffa23000+195000]
Jul 29 23:14:08 mail systemd[1]: ssh.service: Main process exited, code=killed, status=11/SEGV
Jul 29 23:14:08 mail systemd[1]: ssh.service: Unit entered failed state.
Jul 29 23:14:08 mail systemd[1]: ssh.service: Failed with result 'signal'.
Jul 29 23:14:08 mail systemd[1]: ssh.service: Service hold-off time over, scheduling restart.
Jul 29 23:14:08 mail systemd[1]: Stopped OpenBSD Secure Shell server.
Jul 29 23:14:08 mail systemd[1]: Starting OpenBSD Secure Shell server...
Jul 29 23:14:08 mail kernel: [117316.156289] BUG: unable to handle kernel paging request at 000000000288f000
Jul 29 23:14:08 mail kernel: [117316.157568] IP: [<ffffffffb8d350b9>] copy_page_regs+0x49/0xe0
Jul 29 23:14:08 mail kernel: [117316.158368] PGD 0
Jul 29 23:14:08 mail kernel: [117316.158387]
Jul 29 23:14:08 mail kernel: [117316.158748] Oops: 0000 [#4] SMP
Jul 29 23:14:08 mail kernel: [117316.158748] Modules linked in: xt_multiport iptable_filter ppdev bochs_drm ttm parport_pc evdev drm_kms_helper joydev pcspkr sg parport virtio_console shpchp serio_raw virtio_balloon drm acpi_$
Jul 29 23:14:08 mail kernel: [117316.158748] CPU: 1 PID: 23472 Comm: sshd Tainted: G D 4.9.0-3-amd64 #1 Debian 4.9.30-2+deb9u2
Jul 29 23:14:08 mail kernel: [117316.158748] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.10.2-0-g5f4c7b1-prebuilt.qemu-project.org 04/01/2014
Jul 29 23:14:08 mail kernel: [117316.158748] task: ffff9768bc266f40 task.stack: ffffbba7c6e74000
Jul 29 23:14:08 mail kernel: [117316.158748] RIP: 0010:[<ffffffffb8d350b9>] [<ffffffffb8d350b9>] copy_page_regs+0x49/0xe0
Jul 29 23:14:08 mail kernel: [117316.158748] RSP: 0000:ffffbba7c6e77d58 EFLAGS: 00010206
Jul 29 23:14:08 mail kernel: [117316.158748] RAX: 0000000000000000 RBX: 0000000000000049 RCX: 000000000000003a
Jul 29 23:14:08 mail kernel: [117316.158748] RDX: 0000000000000000 RSI: ffff9768a8088000 RDI: ffff9768b27a5000
Jul 29 23:14:08 mail kernel: [117316.158748] RBP: fffff99081c9e940 R08: 0000000000000000 R09: 0000000000000000
Jul 29 23:14:08 mail kernel: [117316.158748] R10: 0000000000000000 R11: 0000000000000000 R12: 00000000001755c0
Jul 29 23:14:08 mail kernel: [117316.158748] R13: ffff9768b9738320 R14: ffff9768b9718400 R15: 00007f5ea1843038
Jul 29 23:14:08 mail kernel: [117316.158748] FS: 00007f5ea2247d40(0000) GS:ffff9768bfd00000(0000) knlGS:0000000000000000
Jul 29 23:14:08 mail kernel: [117316.158748] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jul 29 23:14:08 mail kernel: [117316.158748] CR2: 000000000288f000 CR3: 000000007a360000 CR4: 00000000000006e0
Jul 29 23:14:08 mail kernel: [117316.158748] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jul 29 23:14:08 mail kernel: [117316.158748] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Jul 29 23:14:08 mail kernel: [117316.158748] Stack:
Jul 29 23:14:08 mail kernel: [117316.158748] fffff99081a02200 ffffbba7c6e77e80 ffffffffb8baf0d1 8000000068088025
Jul 29 23:14:08 mail kernel: [117316.158748] ffff9768bc266f40 00007f5ea1842000 ffff9768b8ce2c00 1b9970a463589267
Jul 29 23:14:08 mail kernel: [117316.158748] fffff99081a02200 ffffbba7c6e77e80 8000000068088025 ffff9768b9738320
Jul 29 23:14:08 mail kernel: [117316.158748] Call Trace:
Jul 29 23:14:08 mail kernel: [117316.158748] [<ffffffffb8baf0d1>] ? wp_page_copy+0xf1/0x700
Jul 29 23:14:08 mail kernel: [117316.158748] [<ffffffffb8bb0361>] ? do_wp_page+0x161/0x7d0
Jul 29 23:14:08 mail kernel: [117316.158748] [<ffffffffb8bb252f>] ? alloc_set_pte+0x4bf/0x5e0
Jul 29 23:14:08 mail kernel: [117316.158748] [<ffffffffb8bb3170>] ? handle_mm_fault+0x8d0/0x1350
Jul 29 23:14:08 mail kernel: [117316.158748] [<ffffffffb8bbce4b>] ? mprotect_fixup+0x14b/0x280
Jul 29 23:14:08 mail kernel: [117316.158748] [<ffffffffb8a5fd84>] ? __do_page_fault+0x2a4/0x510
Jul 29 23:14:08 mail kernel: [117316.158748] [<ffffffffb9007688>] ? async_page_fault+0x28/0x30
----
Spider Email Archiver: On-Premises, lightweight email archiving software developed by iRedMail team. Supports Amazon S3 compatible storage and custom branding.