1 Topic by mensmaximus

  • mensmaximus
  • Member
  • Offline
  • Registered: 2013-03-16
  • Posts: 36

Topic: iredapd 1.5.0 still stopping

==== Required information ====
- iRedMail version: 0.9.1
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): mysql
- Web server (Apache or Nginx): apache
- Linux/BSD distribution name and version: centos 7.1
- Related log if you're reporting an issue: none
====

You already closed the thread http://www.iredmail.org/forum/topic9183 … blems.html

However the patch does not work. Still iredapd is stopping without any warning or logentry.

----

Spider Email Archiver: On-Premises, lightweight email archiving software developed by iRedMail team. Supports Amazon S3 compatible storage and custom branding.

2 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,787

Re: iredapd 1.5.0 still stopping

Could you please download and upgrade to the latest development version and try again?
https://bitbucket.org/zhb/iredapd/downloads (click "Download repository" to get the latest development version, then rename extracted directory name to 'iRedAPD-1.6.0', execute she'll script 'tools/upgrade_iredapd.sh' in this directory)

3 Reply by mensmaximus

  • mensmaximus
  • Member
  • Offline
  • Registered: 2013-03-16
  • Posts: 36

Re: iredapd 1.5.0 still stopping

Thank you for the fast reply. Although I already applied the latest development build i did it again and we will see what happens.

4 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,787

Re: iredapd 1.5.0 still stopping

I planned to release iRedMail-0.9.2 tomorrow (June 1), I will wait for you for one more day. Please do let me know whether or not this issue occurs again.

5 Reply by mensmaximus

  • mensmaximus
  • Member
  • Offline
  • Registered: 2013-03-16
  • Posts: 36

Re: iredapd 1.5.0 still stopping

It is 23 hours now without iredapd stopping. This sounds promissing. So whatever has been chaned in the last build seem to have fixed it.

6 Reply by InformaticaTTU

  • InformaticaTTU
  • Member
  • Offline
  • Registered: 2014-07-21
  • Posts: 47

Re: iredapd 1.5.0 still stopping

I got the same problem but mine was only on weekend (just when the server have less traffic). Latest was this Sunday at 17h.

I'll try the latest development version to see if is working.

Greetings!!

7 Reply by deejc

  • deejc
  • Member
  • Offline
  • Registered: 2014-10-17
  • Posts: 28

Re: iredapd 1.5.0 still stopping

Hello,
I am also seeing this issue on 1.5, but it seems only once a week for the last 2 weeks.
Both times on a Sunday.
The logs show a connection refused to port 7777, once I restart ireadapd its working again.

8 Reply by mir

  • mir
  • Member
  • Offline
  • Registered: 2014-05-30
  • Posts: 170

Re: iredapd 1.5.0 still stopping

deejc wrote:

Hello,
I am also seeing this issue on 1.5, but it seems only once a week for the last 2 weeks.
Both times on a Sunday.
The logs show a connection refused to port 7777, once I restart ireadapd its working again.

This is normal as part of logrotate. See /etc/logrotate.d/iredapd

9 Reply by deejc

  • deejc
  • Member
  • Offline
  • Registered: 2014-10-17
  • Posts: 28

Re: iredapd 1.5.0 still stopping

no it is not, it does not restart iredapd and so every connection is refused.

10 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,787

Re: iredapd 1.5.0 still stopping

Dear all,

Do you still have this issue with the latest iRedAPD development version? Please reply to confirm this. Otherwise i'm ready to release iRedMail-0.9.2.

11 Reply by mir

  • mir
  • Member
  • Offline
  • Registered: 2014-05-30
  • Posts: 170

Re: iredapd 1.5.0 still stopping

ZhangHuangbin wrote:

Dear all,

Do you still have this issue with the latest iRedAPD development version? Please reply to confirm this. Otherwise i'm ready to release iRedMail-0.9.2.

