Guten Morgen,
ich betreibe für 5 User einen UCS Server mit den Paketen Zarafa (+ ZPush) und Owncloud. Alles auf aktuellem Stand. Der Server läuft sein ca. 3 Monaten bei Amazon AWS und eigentlich hatte ich nie wirkliche Probleme:
In den letzten Wochen kommt es täglich bis zu zwei mal vor, dass die Mobilgeräte sich nicht mehr authentifizieren können (Exchangedienste nicht verfügbar). Wenn ich dann auf den UCS sehe, kann ich die Management Oberfläche öffnen. In der Zarafa Webapp steht beim Anmelden “Zarafa Server not aviable” und Owncloud meldet nur eine Seite mit Server Fehler…
Nach einem Neustart das Servers funktionieren wieder alle Dienste.
Ich finde auch in den Log Dateien nichts (bzw. habe keinen Ansatz, woran es liegen kann). Über einen Hinweis wäre ich dankbar.
Seitdem diese “Aussetzer” auftreten, ist die Systemlast deutlich
Mit besten Grüßen
Alex Böhm
Moin,
Was genau meinen Sie mit »öffnen«? Können Sie sich auch in der UMC anmelden, z.B. als »administrator«?
Läuft in dem Moment ein Prozess namens »zarafa-server«? Dieser ist der zentrale Prozess von Zarafa, mit dem alle anderen Prozesse (z.B. »zarafa-gateway« für IMAP und POP3) und Interfaces (z.B. die WebApp) kommunizieren. Schauen Sie auch in die Logdatei /var/log/zarafa/server.log für Hinweise, was das Problem sein kann.
Schauen Sie in dem Moment in die Webserver-Fehler-Logs, also /var/log/apache2/error.log.
Deutlich… frühlinghafter? Flauschiger? Höher? 
LG,
mosu
Hi,
also, ich kann mich an der Management Oberfläche ganz normal anmelden (mit dem administrator), auch der ZarafaServer Prozess läuft
4726 root 20 0 357m 79m 0 S 0,3 8,0 0:44.19 zarafa-server
In der /zarafa/server.log sieht es schon anders aus…
Tue May 3 12:41:48 2016: [fatal ] ECDatabaseMySQL::DoSelect(): query failed
Tue May 3 12:41:48 2016: [fatal ] ECCacheManager::GetUserObject(): query failed 80000007
Tue May 3 12:41:48 2016: [fatal ] SQL [00000000] info: Try to reconnect
Tue May 3 12:41:48 2016: [fatal ] ECDatabaseMySQL::Connect(): mysql connect fail 80000007
Tue May 3 12:41:48 2016: [fatal ] ECDatabaseMySQL::DoSelect(): query failed
gleiches auch in der /apache2/error.log
[Tue May 03 12:32:45 2016] [error] [client 217.91.90.179] zarafa-webapp user: aboehm: authentication failure at MAPI, referer: https://url.de/webapp/
[Tue May 03 12:32:50 2016] [error] [client 217.91.90.179] zarafa-webapp user: aboehm: authentication failure at MAPI, referer: https://url.de/webapp/index.php?logo
In meinem letzten Satz hab ich irgendwo vergessen, das “höher” einzusetzen 
- Danke für den Hinweis.
Es scheint so, als ob der SQL Prozess oder vielleicht die Datenbank ein Problem hat…
ich habe ein top | grep mysql abgesetzt, aber da war kein Prozess mehr.
Mit bestem Gruß
Alex Böhm
Moin,
ja dann: die Logdateien von MySQL auswerten. MySQL schreibt oft nach /var/log/syslog, es gibt aber teilweise auch Logs in /var/log/mysql.
Gruß,
mosu
Hi,
die mysql logs sind alle leer… Nur in Syslog stehen die folgenden Zeilen (zu heute Mittag…)
May 3 12:15:56 ucs kernel: [15888.650195] [ 3173] 0 3173 1049 36 8 3 0 0 mysqld_safe
May 3 12:15:56 ucs kernel: [15888.650196] [ 3501] 114 3501 109353 27811 102 4 0 0 mysqld
May 3 12:15:56 ucs kernel: [15888.650304] Out of memory: Kill process 3501 (mysqld) score 109 or sacrifice child
May 3 12:15:56 ucs kernel: [15888.650307] Killed process 3501 (mysqld) total-vm:437412kB, anon-rss:111244kB, file-rss:0kB
May 3 12:15:56 ucs mysqld_safe: Number of processes running now: 0
May 3 12:15:56 ucs mysqld_safe: mysqld restarted
May 3 12:15:57 ucs mysqld: 160503 12:15:57 [Warning] Using unique option prefix key_buffer instead of key_buffer_size is deprecated and will be removed in a future release. Please use the full name instead.
May 3 12:15:57 ucs mysqld: 160503 12:15:57 [Note] /usr/sbin/mysqld (mysqld 5.5.46-0.17.201512141630) starting as process 1005 ...
May 3 12:15:57 ucs mysqld: 160503 12:15:57 [Warning] Using unique option prefix myisam-recover instead of myisam-recover-options is deprecated and will be removed in a future release. Please use the full name instead.
May 3 12:15:57 ucs mysqld: 160503 12:15:57 [Note] Plugin 'FEDERATED' is disabled.
May 3 12:15:57 ucs mysqld: 160503 12:15:57 InnoDB: The InnoDB memory heap is disabled
May 3 12:15:57 ucs mysqld: 160503 12:15:57 InnoDB: Mutexes and rw_locks use GCC atomic builtins
May 3 12:15:57 ucs mysqld: 160503 12:15:57 InnoDB: Compressed tables use zlib 1.2.7
May 3 12:15:57 ucs mysqld: 160503 12:15:57 InnoDB: Using Linux native AIO
May 3 12:15:57 ucs mysqld: 160503 12:15:57 InnoDB: Initializing buffer pool, size = 128.0M
May 3 12:15:57 ucs mysqld: InnoDB: mmap(137363456 bytes) failed; errno 12
May 3 12:15:57 ucs mysqld: 160503 12:15:57 InnoDB: Completed initialization of buffer pool
May 3 12:15:57 ucs mysqld: 160503 12:15:57 InnoDB: Fatal error: cannot allocate memory for the buffer pool
May 3 12:15:57 ucs mysqld: 160503 12:15:57 [ERROR] Plugin 'InnoDB' init function returned error.
May 3 12:15:57 ucs mysqld: 160503 12:15:57 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
May 3 12:15:57 ucs mysqld: 160503 12:15:57 [ERROR] Unknown/unsupported storage engine: InnoDB
May 3 12:15:57 ucs mysqld: 160503 12:15:57 [ERROR] Aborting
May 3 12:15:57 ucs mysqld:
May 3 12:15:57 ucs mysqld: 160503 12:15:57 [Note] /usr/sbin/mysqld: Shutdown complete
May 3 12:15:57 ucs mysqld:
May 3 12:15:57 ucs mysqld_safe: mysqld from pid file /var/run/mysqld/mysqld.pid ended
May 3 12:55:52 ucs mysqld_safe: Starting mysqld daemon with databases from /var/lib/mysql
May 3 12:55:52 ucs mysqld: 160503 12:55:52 [Warning] Using unique option prefix key_buffer instead of key_buffer_size is deprecated and will be removed in a future release. Please use the full name instead.
May 3 12:55:52 ucs mysqld: 160503 12:55:52 [Note] /usr/sbin/mysqld (mysqld 5.5.46-0.17.201512141630) starting as process 3497 ...
May 3 12:55:52 ucs mysqld: 160503 12:55:52 [Warning] Using unique option prefix myisam-recover instead of myisam-recover-options is deprecated and will be removed in a future release. Please use the full name instead.
May 3 12:55:52 ucs mysqld: 160503 12:55:52 [Note] Plugin 'FEDERATED' is disabled.
May 3 12:55:52 ucs mysqld: 160503 12:55:52 InnoDB: The InnoDB memory heap is disabled
May 3 12:55:52 ucs mysqld: 160503 12:55:52 InnoDB: Mutexes and rw_locks use GCC atomic builtins
May 3 12:55:52 ucs mysqld: 160503 12:55:52 InnoDB: Compressed tables use zlib 1.2.7
May 3 12:55:52 ucs mysqld: 160503 12:55:52 InnoDB: Using Linux native AIO
May 3 12:55:52 ucs mysqld: 160503 12:55:52 InnoDB: Initializing buffer pool, size = 128.0M
May 3 12:55:52 ucs mysqld: 160503 12:55:52 InnoDB: Completed initialization of buffer pool
May 3 12:55:52 ucs mysqld: 160503 12:55:52 InnoDB: highest supported file format is Barracuda.
May 3 12:55:52 ucs mysqld: InnoDB: Log scan progressed past the checkpoint lsn 2394973169
May 3 12:55:52 ucs mysqld: 160503 12:55:52 InnoDB: Database was not shut down normally!
May 3 12:55:52 ucs mysqld: InnoDB: Starting crash recovery.
May 3 12:55:52 ucs mysqld: InnoDB: Reading tablespace information from the .ibd files...
May 3 12:55:52 ucs mysqld: InnoDB: Restoring possible half-written data pages from the doublewrite
May 3 12:55:52 ucs mysqld: InnoDB: buffer...
May 3 12:55:52 ucs mysqld: InnoDB: Doing recovery: scanned up to log sequence number 2394973473
May 3 12:55:53 ucs mysqld: 160503 12:55:53 InnoDB: Starting an apply batch of log records to the database...
May 3 12:55:53 ucs mysqld: InnoDB: Progress in percents: 88 89 90 91 92 93 94 95 96 97 98 99
May 3 12:55:53 ucs mysqld: InnoDB: Apply batch completed
May 3 12:55:53 ucs mysqld: 160503 12:55:53 InnoDB: Waiting for the background threads to start
May 3 12:55:54 ucs mysqld: 160503 12:55:54 InnoDB: 5.5.46 started; log sequence number 2394973473
May 3 12:55:54 ucs mysqld: 160503 12:55:54 [Note] Server hostname (bind-address): '127.0.0.1'; port: 3306
May 3 12:55:54 ucs mysqld: 160503 12:55:54 [Note] - '127.0.0.1' resolves to '127.0.0.1';
May 3 12:55:54 ucs mysqld: 160503 12:55:54 [Note] Server socket created on IP: '127.0.0.1'.
May 3 12:55:54 ucs mysqld: 160503 12:55:54 [Note] Event Scheduler: Loaded 0 events
May 3 12:55:54 ucs mysqld: 160503 12:55:54 [Note] /usr/sbin/mysqld: ready for connections.
May 3 12:55:54 ucs mysqld: Version: '5.5.46-0.17.201512141630' socket: '/var/run/mysqld/mysqld.sock' port: 3306 (Univention)
May 3 12:55:54 ucs /etc/mysql/debian-start[3577]: Upgrading MySQL tables if necessary.
May 3 12:55:54 ucs /etc/mysql/debian-start[3581]: /usr/bin/mysql_upgrade: the '--basedir' option is always ignored
May 3 12:55:54 ucs /etc/mysql/debian-start[3581]: Looking for 'mysql' as: /usr/bin/mysql
May 3 12:55:54 ucs /etc/mysql/debian-start[3581]: Looking for 'mysqlcheck' as: /usr/bin/mysqlcheck
May 3 12:55:54 ucs /etc/mysql/debian-start[3581]: This installation of MySQL is already upgraded to 5.5.46, use --force if you still need to run mysql_upgrade
May 3 12:55:54 ucs /etc/mysql/debian-start[3599]: Checking for insecure root accounts.
May 3 12:55:54 ucs /etc/mysql/debian-start[3604]: Triggering myisam-recover for all MyISAM tables
May 3 12:55:54 ucs mysqld: 160503 12:55:54 [ERROR] /usr/sbin/mysqld: Table './mysql/proc' is marked as crashed and should be repaired
May 3 12:55:54 ucs mysqld: 160503 12:55:54 [Warning] Checking table: './mysql/proc'
May 3 12:59:38 ucs kernel: [ 280.741368] [ 3169] 0 3169 1049 37 8 3 0 0 mysqld_safe
May 3 12:59:38 ucs kernel: [ 280.741370] [ 3497] 114 3497 109126 15979 78 4 0 0 mysqld
Interessanter weise habe ich diverse Kernel Out of Memory Einträge…
root@ucs:~# cat /var/log/syslog | grep "Out of memory"
May 2 08:01:07 ucs kernel: [60967.183423] Out of memory: Kill process 5198 (apache2) score 102 or sacrifice child
May 2 11:05:25 ucs kernel: [ 504.322966] Out of memory: Kill process 3839 (clamd) score 329 or sacrifice child
May 2 12:08:13 ucs kernel: [ 4272.619291] Out of memory: Kill process 14953 (zarafa-dagent) score 171 or sacrifice child
May 2 13:18:12 ucs kernel: [ 8472.292940] Out of memory: Kill process 23356 (zarafa-dagent) score 147 or sacrifice child
May 2 14:28:14 ucs kernel: [12673.816510] Out of memory: Kill process 32546 (zarafa-dagent) score 129 or sacrifice child
May 2 15:38:14 ucs kernel: [16873.816441] Out of memory: Kill process 9770 (zarafa-dagent) score 127 or sacrifice child
May 2 15:38:14 ucs kernel: [16873.824688] Out of memory: Kill process 9777 (NotifyThread) score 127 or sacrifice child
May 2 15:38:14 ucs kernel: [16873.828621] Out of memory: Kill process 9777 (NotifyThread) score 127 or sacrifice child
May 2 16:48:13 ucs kernel: [21072.876887] Out of memory: Kill process 18481 (zarafa-dagent) score 128 or sacrifice child
May 2 17:58:21 ucs kernel: [25280.816433] Out of memory: Kill process 27913 (zarafa-dagent) score 120 or sacrifice child
May 2 17:58:21 ucs kernel: [25280.820491] Out of memory: Kill process 27917 (NotifyThread) score 121 or sacrifice child
May 2 19:08:13 ucs kernel: [29472.966274] Out of memory: Kill process 3501 (mysqld) score 104 or sacrifice child
May 2 19:08:13 ucs kernel: [29472.968395] Out of memory: Kill process 14281 (/usr/sbin/amavi) score 90 or sacrifice child
May 2 20:15:11 ucs kernel: [33490.401665] Out of memory: Kill process 4730 (zarafa-server) score 134 or sacrifice child
May 2 22:02:08 ucs kernel: [39907.728022] Out of memory: Kill process 12241 (/usr/sbin/amavi) score 89 or sacrifice child
May 2 22:02:19 ucs kernel: [39918.816791] Out of memory: Kill process 3139 (/usr/sbin/amavi) score 85 or sacrifice child
May 2 22:18:11 ucs kernel: [ 694.044335] Out of memory: Kill process 3835 (clamd) score 329 or sacrifice child
May 2 22:37:22 ucs kernel: [ 1844.439831] Out of memory: Kill process 4723 (zarafa-server) score 110 or sacrifice child
May 2 22:37:22 ucs kernel: [ 1844.445913] Out of memory: Kill process 4761 (NotificationMan) score 111 or sacrifice chil
May 3 07:57:19 ucs kernel: [ 371.816451] Out of memory: Kill process 3839 (clamd) score 329 or sacrifice child
May 3 12:15:56 ucs kernel: [15888.650304] Out of memory: Kill process 3501 (mysqld) score 109 or sacrifice child
May 3 12:59:38 ucs kernel: [ 280.741492] Out of memory: Kill process 3835 (clamd) score 329 or sacrifice child
Das würde ja bedeuten, dass der Speicher volläuft. Oder sehe ich das falsch?
Mit bestem Gruß
Alex Böhm
Moin,
ja, Ihre Programme wollen mehr Speicher benutzen, als Ihre Linux-Instanz zur Verfügung stellt. Entweder, Sie schränken den Speicherbedarf ein (weniger Apache-Prozesse starten, MySQL und Zarafa jeweils weniger Hauptspeicher füh ihre Caches zuordnen…), oder Sie nutzen eine größere Linux-Instanz. Ich rate stark zu »mehr Hauptspeicher«, denn nichts tötet Performance so zuverlässig, wie zu wenig Speicher zur Verfügung zu haben.
Gruß,
mosu
Vielen Dank!
Ich werde mal sehen, wie ich das einstellen kann. 
Bester Grüße
Alex Böhm
- Danke für den Hinweis.