1

Topic: iRedAPD not start!

==== Required information ====
- iRedMail version (check /etc/iredmail-release):
- Linux/BSD distribution name and version:
- Store mail accounts in which backend (LDAP/MySQL/PGSQL):
- Web server (Apache or Nginx):
- Manage mail accounts with iRedAdmin-Pro?
- Related log if you're reporting an issue:
======== Required information ====
- iRedMail version (check /etc/iredmail-release): 0.9.5.-1
- Linux/BSD distribution name and version: CentOS 6
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): MySQL
- Web server (Apache or Nginx): Apache
- Manage mail accounts with iRedAdmin-Pro? iRedAdmin-Pro-SQL 2.4.1
- Related log if you're reporting an issue:
====

iRedAPD error
#service iredapd restart
#iredapd is already stopped.
Starting iredapd ...
Traceback (most recent call last):
  File "/opt/iredapd/iredapd.py", line 24, in <module>
    from libs.logger import logger
  File "/opt/iRedAPD-1.9.1/libs/logger.py", line 119, in <module>
    log_level = getattr(logging, str(settings.log_level).upper())
AttributeError: 'module' object has no attribute 'log_level'

Iredapd.log
2017-02-16 11:05:59 INFO [203.162.146.186] RCPT, XXXXX , DUNNO
2017-02-16 11:05:59 INFO [203.162.146.186] RCPT, XXXXX, DUNNO
2017-02-16 11:05:59 INFO [203.162.146.186] END-OF-MESSAGE, XXXX-> , DUNNO

maillog.
Feb 16 11:51:04 mail2 postfix/submission/smtpd[7351]: NOQUEUE: reject: RCPT from mail2.mx.
[127.0.0.1]: 451 4.3.5 Server configuration problem; from=<test@xxx> to=<test@xxx> proto=ESMTP helo=<mail.xxx>
Feb 16 11:51:04 mail2 roundcube: ERROR: Invalid response code received from server (451) Feb 16 11:51:04 mail2 roundcube: <8koc4r2o> SMTP Error: Failed to add recipient 'test@xxx'. 4.3.5 Server configuration problem (Code: 451) in /var/www/roundcubemail-1.2.0/ program/lib/Roundcube/rcube.php on line 1595 (POST /mail/?_task=mail&_unlock=loading148722
0661719&_lang=en_US&_framed=1&_action=send)

Feb 16 14:46:56 mail2 abrt: detected unhandled Python exception in '/opt/iredapd/iredapd.py'
Feb 16 14:46:56 mail2 abrt-server[31703]: Saved Python crash dump of pid 31702 to /var/spool/abrt/pyhook-2017-02-16-14:46:56-31702
Feb 16 14:46:56 mail2 abrtd: Directory 'pyhook-2017-02-16-14:46:56-31702' creation detected Feb 16 14:46:56 mail2 abrtd: Executable '/opt/iredapd/iredapd.py' doesn't belong to any package and ProcessUnpackaged is set to 'no'
Feb 16 14:46:56 mail2 abrtd: 'post-create' on '/var/spool/abrt/pyhook-2017-02-16-14:46:56-31702' exited with 1 Feb 16 14:46:56 mail2 abrtd: Deleting problem directory '/var/spool/abrt/pyhook-2017-02-16-14:46:56-31702'

Mail server not send and receive mail. How can fix problem.
Thanks for your help.

----

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

2

Re: iRedAPD not start!

dudd wrote:

AttributeError: 'module' object has no attribute 'log_level'

Seems you don't have parameter "log_level =" in /opt/iredapd/settings.py. Please double check.

You can find sample config file under same directory: /opt/iredapd/settings.py.sample.

3

Re: iRedAPD not start!

After problem I change /opt/iredapd/settings.py

# Log level: info, debug.
#log_level = "info"
log_level = "debug"

4

Re: iRedAPD not start!

Is iRedAPD working now after restarted?

dudd wrote:

Feb 16 14:46:56 mail2 abrtd: Directory 'pyhook-2017-02-16-14:46:56-31702' creation detected Feb 16 14:46:56 mail2 abrtd: Executable '/opt/iredapd/iredapd.py' doesn't belong to any package and ProcessUnpackaged is set to 'no'
Feb 16 14:46:56 mail2 abrtd: 'post-create' on '/var/spool/abrt/pyhook-2017-02-16-14:46:56-31702' exited with 1 Feb 16 14:46:56 mail2 abrtd: Deleting problem directory '/var/spool/abrt/pyhook-2017-02-16-14:46:56-31702'

