Re: [Exim] exim 4.12 strange logging behavior when logging t…

Top Page
Delete this message
Reply to this message
Author: Marc Haber
Date:  
To: exim-users
Subject: Re: [Exim] exim 4.12 strange logging behavior when logging to syslog
On Thu, 6 Mar 2003 09:27:45 +0000 (GMT), Philip Hazel
<ph10@???> wrote:
>On Wed, 5 Mar 2003, Marc Haber wrote:
>> exim behaves strange when I try to modify the logging behavior. For
>> example, when I set log_file_path = :syslog (logging to default path,
>> and syslog), the majority of log messages is written to syslog only.
>
>What exactly do you mean by "majority"? Does that mean you get some
>messages to the file? That would be really weird. I have made a note to
>check this out.


This is my syslog:
<changed log_file_path to :syslog>
|Mar  6 20:32:50 torres sudo:       mh : TTY=pts/6 ; PWD=/etc/exim4/conf.d/main ; USER=root ; COMMAND=/etc/init.d/exim4 reload
|Mar  6 20:33:05 torres exim[20585]: pid 20585: SIGHUP received: re-exec daemon
|Mar  6 20:33:06 torres exim[20585]: IPv6 socket creation failed: Address family not supported by protocol
|Mar  6 20:33:06 torres exim[20585]: Failed to create IPv6 socket for wildcard listening (Address family not supported by protocol): falling back to IPv4
|Mar  6 20:33:06 torres exim[20585]: exim 4.12 daemon started: pid=20585, -q30m, listening for SMTP on port 25 (IPv4)
|Mar  6 20:33:06 torres exim[9620]: Start queue run: pid=9620
|Mar  6 20:33:06 torres exim[9620]: End queue run: pid=9620
|Mar  6 20:33:35 torres exim[9621]: SMTP connection from murphy.debian.org [65.125.64.134]:36079 (TCP/IP connection count = 1)
|Mar  6 20:33:35 torres exim[9621]: SMTP protocol error in "RCPT TO:<mh+debian-user-german@???>" H=murphy.debian.org [65.125.64.134]:36079 sender not yet given
|Mar  6 20:33:35 torres exim[9621]: SMTP protocol error in "DATA" H=murphy.debian.org [65.125.64.134]:36079 MAIL command must precede DATA
|Mar  6 20:33:35 torres exim[9621]: SMTP connection from murphy.debian.org [65.125.64.134]:36079 closed by QUIT
|Mar  6 20:33:48 torres exim[9622]: SMTP connection from dsl081-251-250.sfo1.dsl.speakeasy.net [64.81.251.250]:3836 (TCP/IP connection count = 1)
|Mar  6 20:33:48 torres exim[9622]: SMTP protocol error in "RCPT TO:<list-managers.greatcircle.com@???>" H=dsl081-251-250.sfo1.dsl.speakeasy.net (mycroft.greatcircle.com) [64.81.251.250]:3836 sender not yet given
|Mar  6 20:33:48 torres exim[9622]: SMTP protocol error in "DATA" H=dsl081-251-250.sfo1.dsl.speakeasy.net (mycroft.greatcircle.com) [64.81.251.250]:3836 MAIL command must precede DATA
|Mar  6 20:33:49 torres exim[9622]: SMTP connection from dsl081-251-250.sfo1.dsl.speakeasy.net (mycroft.greatcircle.com) [64.81.251.250]:3836 closed by QUIT
|Mar  6 20:33:49 torres exim[9624]: SMTP connection from vger.kernel.org [209.116.70.75]:33486 (TCP/IP connection count = 1)
|Mar  6 20:33:50 torres exim[9624]: SMTP protocol error in "RCPT To:<mh+linux-kernel@???>" H=vger.kernel.org [209.116.70.75]:33486 sender not yet given
|Mar  6 20:33:50 torres exim[9624]: SMTP protocol error in "DATA" H=vger.kernel.org [209.116.70.75]:33486 MAIL command must precede DATA
|Mar  6 20:33:50 torres exim[9624]: SMTP connection from vger.kernel.org [209.116.70.75]:33486 lost
|Mar  6 20:33:54 torres exim[9625]: SMTP connection from q.bofh.de [212.126.220.202]:4155 (TCP/IP connection count = 1)
|Mar  6 20:33:54 torres exim[9625]: SMTP protocol error in "RCPT TO:<mh+linux-kernel@???>" H=q.bofh.de [212.126.220.202]:4155 sender not yet given
|Mar  6 20:33:54 torres exim[9625]: SMTP protocol error in "DATA" H=q.bofh.de [212.126.220.202]:4155 MAIL command must precede DATA
|Mar  6 20:33:54 torres exim[9625]: SMTP connection from q.bofh.de [212.126.220.202]:4155 closed by QUIT
|Mar  6 20:34:02 torres ippl: ssh connection attempt from unknown@212.126.200.2 (212.126.200.2:2068->212.126.206.6:22)
|Mar  6 20:34:17 torres exim[9628]: SMTP connection from murphy.debian.org [65.125.64.134]:37712 (TCP/IP connection count = 1)
|Mar  6 20:34:18 torres exim[9628]: SMTP protocol error in "RCPT TO:<debian-user.lists.debian.org@???>" H=murphy.debian.org [65.125.64.134]:37712 sender not yet given
|Mar  6 20:34:18 torres exim[9628]: SMTP protocol error in "DATA" H=murphy.debian.org [65.125.64.134]:37712 MAIL command must precede DATA
|Mar  6 20:34:18 torres exim[9628]: SMTP connection from murphy.debian.org [65.125.64.134]:37712 closed by QUIT


