Kopano-Server didn‘t start

cblaha

Hi,

I‘ve got the following log message when I start my updated server:

2019-11-20T20:32:00.258450: [=======] Starting kopano-server version 8.7.85 (pid 23425 uid 0)
2019-11-20T20:32:00.258501: [info ] Using epoll events
2019-11-20T20:32:00.258815: [info ] Listening on 0.0.0.0:236 (fd 5)
2019-11-20T20:32:00.258860: [info ] Listening on [::]:236 (fd 6)
2019-11-20T20:32:00.262368: [error ] K-1561: chmod “/var/run/kopano/prio.sock”: Die Operation ist nicht erlaubt
2019-11-20T20:32:00.262537: [=======] Server shutdown complete.

externa1

@cblaha

maybe its related to this entry:

https://forum.kopano.io/topic/2512/socket-permissions-issues-with-kopano-server-build-8-7-81-162

rg
Christian

cblaha

I can‘t find the solution.

JochenH

Hi,
i have the same issue.

2019-11-17T11:42:13.826327: [=======] Starting kopano-server version 8.7.85 (pid 16022 uid 0)
2019-11-17T11:42:13.836224: [error ] K-1561: chmod “/var/run/kopano/prio.sock”: Vorgang nicht zulässig
2019-11-17T11:42:13.837154: [=======] Server shutdown complete.

fbartels

@cblaha @JochenH it would be helpful if you could specify the distribution/os you’re using.

JochenH

@fbartels Ubuntu 18.04

cblaha

@fbartels Debian 10

fbartels

Is that a fresh installation or an upgrade (from which exact version)? What is the output of ls -la /var/run/kopano?

Can you also try to start kopano-server with a higher log_level?

cblaha