Why "/var/spool/abrt" is involved in iredapd issue?

5

Re: iRedAPD not start!

ZhangHuangbin wrote:

Is iRedAPD working now after restarted?

dudd wrote:

Feb 16 14:46:56 mail2 abrtd: Directory 'pyhook-2017-02-16-14:46:56-31702' creation detected Feb 16 14:46:56 mail2 abrtd: Executable '/opt/iredapd/iredapd.py' doesn't belong to any package and ProcessUnpackaged is set to 'no'
Feb 16 14:46:56 mail2 abrtd: 'post-create' on '/var/spool/abrt/pyhook-2017-02-16-14:46:56-31702' exited with 1 Feb 16 14:46:56 mail2 abrtd: Deleting problem directory '/var/spool/abrt/pyhook-2017-02-16-14:46:56-31702'

Why "/var/spool/abrt" is involved in iredapd issue?

I would explain the situation.
At first, the server was spammed with 200k message. Then I deleted the queues with command postsuper -d ALL.
Then, then mail server behaved strangely even if I restared the system.
Searching every log, I found Iredapd process cannot start with the log I sent to you.
just my guess.

Thank for your help.

6

Re: iRedAPD not start!

Is iRedAPD running now? Any error in Postfix log file?

7

Re: iRedAPD not start!

ZhangHuangbin wrote:

Is iRedAPD running now? Any error in Postfix log file?

iredapd not start.
/var/log/iredapd/iredapd.log
Traceback (most recent call last):
  File "/opt/iredapd/iredapd.py", line 24, in <module>
    from libs.logger import logger
  File "/opt/iRedAPD-1.9.1/libs/logger.py", line 119, in <module>
    log_level = getattr(logging, str(settings.log_level).upper())
AttributeError: 'module' object has no attribute 'log_level'

/var/log/maillog
Feb 19 04:00:02 mail2 postfix/qmgr[18979]: 8992E1235FD: from=<root@xxx>, size=1600, nrcpt=1 (queue active)
Feb 19 04:00:02 mail2 amavis[14499]: (14499-12) Passed CLEAN {RelayedInbound},  -> , Message-ID: , mail_id: v13VSwXWVE8a, Hits: -, size: 1113, queued_as: 8992E1235FD, 208 ms
Feb 19 04:00:02 mail2 postfix/smtp[17894]: 422E6123659: to=<root@xxxx>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.38, delays=0.1/0.05/0.01/0.22, 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 8992E1235FD)
Feb 19 04:00:02 mail2 postfix/qmgr[18979]: 422E6123659: removed
Feb 19 04:00:02 mail2 postfix/local[17900]: warning: alias database loop for postmaster
Feb 19 04:00:02 mail2 postfix/local[17900]: 8992E1235FD: to=<postmaster@xxxx...skipping...
mien.vn>, relay=local, delay=0.1, delays=0.01/0/0/0.09, dsn=5.4.6, status=bounced (alias d
atabase loop for postmaster)
Feb 20 14:30:04 mail2 postfix/qmgr[18979]: AD0C112360E: removed
Feb 20 15:00:02 mail2 postfix/pickup[27731]: 847BA123659: uid=0 from=<root>
Feb 20 15:00:02 mail2 postfix/cleanup[27878]: 847BA123659: message-id=<20170220080002.847B
A123659@mail2.xxxx>
Feb 20 15:00:02 mail2 postfix/qmgr[18979]: 847BA123659: from=<root@mail2.xxx>, size=1113, nrcpt=1 (queue active)
Feb 20 15:00:02 mail2 postfix/smtpd[27884]: connect from mail2.xxx[127.0.0
.1]
Feb 20 15:00:02 mail2 postfix/smtpd[27884]: D803C1235FD: client=mail2.xxx[
127.0.0.1]
Feb 20 15:00:02 mail2 postfix/cleanup[27878]: D803C1235FD: message-id=<20170220080002.847B
A123659@mail2.xxxn>
Feb 20 15:00:02 mail2 postfix/smtpd[27884]: disconnect from mail2.xxx[127.
0.0.1]
Feb 20 15:00:02 mail2 postfix/qmgr[18979]: D803C1235FD: from=<root@mail2.xxx>, size=1600, nrcpt=1 (queue active)
Feb 20 15:00:02 mail2 amavis[25424]: (25424-10) Passed CLEAN {RelayedInbound},  -> , Message-ID: , mail_id: MTHpMoYiN9nJ, Hits: -, size: 1113, queued_as: D803C1235FD, 283 ms
Feb 20 15:00:02 mail2 postfix/smtp[27882]: 847BA123659: to=<root@mail2.xxx>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.48, delays=0.12/0.05/0.01/0.29, 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 D803C1235FD)
Feb 20 15:00:02 mail2 postfix/qmgr[18979]: 847BA123659: removed
Feb 20 15:00:03 mail2 postfix/local[27888]: warning: alias database loop for postmaster
Feb 20 15:00:03 mail2 postfix/local[27888]: D803C1235FD: to=<postmaster@mail2.xxx>, relay=local, delay=0.2, delays=0.06/0.02/0/0.12, dsn=5.4.6, status=bounced (alias database loop for postmaster)
Feb 20 15:00:03 mail2 postfix/cleanup[27878]: 14C0112360E: message-id=<20170220080003.14C0112360E@mail2.xxx>
Feb 20 15:00:03 mail2 postfix/bounce[27889]: D803C1235FD: sender non-delivery notification: 14C0112360E
Feb 20 15:00:03 mail2 postfix/qmgr[18979]: 14C0112360E: from=<>, size=3638, nrcpt=1 (queue active)
Feb 20 15:00:03 mail2 postfix/qmgr[18979]: D803C1235FD: removed
Feb 20 15:00:03 mail2 postfix/local[27888]: warning: alias database loop for postmaster
Feb 20 15:00:03 mail2 postfix/local[27888]: 14C0112360E: to=<postmaster@mail2.xxx>, relay=local, delay=0.18, delays=0.07/0.01/0/0.1, dsn=5.4.6, status=bounced (alias database loop for postmaster)
Feb 20 15:00:03 mail2 postfix/qmgr[18979]: 14C0112360E: removed