Oops, exim not accepting any more messages? Change log_file_path back
to "syslog : /var/log/exim4/%slog"

|Mar  6 20:34:26 torres sudo:       mh : TTY=pts/6 ; PWD=/etc/exim4/conf.d/main ; USER=root ; COMMAND=/usr/bin/jed 03_local_logging
|Mar  6 20:34:33 torres sudo:       mh : TTY=pts/6 ; PWD=/etc/exim4/conf.d/main ; USER=root ; COMMAND=/etc/init.d/exim4 reload
|Mar  6 20:34:49 torres exim[20585]: pid 20585: SIGHUP received: re-exec daemon
|Mar  6 20:34:49 torres exim[20585]: IPv6 socket creation failed: Address family not supported by protocol
|Mar  6 20:34:49 torres exim[20585]: Failed to create IPv6 socket for wildcard listening (Address family not supported by protocol): falling back to IPv4
|Mar  6 20:34:49 torres exim[20585]: exim 4.12 daemon started: pid=20585, -q30m, listening for SMTP on port 25 (IPv4)
|Mar  6 20:34:49 torres exim[9770]: Start queue run: pid=9770
|Mar  6 20:34:49 torres exim[9770]: End queue run: pid=9770
|Mar  6 20:35:35 torres exim[9771]: SMTP connection from exim-colo-01.whoc.theplanet.co.uk [195.92.249.251]:45029 (TCP/IP connection count = 1)
|Mar  6 20:35:38 torres exim[9772]: SMTP connection from vger.kernel.org [209.116.70.75]:34995 (TCP/IP connection count = 2)
|Mar  6 20:35:40 torres exim[9771]: 18r19X-0002Xb-00 <= exim-users-admin@??? H=exim-colo-01.whoc.theplanet.co.uk [195.92.249.251]:45029 I=[212.126.206.6]:25 U=[lTvqjPi7XoWyObUuDIMaw3bGhmQNiP2D] P=esmtp S=4212 id=E18r13E-0002QC-00@??? from <exim-users-admin@???> for mh+exim-users@???
|Mar  6 20:35:44 torres exim[9776]: SMTP connection from exim-colo-01.whoc.theplanet.co.uk [195.92.249.251]:45072 (TCP/IP connection count = 3)
|Mar  6 20:35:44 torres exim[9772]: 18r19X-0002Xc-00 <= linux-kernel-owner+mh=2Blinux-kernel=40zugschlus.de@??? H=vger.kernel.org [209.116.70.75]:34995 I=[212.126.206.6]:25 P=esmtp S=3634 id=b487l2$1tn$1@??? from <linux-kernel-owner+mh=2Blinux-kernel=40zugschlus.de@???> for mh+linux-kernel@???
|Mar  6 20:35:47 torres exim[9771]: SMTP connection from exim-colo-01.whoc.theplanet.co.uk [195.92.249.251]:45029 closed by QUIT
|Mar  6 20:35:47 torres exim[9772]: 18r19d-0002Xc-00 <= linux-kernel-owner+mh=2Blinux-kernel=40zugschlus.de@??? H=vger.kernel.org [209.116.70.75]:34995 I=[212.126.206.6]:25 P=esmtp S=2860 id=20030306193344.GA29166@??? from <linux-kernel-owner+mh=2Blinux-kernel=40zugschlus.de@???> for mh+linux-kernel@???
|Mar  6 20:35:47 torres exim[9776]: 18r19d-0002Xg-00 <= exim-users-admin@??? H=exim-colo-01.whoc.theplanet.co.uk [195.92.249.251]:45072 I=[212.126.206.6]:25 U=[aTuhuSdHlfM7l8Gz4mXlkvc54rhMUAjm] P=esmtp S=2953 id=E18r13w-0002QI-00@??? from <exim-users-admin@???> for mh+exim-users@???
|Mar  6 20:35:47 torres exim[9772]: SMTP connection from vger.kernel.org [209.116.70.75]:34995 closed by QUIT
|Mar  6 20:35:49 torres exim[9781]: 18r19d-0002Xc-00 => /home/mh/.mail/.linux-kernel/ <mh+linux-kernel@???> F=<linux-kernel-owner+mh=2Blinux-kernel=40zugschlus.de@???> R=userforward T=address_maildir S=3131
|Mar  6 20:35:49 torres exim[9781]: 18r19d-0002Xc-00 Completed
|Mar  6 20:35:49 torres exim[9778]: 18r19X-0002Xc-00 => /home/mh/.mail/.linux-kernel/ <mh+linux-kernel@???> F=<linux-kernel-owner+mh=2Blinux-kernel=40zugschlus.de@???> R=userforward T=address_maildir S=3905
|Mar  6 20:35:49 torres exim[9778]: 18r19X-0002Xc-00 Completed
|Mar  6 20:35:50 torres exim[9775]: 18r19X-0002Xb-00 => /home/mh/.mail/.lists/ (mh+lists@???) <mh+exim-users@???> F=<exim-users-admin@???> R=userforward T=address_maildir S=4397