@fbartels: It is an upgrade from 8.7.83.106. The kopano-server has the log level 6 and this is the output from ```
ls -la /var/run/kopano


root@server ~ # ls -la /var/run/kopano
insgesamt 32K
drwxrwxr-x  2 kopano kopano  260 Nov 20 21:07 .
drwxr-xr-x 58 root   root   1,9K Nov 21 10:10 ..
-rw-------  1 kopano kopano    6 Nov 20 18:01 dagent.pid
-rw-r--r--  1 kopano kopano    6 Nov 20 18:01 gateway.pid
-rw-r--r--  1 kopano kopano    6 Nov 20 18:01 ical.pid
-rw-r--r--  1 kopano kopano    6 Nov 20 18:01 monitor.pid
srwxr-xr-x  1 kopano kopano    0 Nov 20 21:07 prio.sock
-rw-r--r--  1 kopano kopano    6 Nov 20 18:03 search.pid
-rw-r--r--  1 kopano kopano    5 Nov 20 09:02 server.pid
srw-rw-rw-  1 kopano kopano    0 Nov 20 20:11 server.sock
-rw-r--r--  1 kopano amavis    6 Nov 20 18:03 spamd.pid
-rw-------  1 kopano kopano    6 Nov 20 18:03 spooler.pid
srw-rw----  1 kopano kopano    0 Nov 20 18:01 statsd.sock

jengelh

If chmod is forbidden while being uid 0, you have “bigger problems” in your system. (SELinux? AppArmor?)

thctlo

Hm, i just had a look at this, im running debian 10.

I did not see this problem in 8.7.85.50.bb7fcea13-0+174.1 and (updated today ) 8.7.85.51.2bf02c781-0+178.1

What i did notice on my server, all my kopano service where having override settings.
Like these:

# /etc/systemd/system/kopano-server.service.d/override.conf
[Unit]
After=network-online.target mysql.service mariadb.service
Wants=network-online.target mysql.service mariadb.service

I had to reduce the settings to minimal to avoid startup problem of the kopano services.
Noted, that these are my own changes to tune the startup processes…

I also noticed that kopano-search does not respect the log settings, i want it all in file, only Search wont write in the file. ( needs more investigations )

About the kopano-server process.
this is my debug level 6 to others can compair with it.

2019-11-22T11:05:39.257520: [info   ] Audit logging not enabled.
2019-11-22T11:05:39.257579: [=======] Starting kopano-server version 8.7.85 (pid 27299 uid 0)
2019-11-22T11:05:39.257617: [info   ] Using epoll events
2019-11-22T11:05:39.257819: [info   ] Listening on 0.0.0.0:236 (fd 5)
2019-11-22T11:05:39.257857: [info   ] Listening on [::]:236 (fd 6)
2019-11-22T11:05:39.257974: [info   ] Listening on 0.0.0.0:237 (fd 7)
2019-11-22T11:05:39.257996: [info   ] Listening on [::]:237 (fd 8)
2019-11-22T11:05:39.278906: [debug  ] K-1562: changed owner "/var/run/kopano/prio.sock" to kopano:kopano mode 660
2019-11-22T11:05:39.278923: [info   ] Listening on unix:/var/run/kopano/prio.sock (fd 9)
2019-11-22T11:05:39.279061: [debug  ] K-1562: changed owner "/var/run/kopano/server.sock" to kopano:kopano mode 666
2019-11-22T11:05:39.279070: [info   ] Listening on unix:/var/run/kopano/server.sock (fd 10)
2019-11-22T11:05:39.279131: [notice ] Coredumps are disabled via configuration file.
2019-11-22T11:05:39.283812: [debug  ] Preparing relaunch with allocator lib libtcmalloc_minimal.so.4
2019-11-22T11:05:39.283874: [debug  ] Reexecing /usr/sbin/kopano-server
2019-11-22T11:05:39.310809: [info   ] Audit logging not enabled.
2019-11-22T11:05:39.310864: [=======] Starting kopano-server version 8.7.85 (pid 27299 uid 999)
2019-11-22T11:05:39.310900: [info   ] Using epoll events
2019-11-22T11:05:39.311067: [info   ] Re-using fd 5 for 0.0.0.0:236
2019-11-22T11:05:39.311081: [info   ] Re-using fd 6 for [::]:236
2019-11-22T11:05:39.311143: [info   ] Re-using fd 7 for 0.0.0.0:237
2019-11-22T11:05:39.311159: [info   ] Re-using fd 8 for [::]:237
2019-11-22T11:05:39.329205: [info   ] Re-using fd 9 for unix:/var/run/kopano/prio.sock
2019-11-22T11:05:39.329286: [info   ] Re-using fd 10 for unix:/var/run/kopano/server.sock
2019-11-22T11:05:39.329351: [notice ] Coredumps are disabled via configuration file.
2019-11-22T11:05:39.334210: [notice ] Connection to database 'kopano' succeeded
2019-11-22T11:05:39.340530: [info   ] Using the "files" attachment storage backend
2019-11-22T11:05:39.343261: [info   ] Setting object cache size: 16777216
2019-11-22T11:05:39.343275: [info   ] Setting quota cache size: 1048576
2019-11-22T11:05:39.343282: [info   ] Setting userdetails cache size: 26214400
2019-11-22T11:05:39.343307: [debug  ] PurgeCache 0xffffffff took 0 ms
2019-11-22T11:05:39.345725: [notice ] Querying database for searchfolders. This may take a while.
2019-11-22T11:05:39.345796: [notice ] Loading search folders.
2019-11-22T11:05:39.347300: [notice ] Done loading search folders.
2019-11-22T11:05:39.347382: [notice ] Startup succeeded on pid 27299
2019-11-22T11:05:39.859677: [debug  ] Accepted incoming connection from file:///var/run/kopano/server.sock

Now what i expect to be the problem, im not sure.

ps, i dont use apparmor myself , The debian apparmor profile :

/usr/share/doc/kopano/example-config/apparmor.d/usr.sbin.kopano-server

#include <tunables/global>

/usr/sbin/kopano-server flags=(attach_disconnected) {
  #include <abstractions/base>
  #include <abstractions/nameservice>
  #include <abstractions/user-tmp>
  #include <abstractions/mysql>
  #include <kopano-coredump.aa>

  capability chown,
  capability dac_override,
  capability dac_read_search,
  capability setgid,
  capability setuid,

  network tcp,

  /etc/kopano/debian-db.cfg r,
  /etc/kopano/server.cfg r,
  /usr/sbin/kopano-server r,

  @{PROC}/@{pid}/task/@{tid}/comm rw,

  /run/kopano/prio.sock rw,
  /run/kopano/server.pid rw,
  /run/kopano/server.sock rw,

  /usr/lib/kopano/*.so m,
  /usr/lib64/kopano/*.so m,
  /usr/lib/@{multiarch}/kopano/*.so m,

  /var/lib/kopano/attachments/ r,
  /var/lib/kopano/attachments/** rw,
  /var/log/kopano/server.log rw,

  /etc/kopano/userscripts/* Cxr -> kopano_userscripts,
  /usr/lib/kopano/userscripts/* Cxr -> kopano_userscripts,

  # There's little we can do if the server is allowed to run
  # arbitrary scripts
  profile kopano_userscripts flags=(attach_disconnected) {
    file,
    network,
  }
}

here i suggest the following change.

  /run/kopano/prio.sock rw,
  /run/kopano/server.pid rw,
  /run/kopano/server.sock rw,

to

/{,var/}run/kopano/prio.sock rw,
/{,var/}run/kopano/server.pid rw,
/{,var/}run/kopano/server.sock rw,

Good luck. above should fix it for you.

All i can say is without apparmor, my system runs great atm. ( debian 10 )

cblaha

@thctlo ,@jengelh : Thank you for the clues. AppArmor was the problem. This occurred after a Debian 10 update and had nothing to do with Kopano. I was just following the wrong track.