8

Re: iRedAPD not start!

dudd wrote:

  File "/opt/iRedAPD-1.9.1/libs/logger.py", line 119, in <module>
    log_level = getattr(logging, str(settings.log_level).upper())
AttributeError: 'module' object has no attribute 'log_level'

Could you please show us FULL output of commands below:

service iredapd restart
grep 'log_level' /opt/iredapd/settings.py
ls -l /opt/iredapd/settings.py

9

Re: iRedAPD not start!

ZhangHuangbin wrote:
dudd wrote:

  File "/opt/iRedAPD-1.9.1/libs/logger.py", line 119, in <module>
    log_level = getattr(logging, str(settings.log_level).upper())
AttributeError: 'module' object has no attribute 'log_level'

Could you please show us FULL output of commands below:

service iredapd restart
grep 'log_level' /opt/iredapd/settings.py
ls -l /opt/iredapd/settings.py

[root@mail2]# service iredapd restart
grep 'log_level' /opt/iredapd/settings.py
ls -l /opt/iredapd/settings.py
iredapd is already stopped.
Starting iredapd ...
Traceback (most recent call last):
  File "/opt/iredapd/iredapd.py", line 24, in <module>
    from libs.logger import logger
  File "/opt/iRedAPD-1.9.1/libs/logger.py", line 119, in <module>
    log_level = getattr(logging, str(settings.log_level).upper())
AttributeError: 'module' object has no attribute 'log_level'
[root@mail2]# grep 'log_level' /opt/iredapd/settings.py
log_level = "info"
# log_level = "debug"
[root@mail2]# ls -l /opt/iredapd/settings.py
-r-------- 1 root root 1929 Feb 17 09:27 /opt/iredapd/settings.py
[root@mail2]#

Thanks.

10

Re: iRedAPD not start!

Seems just fine, no idea right now.
Is it possible to give me direct ssh access with root privilege to figure it out?

11

Re: iRedAPD not start!

ZhangHuangbin wrote:

Seems just fine, no idea right now.
Is it possible to give me direct ssh access with root privilege to figure it out?

Please contact me by email huend999@gmail.com.
Thank for your help.

12

Re: iRedAPD not start!

Fixed. There's file /opt/iredapd/libs/settings.py, it should be removed.