Now, it works again.

Here is the corresponding part of /var/log/exim4/mainlog:
|2003-03-06 20:33:05 pid 20585: SIGHUP received: re-exec daemon
|2003-03-06 20:34:49 IPv6 socket creation failed: Address family not supported by protocol
|2003-03-06 20:34:49 Failed to create IPv6 socket for wildcard listening (Address family not supported by protocol): falling back to IPv4
|2003-03-06 20:34:49 exim 4.12 daemon started: pid=20585, -q30m, listening for SMTP on port 25 (IPv4)
|2003-03-06 20:34:49 Start queue run: pid=9770
|2003-03-06 20:34:49 End queue run: pid=9770
|2003-03-06 20:35:35 SMTP connection from exim-colo-01.whoc.theplanet.co.uk [195.92.249.251]:45029 (TCP/IP connection count = 1)
|2003-03-06 20:35:38 SMTP connection from vger.kernel.org [209.116.70.75]:34995 (TCP/IP connection count = 2)
|2003-03-06 20:35:40 18r19X-0002Xb-00 <= exim-users-admin@??? H=exim-colo-01.whoc.theplanet.co.uk [195.92.249.251]:45029 I=[212.126.206.6]:25 U=[lTvqjPi7XoWyObUuDIMaw3bGhmQNiP2D] P=esmtp S=4212 id=E18r13E-0002QC-00@??? from <exim-users-admin@???> for mh+exim-users@???
|2003-03-06 20:35:44 SMTP connection from exim-colo-01.whoc.theplanet.co.uk [195.92.249.251]:45072 (TCP/IP connection count = 3)
|2003-03-06 20:35:44 18r19X-0002Xc-00 <= linux-kernel-owner+mh=2Blinux-kernel=40zugschlus.de@??? H=vger.kernel.org [209.116.70.75]:34995 I=[212.126.206.6]:25 P=esmtp S=3634 id=b487l2$1tn$1@??? from <linux-kernel-owner+mh=2Blinux-kernel=40zugschlus.de@???> for mh+linux-kernel@???
|2003-03-06 20:35:47 SMTP connection from exim-colo-01.whoc.theplanet.co.uk [195.92.249.251]:45029 closed by QUIT
|2003-03-06 20:35:47 18r19d-0002Xc-00 <= linux-kernel-owner+mh=2Blinux-kernel=40zugschlus.de@??? H=vger.kernel.org [209.116.70.75]:34995 I=[212.126.206.6]:25 P=esmtp S=2860 id=20030306193344.GA29166@??? from <linux-kernel-owner+mh=2Blinux-kernel=40zugschlus.de@???> for mh+linux-kernel@???
|2003-03-06 20:35:47 18r19d-0002Xg-00 <= exim-users-admin@??? H=exim-colo-01.whoc.theplanet.co.uk [195.92.249.251]:45072 I=[212.126.206.6]:25 U=[aTuhuSdHlfM7l8Gz4mXlkvc54rhMUAjm] P=esmtp S=2953 id=E18r13w-0002QI-00@??? from <exim-users-admin@???> for mh+exim-users@???
|2003-03-06 20:35:47 SMTP connection from vger.kernel.org [209.116.70.75]:34995 closed by QUIT
|2003-03-06 20:35:49 18r19d-0002Xc-00 => /home/mh/.mail/.linux-kernel/ <mh+linux-kernel@???> F=<linux-kernel-owner+mh=2Blinux-kernel=40zugschlus.de@???> R=userforward T=address_maildir S=3131
|2003-03-06 20:35:49 18r19d-0002Xc-00 Completed
|2003-03-06 20:35:49 18r19X-0002Xc-00 => /home/mh/.mail/.linux-kernel/ <mh+linux-kernel@???> F=<linux-kernel-owner+mh=2Blinux-kernel=40zugschlus.de@???> R=userforward T=address_maildir S=3905
|2003-03-06 20:35:49 18r19X-0002Xc-00 Completed
|2003-03-06 20:35:50 18r19X-0002Xb-00 => /home/mh/.mail/.lists/ (mh+lists@???) <mh+exim-users@???> F=<exim-users-admin@???> R=userforward T=address_maildir S=4397
|2003-03-06 20:35:50 18r19X-0002Xb-00 Completed

Repeating the process showed the same result.

There is definetely something wrong, and it affects mail transport.

Greetings
Marc

--
-------------------------------------- !! No courtesy copies, please !! -----
Marc Haber          |   " Questions are the         | Mailadresse im Header
Karlsruhe, Germany  |     Beginning of Wisdom "     | Fon: *49 721 966 32 15
Nordisch by Nature  | Lt. Worf, TNG "Rightful Heir" | Fax: *49 721 966 31 29