Unfortunately it seems I had an unexpected restart made by my monitor today:
Made by logrote: 2015-06-01 06:25:17 INFO Starting iRedAPD (version: 1.5.0, backend: ldap), listening on 127.0.0.1:7777.
Made by my monitor: 2015-06-01 14:37:01 INFO Starting iRedAPD (version: 1.5.0, backend: ldap), listening on 127.0.0.1:7777.

12 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,787

Re: iredapd 1.5.0 still stopping

Any log in iRedAPD log file? search string 'error' should be enough:

# grep -i 'error' /var/log/iredapd.log

The one restarted by logrotate is expected, but the one by your monitor is unexpected.

13 Reply by mir

  • mir
  • Member
  • Offline
  • Registered: 2014-05-30
  • Posts: 170

Re: iredapd 1.5.0 still stopping

ZhangHuangbin wrote:

Any log in iRedAPD log file? search string 'error' should be enough:

# grep -i 'error' /var/log/iredapd.log

Nothing.

ZhangHuangbin wrote:

The one restarted by logrotate is expected, but the one by your monitor is unexpected.

yep, aware of that. Just to show the history.

14 Reply by mir

  • mir
  • Member
  • Offline
  • Registered: 2014-05-30
  • Posts: 170

Re: iredapd 1.5.0 still stopping

mir wrote:
ZhangHuangbin wrote:

Any log in iRedAPD log file? search string 'error' should be enough:

# grep -i 'error' /var/log/iredapd.log

Nothing.

Forgot to mention that I have extended error logging enabled in iredapd.py:

    # Starting loop.
    try:
        # There's a bug report for Python 2.6/3.0 that `use_poll=True` yields
        # some 2.5 incompatibilities:
        if (sys.version_info >= (2, 7) and sys.version_info < (2, 8)) \
           or (sys.version_info >= (3, 4)):     # if python 2.7 ...
            # workaround for the "Bad file descriptor" issue on Python 2.7, gh-161
            asyncore.loop(use_poll=True)
        else:
            # fixes the "Unexpected communication problem" issue on Python 2.6 and 3.0
            asyncore.loop(use_poll=False)

    except KeyboardInterrupt:
        pass
    except Exception, e:
    logging.info('Error: ' + str(e))

I suspect therefore that the bug should be traced in one of the plugins since iredapd stops before reaching the last exception handler.

15 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,787

Re: iredapd 1.5.0 still stopping

mir wrote:

    except Exception, e:
    logging.info('Error: ' + str(e))

Do you have proper indent in the second line? It should be 8 spaces before 'logging.info(...)'.

    except KeyboardInterrupt:
        pass
    except Exception, e:
        logging.info('Error in asyncore.loop: ' + str(e))          # <- 8 spaces, not tab.

16 Reply by mir

  • mir
  • Member
  • Offline
  • Registered: 2014-05-30
  • Posts: 170

Re: iredapd 1.5.0 still stopping

Yes, indent is correct. If indent was not correct I would expect to get an error and the application wouldn't start.

17 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,787

Re: iredapd 1.5.0 still stopping

mir wrote:

I suspect therefore that the bug should be traced in one of the plugins since iredapd stops before reaching the last exception handler.

Good catch. Please apply this patch, if plugin has something wrong, it will be logged.

diff -r 34bbf2dad80d libs/utils.py
--- a/libs/utils.py    Sat May 30 12:24:45 2015 +0800
+++ b/libs/utils.py    Mon Jun 01 23:54:36 2015 +0800
@@ -25,7 +25,7 @@
         action = plugin.restriction(**kwargs)
         logging.debug('<-- Result: %s' % action)
     except Exception, e:
-        logging.debug('<!> Error: %s' % str(e))
+        logging.info('<!> Error applying plugin %s: %s' % (plugin.__name__, str(e)))
 
     return action

18 Reply by mir (edited by mir 2015-06-02 02:26:13)

  • mir
  • Member
  • Offline
  • Registered: 2014-05-30
  • Posts: 170

