Loading ...
Sorry, an error occurred while loading the content.

Re: performance of postfix

Expand Messages
  • Viktor Dukhovni
    ... No, less than 5% of messages spend more than 132s in the active queue. Most messages spend less than 21s, with 50%s delivered immediately. ... To
    Message 1 of 9 , May 22, 2013
    • 0 Attachment
      On Wed, May 22, 2013 at 04:45:42PM +0300, Selcuk Yazar wrote:

      > > >If your content filter is not very fast, bursts of mail will accumulate<
      > > >while they are waiting to be scanned. Then the queue becomes empty.
      > > >
      > > >You may also have deferred mail that is retried periodically. You logs
      > > >have a more complete picture.
      > > >
      > > >To improve content filter performance, eliminate remote DNS lookups
      > > >in the filter, or increate concurrency. If the problem is lack of
      > > >sufficient CPU resources, try to find a more performant scanner or
      > > >turn off optional scanning features you don't need.
      > > >
      > > >Since mail is not delayed for very long, there is no problem (certainly
      > > >not with Postfix itself, but scanning could perhaps be tuned).
      >
      > I found a script for log analyze (sourceforge), result are like below. I
      > think we have some queue problem, as I understand, %95 e-mails wait in
      > queue 132 seconds ?

      No, less than 5% of messages spend more than 132s in the active
      queue. Most messages spend less than 21s, with 50%s delivered
      immediately.

      > postfix logwatch
      >
      > === Delivery Delays Percentiles
      > ============================================================
      > 0% 25% 50% 75% 90% 95%
      > 98% 100%
      > --------------------------------------------------------------------------------------------
      > In qmgr 0.00 0.00 0.01 21.00 110.00 132.00
      > 158.00 180.00
      > Conn setup 0.00 0.00 0.00 0.00 0.85 9.43
      > 51.00 226.00
      > Transmission 0.00 0.11 4.70 6.20 13.00 18.00
      > 22.00 73.00
      > Total 0.04 1.10 9.00 46.00 123.00 154.00
      > 180.00 2373.00
      > ============================================================================================

      To understand what is actually going on, you'll have to *read* the
      logs, not just look at summaries. You'll probably find occasional
      latency sending messages through the content filter. If that's a
      problem, tune the content filter to remove DNS lookups or raise
      its concurrency. If the content filter is using all available CPU
      resources, tune it to do less, or find a more efficient one.

      Before any of that, locate the log entries showing delayed deliveries,
      read them, and figure out the reasons for the delay.

      --
      Viktor.
    • Stan Hoeppner
      ... I ve been using logwatch for quite some time and I ve found the Delivery Delay Percentiles 100% column to be seemingly pulled from thin air. Don t rely
      Message 2 of 9 , May 22, 2013
      • 0 Attachment
        On 5/22/2013 10:13 AM, Viktor Dukhovni wrote:
        > On Wed, May 22, 2013 at 04:45:42PM +0300, Selcuk Yazar wrote:
        >
        >>>> If your content filter is not very fast, bursts of mail will accumulate<
        >>>> while they are waiting to be scanned. Then the queue becomes empty.
        >>>>
        >>>> You may also have deferred mail that is retried periodically. You logs
        >>>> have a more complete picture.
        >>>>
        >>>> To improve content filter performance, eliminate remote DNS lookups
        >>>> in the filter, or increate concurrency. If the problem is lack of
        >>>> sufficient CPU resources, try to find a more performant scanner or
        >>>> turn off optional scanning features you don't need.
        >>>>
        >>>> Since mail is not delayed for very long, there is no problem (certainly
        >>>> not with Postfix itself, but scanning could perhaps be tuned).
        >>
        >> I found a script for log analyze (sourceforge), result are like below. I
        >> think we have some queue problem, as I understand, %95 e-mails wait in
        >> queue 132 seconds ?
        >
        > No, less than 5% of messages spend more than 132s in the active
        > queue. Most messages spend less than 21s, with 50%s delivered
        > immediately.
        >
        >> postfix logwatch
        >>
        >> === Delivery Delays Percentiles
        >> ============================================================
        >> 0% 25% 50% 75% 90% 95%
        >> 98% 100%
        >> --------------------------------------------------------------------------------------------
        >> In qmgr 0.00 0.00 0.01 21.00 110.00 132.00
        >> 158.00 180.00
        >> Conn setup 0.00 0.00 0.00 0.00 0.85 9.43
        >> 51.00 226.00
        >> Transmission 0.00 0.11 4.70 6.20 13.00 18.00
        >> 22.00 73.00
        >> Total 0.04 1.10 9.00 46.00 123.00 154.00
        >> 180.00 2373.00
        >> ============================================================================================
        >
        > To understand what is actually going on, you'll have to *read* the
        > logs, not just look at summaries.

        I've been using logwatch for quite some time and I've found the Delivery Delay Percentiles '100%' column to be seemingly pulled from thin air. Don't rely on it.

        === Delivery Delays Percentiles ============================================================
        0% 25% 50% 75% 90% 95% 98% 100%
        --------------------------------------------------------------------------------------------
        Before qmgr 0.02 0.03 0.06 0.28 0.42 0.88 2.48 9.20
        In qmgr 0.00 0.02 0.02 0.03 0.03 0.03 0.04 0.06
        Conn setup 0.00 0.00 0.00 0.00 0.00 0.00 0.55 2.70
        Transmission 0.03 0.07 0.62 3.10 4.12 5.36 9.75 232.00
        Total 0.08 0.12 1.50 3.60 4.82 6.90 11.28 232.00
        ============================================================================================

        For instance this summary of yesterday shows 232s for Transmission. Yet when I search my last ~3 days of logs with:

        ~$ grep local /var/log/mail.log|mawk '{ print($10) }'|grep "delays"
        ~$ grep smtp /var/log/mail.log|mawk '{ print($10) }'|grep "delays"

        the largest value I see is 3.1s, in smtp. For local all delays are less than one second.

        > You'll probably find occasional
        > latency sending messages through the content filter. If that's a
        > problem, tune the content filter to remove DNS lookups or raise
        > its concurrency. If the content filter is using all available CPU
        > resources, tune it to do less, or find a more efficient one.
        >
        > Before any of that, locate the log entries showing delayed deliveries,
        > read them, and figure out the reasons for the delay.

        I'm using spamc/spamd via pipe so it doesn't add to delays in postfix/local log stamps. To see the spamd delays I use:

        ~$ grep scantime /var/log/mail.log|mawk '{ print($12) }'|cut -f1 -d,

        This shows the largest spamd time is 37.7s, the next largest 13.0s. Some 95% appear to be less than 6s. Summing the largest of these with corresponding postfix/local delays doesn't come close to 232s, but less than 40s.

        --
        Stan
      • Viktor Dukhovni
        ... When the scanner throughput is too low, the delay shows up in the active queue of the pre-scan Postfix instance, not in the scanner time to scan a message
        Message 3 of 9 , May 22, 2013
        • 0 Attachment
          On Wed, May 22, 2013 at 03:00:44PM -0500, Stan Hoeppner wrote:

          > > You'll probably find occasional
          > > latency sending messages through the content filter. If that's a
          > > problem, tune the content filter to remove DNS lookups or raise
          > > its concurrency. If the content filter is using all available CPU
          > > resources, tune it to do less, or find a more efficient one.
          > >
          > > Before any of that, locate the log entries showing delayed deliveries,
          > > read them, and figure out the reasons for the delay.
          >
          > I'm using spamc/spamd via pipe so it doesn't add to delays in postfix/local log stamps. To see the spamd delays I use:
          >
          > ~$ grep scantime /var/log/mail.log|mawk '{ print($12) }'|cut -f1 -d,

          When the scanner throughput is too low, the delay shows up in the
          active queue of the pre-scan Postfix instance, not in the scanner
          time to scan a message logs. Messages sitting in active wating to
          be scheduled for scanning are not seen by the non-telepathic scanner.

          --
          Viktor.
        • Stan Hoeppner
          ... The only point I was making is that some of the logwatch summary values may not be accurate, providing him a heads up as he had apparently never used
          Message 4 of 9 , May 22, 2013
          • 0 Attachment
            On 5/22/2013 4:04 PM, Viktor Dukhovni wrote:
            > On Wed, May 22, 2013 at 03:00:44PM -0500, Stan Hoeppner wrote:
            >
            >>> You'll probably find occasional
            >>> latency sending messages through the content filter. If that's a
            >>> problem, tune the content filter to remove DNS lookups or raise
            >>> its concurrency. If the content filter is using all available CPU
            >>> resources, tune it to do less, or find a more efficient one.
            >>>
            >>> Before any of that, locate the log entries showing delayed deliveries,
            >>> read them, and figure out the reasons for the delay.
            >>
            >> I'm using spamc/spamd via pipe so it doesn't add to delays in postfix/local log stamps. To see the spamd delays I use:
            >>
            >> ~$ grep scantime /var/log/mail.log|mawk '{ print($12) }'|cut -f1 -d,
            >
            > When the scanner throughput is too low, the delay shows up in the
            > active queue of the pre-scan Postfix instance, not in the scanner
            > time to scan a message logs. Messages sitting in active wating to
            > be scheduled for scanning are not seen by the non-telepathic scanner.

            The only point I was making is that some of the logwatch summary values
            may not be accurate, providing him a heads up as he had apparently never
            used logwatch prior to installing it and posting his summary table. I
            was not attempting to troubleshoot his larger issue in this post.

            --
            Stan
          Your message has been successfully submitted and would be delivered to recipients shortly.