On Sat, Sep 29, 2018, at 8:59 AM, Paul van der Vlis wrote:
> Op 28-09-18 om 15:34 schreef Michael Menge:
> >
> > Quoting Paul van der Vlis <paul@xxxxxxxxxxxxx>:
> >
> >> Hello,
> >>
> >> I am using Cyrus-imapd from Debian stable (2.5.10-3), and starting up
> >> takes very long. I see processes starting, but no imapd.
> >>
> >> In most cases I restart Cyrus more then ones before it works. Not sure I
> >> have to wait longer, or restarting after some time helps.
> >>
> >> This problem occurs on only one machine, on two other less busy machine
> >> with the same Cyrus I don't have problems.
> >>
> >> Maybe somebody here knows more about what could be wrong? Or how to
> >> debug this?
> >>
> >
> >
> > What is cyrus logging to your logfiles when you restart?
>
> In my crontab I have this line:
> 00 4 * * * root /usr/sbin/service cyrus-imapd restart
>
> First I see many of this lines in /var/log/mail.log:
> Sep 25 04:00:01 sigmund cyrus/imap[21598]: graceful shutdown
>
> Then I see this between those lines this:
> -----
> Sep 25 04:00:02 sigmund cyrus/idled[5844]: graceful shutdown initiated
> by unexpected process 5838 (/usr/sbin/cyrmaster -l 32 -C /etc/imapd.conf
> -M /etc/cyrus.conf)
> Sep 25 04:00:02 sigmund cyrus/imaps[16434]: IDLE: error sending message
> DONE to idled for mailbox user.nospam.Junk: Connection refused.
> -----
>
> This line:
> Sep 25 04:00:02 sigmund cyrus/master[5838]: process type:SERVICE
> name:notify path:/usr/lib/cyrus/bin/notifyd age:85080.426s pid:6024
> exited, status 75
>
> Many of these lines:
> Sep 25 04:00:02 sigmund cyrus/master[5838]: process type:SERVICE
> name:imap path:/usr/lib/cyrus/bin/imapd age:85073.234s pid:6027 exited,
> status 75
>
> Then this:
> --------
> Sep 25 04:00:05 sigmund cyrus/ctl_cyrusdb[21829]: skiplist: clean
> shutdown file missing, updating recovery stamp
> Sep 25 04:00:05 sigmund cyrus/ctl_cyrusdb[21829]: recovering cyrus databases
> Sep 25 04:00:05 sigmund cyrus/ctl_cyrusdb[21829]: done recovering cyrus
> databases
> Sep 25 04:00:05 sigmund cyrus/cyr_expire[21834]: skiplist: recovered
> /var/lib/cyrus/deliver.db (9290 records, 1759220 bytes) in 0 seconds
> Sep 25 04:00:05 sigmund cyrus/cyr_expire[21834]: skiplist: checkpointed
> /var/lib/cyrus/deliver.db (9290 records, 1412288 bytes) in 0.227 sec
> Sep 25 04:00:19 sigmund cyrus/cyr_expire[21834]: Expired 0 and expunged
> 0 out of 1312483 messages from 2984 mailboxes
> Sep 25 04:00:19 sigmund cyrus/cyr_expire[21834]: duplicate_prune:
> pruning back 3.00 days
> Sep 25 04:00:30 sigmund cyrus/cyr_expire[21834]: skiplist: longlock
> /var/lib/cyrus/deliver.db for 1.8 seconds
> Sep 25 04:00:33 sigmund cyrus/cyr_expire[21834]: skiplist: longlock
> /var/lib/cyrus/deliver.db for 2.2 seconds
> Sep 25 04:00:39 sigmund cyrus/cyr_expire[21834]: skiplist: longlock
> /var/lib/cyrus/deliver.db for 1.3 seconds
> Sep 25 04:05:36 sigmund cyrus/cyr_expire[21834]: duplicate_prune: purged
> 2217 out of 9290 entries
> Sep 25 04:05:36 sigmund cyrus/tls_prune[21860]: skiplist: recovered
> /var/lib/cyrus/tls_sessions.db (10219 records, 2235748 bytes) in 0 seconds
> Sep 25 04:05:36 sigmund cyrus/tls_prune[21860]: skiplist: checkpointed
> /var/lib/cyrus/tls_sessions.db (10219 records, 2147768 bytes) in 0.308 sec
> Sep 25 04:09:47 sigmund cyrus/tls_prune[21860]: skiplist: longlock
> /var/lib/cyrus/tls_sessions.db for 1.4 seconds
> Sep 25 04:10:23 sigmund cyrus/tls_prune[21860]: skiplist: longlock
> /var/lib/cyrus/tls_sessions.db for 2.2 seconds
> Sep 25 04:10:45 sigmund cyrus/tls_prune[21860]: skiplist: longlock
> /var/lib/cyrus/tls_sessions.db for 2.2 seconds
> Sep 25 04:12:21 sigmund cyrus/tls_prune[21860]: skiplist: longlock
> /var/lib/cyrus/tls_sessions.db for 1.3 seconds
> Sep 25 04:12:47 sigmund cyrus/tls_prune[21860]: skiplist: longlock
> /var/lib/cyrus/tls_sessions.db for 1.0 seconds
> Sep 25 04:12:49 sigmund cyrus/tls_prune[21860]: skiplist: longlock
> /var/lib/cyrus/tls_sessions.db for 1.8 seconds
> Sep 25 04:17:33 sigmund cyrus/tls_prune[21860]: skiplist: longlock
> /var/lib/cyrus/tls_sessions.db for 1.0 seconds
> Sep 25 04:23:11 sigmund cyrus/tls_prune[21860]: skiplist: longlock
> /var/lib/cyrus/tls_sessions.db for 1.0 seconds
> Sep 25 04:25:31 sigmund cyrus/tls_prune[21860]: tls_prune: purged 4463
> out of 10219 entries
> Sep 25 04:25:31 sigmund cyrus/master[21826]: unable to
> setsocketopt(IP_TOS) service lmtpunix/unix: Operation not supported
> Sep 25 04:25:31 sigmund cyrus/master[21826]: unable to
> setsocketopt(IP_TOS) service notify/unix: Operation not supported
> Sep 25 04:25:31 sigmund cyrus/ctl_cyrusdb[22345]: checkpointing cyrus
> databases
> Sep 25 04:25:31 sigmund cyrus/ctl_cyrusdb[22345]: done checkpointing
> cyrus databases
> Sep 25 04:25:32 sigmund cyrus/imaps[22349]: inittls: Loading hard-coded
> DH parameters
> Sep 25 04:25:33 sigmund cyrus/imaps[22349]: starttls: TLSv1.2 with
> cipher ECDHE-RSA-AES128-SHA (128/128 bits new) no authentication
> Sep 25 04:26:20 sigmund cyrus/imap[22362]: inittls: Loading hard-coded
> DH parameters
> Sep 25 04:26:20 sigmund cyrus/imap[22363]: inittls: Loading hard-coded
> DH parameters
> ---------
>
> So you can see imap is active after 25 minutes...
>
> > What is in the START section of your /etc/cyrus.conf?
> ----
> START {
> # do not delete this entry!
> recover cmd="/usr/sbin/cyrus ctl_cyrusdb -r"
>
> # this is only necessary if idlemethod is set to "idled" in
> # imapd.conf
> idled cmd="idled"
>
> # this is useful on backend nodes of a Murder cluster
> # it causes the backend to syncronize its mailbox list with
> # the mupdate master upon startup
> #mupdatepush cmd="/usr/sbin/cyrus ctl_mboxlist -m"
>
> # this is recommended if using duplicate delivery suppression
> delprune cmd="/usr/sbin/cyrus expire -E 3"
> # this is recommended if caching TLS sessions
> tlsprune cmd="/usr/sbin/cyrus tls_prune"
> }
> ---------
>
> Thanks for you help!
>
> With regards,
> Paul van der Vlis
Looks like most of the time (nearly 20 minutes) is being taken up by tls_prune cleaning up the tls_sessions.db:
> Sep 25 04:05:36 sigmund cyrus/tls_prune[21860]: skiplist: recovered
> /var/lib/cyrus/tls_sessions.db (10219 records, 2235748 bytes) in 0 seconds
> Sep 25 04:05:36 sigmund cyrus/tls_prune[21860]: skiplist: checkpointed
> /var/lib/cyrus/tls_sessions.db (10219 records, 2147768 bytes) in 0.308 sec
> [...]
> Sep 25 04:25:31 sigmund cyrus/tls_prune[21860]: tls_prune: purged 4463
> out of 10219 entries
You could use the tls_sessions_db_path imapd.conf(5) option to put this database onto faster storage?
> tls_sessions_db_path: <none>
> The absolute path to the TLS sessions db file. If not specified, will be
> configdirectory/tls_sessions.db
If you have the RAM for it, you should be able to put tls_sessions.db on a tmpfs filesystem. This database is only a cache, so nothing valuable will be lost if the machine is rebooted; and as a cache, it benefits from being on the fastest storage you have available. :)
Cheers,
ellie
----
Cyrus Home Page: http://www.cyrusimap.org/
List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/
To Unsubscribe:
https://lists.andrew.cmu.edu/mailman/listinfo/info-cyrus