Re: iredapd 1.5.0 still stopping

Patch added but nothing suspicious logged. I think the bug is hidden somewhere in one of the plugins which occasionally emerges and causes one the plugins to crash. The crash is apparently catch somewhere by an exception handler which doesn't log anything when run normally or even worse and exception handler looking like this:
except Exception[, e]:
        pass

This has the result that upper layer exception handlers see this as a normal exit and stops iredapd normally resulting in no login taken place.

Plugins loaded:
2015-06-01 20:18:53 INFO Loading plugin: reject_null_sender
2015-06-01 20:18:53 INFO Loading plugin: ldap_maillist_access_policy
2015-06-01 20:18:53 INFO Loading plugin: ldap_amavisd_block_blacklisted_senders
2015-06-01 20:18:53 INFO Loading plugin: ldap_recipient_restrictions
2015-06-01 20:18:53 INFO Loading plugin: amavisd_message_size_limit

19 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,787

Re: iredapd 1.5.0 still stopping

mir wrote:

2015-06-01 20:18:53 INFO Loading plugin: ldap_amavisd_block_blacklisted_senders
2015-06-01 20:18:53 INFO Loading plugin: ldap_recipient_restrictions

These two plugins are depreciated, you should use plugin 'amavisd_wblist' instead.

I will try to add some more try...except... block in iredapd to catch possible errors.

20 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,787

Re: iredapd 1.5.0 still stopping

Dear all, any update about iRedAPD issue?

21 Reply by camel1cz

  • camel1cz
  • camel1cz
  • Member
  • Offline
  • From: Czech Republic
  • Registered: 2013-04-20
  • Posts: 220

Re: iredapd 1.5.0 still stopping

I had restarts each about 3 hours since this saturday on the 1.5.0 - so I upgraded to the devel version.

- the problem seems to be on my server thightly connected to one of my customers. He reported occasional "451 4.3.5 Server configuration problem" server responses which seems to collerate with iRedAPd exits...
- if the problem is connected with a misbehiving plugin, it has to be sql_alias_access_policy

22 Reply by mensmaximus

  • mensmaximus
  • Member
  • Offline
  • Registered: 2013-03-16
  • Posts: 36

Re: iredapd 1.5.0 still stopping

2 stable days now with the latest development release.

23 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,787

Re: iredapd 1.5.0 still stopping

camel1cz wrote:

- if the problem is connected with a misbehiving plugin, it has to be sql_alias_access_policy

Any error message in iRedAPD log file? You can try this:

# grep -i 'error' /var/log/iredapd.log

Also, could you try the latest development edition? it adds a try...except... block to log message if applied plugin raised some exception.

24 Reply by camel1cz (edited by camel1cz 2015-06-02 22:56:59)

  • camel1cz
  • camel1cz
  • Member
  • Offline
  • From: Czech Republic
  • Registered: 2013-04-20
  • Posts: 220

Re: iredapd 1.5.0 still stopping

ZhangHuangbin wrote:

Any error message in iRedAPD log file? You can try this:

Nothing much, just the errors I already posted here (at least I think so) and probably not connected to this issue:

2015-06-02 10:41:09 DEBUG SQL: query access policy: SELECT accesspolicy, goto, moderators
            FROM alias
            WHERE
                address='address@example.com'
                AND address <> goto
                AND active=1
            LIMIT 1
...
2015-06-02 10:41:09 DEBUG <!> Error: 'Connection' object has no attribute 'fetchone'
ZhangHuangbin wrote:

Also, could you try the latest development edition? it adds a try...except... block to log message if applied plugin raised some exception.

Sure, my server is running now on the latest snapshot of iRedAPd... will report anything unusual.

25 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,787

Re: iredapd 1.5.0 still stopping

camel1cz wrote:

2015-06-02 10:41:09 DEBUG <!> Error: 'Connection' object has no attribute 'fetchone'

this is a bug in 1.5.0 and old development edition, but fixed in latest development version.