タイトルが紛らわしくて恐縮だが、今回はコミュニティ版(旧)→コミュニティ版(新)のアップデート。
前回は「Ubuntu 18.04標準のリポジトリが提供するKopano」からコミュニティ版に乗り換えた。
アップグレードした日がよろしくなくて、php-mapiが大量のスパムログを出していたバージョンだったので、今日改めてアップデートしてみた。
11.0.2.43にアップグレードしたところ、php-mapiの問題は解消していたものの、kopano-searchがCPUを使い続ける問題が発生。
すべてのシステムで起きるわけではないようだけれども、うちの1つがあたってしまった…
Upgrade core 11.0.1.2 to 11.0.2.41 - High search cpu usage
仕方がないので、当面の間は systemctl disable kopano-search として、改善を待つことにした。2021/08/13追記
問題の修正が始まった模様。こちらの投稿に張られたリンクに修正方法が書かれており、これを適用したところ問題が解消。
Upgrade core 11.0.1.2 to 11.0.2.41 - High search cpu usage #20
当該のソースはこちらにあって、これを修正した後に kopano-search を起動したところ、数分でCPUが落ち着いた。
/usr/lib/python3/dist-packages/kopano_search/__init__.py
前回のような大幅アップデートではなかったので、思っていたよりも簡単にアップデートができた。
環境
Ubuntu 18.04にKopano(コミュニティ版)が入っていて、PostfixとApacheでサービス提供している。
Kopano(コミュニティ版)はCoreが11.0.1.101でphp-maipがスパムログを大量に出力するバージョン。
アップグレード
こちらから最新のコミュニティ版をダウンロードしてくる。
https://download.kopano.io/community/
Core
最新のパッケージをダウンロードしてきて展開、全てをdpkgでインストールするだけ。
この日のバージョンはcore-11.0.2.43.ba2c19f-Ubuntu_18.04-amd64.tar.gzだった。
途中で受けた質問は全てNで実行。
$ sudo dpkg -i *
Selecting previously unselected package gir1.2-ical-3.0:amd64.
(Reading database ... 156172 files and directories currently installed.)
Preparing to unpack gir1.2-ical-3.0_3.0.5-0+3.1_amd64.deb ...
…
Setting up libical3:amd64 (3.0.8+0kopano1-1+ubuntu18.04~4.1) ...
dpkg: dependency problems prevent configuration of libical-dev:amd64:
libical-dev:amd64 depends on libdb-dev; however:
Package libdb-dev is not installed.
dpkg: error processing package libical-dev:amd64 (--install):
dependency problems - leaving unconfigured
Setting up libical-doc (3.0.8+0kopano1-1+ubuntu18.04~4.1) ...
…
Configuration file '/etc/kopano/dagent.cfg'
==> Modified (by you or by a script) since installation.
==> Package distributor has shipped an updated version.
What would you like to do about it ? Your options are:
Y or I : install the package maintainer's version
N or O : keep your currently-installed version
D : show the differences between the versions
Z : start a shell to examine the situation
The default action is to keep your current version.
*** dagent.cfg (Y/I/N/O/D/Z) [default=N] ?
[何も入れずにEnterでNになった模様]
…
Processing triggers for libapache2-mod-php7.2 (7.2.24-0ubuntu0.18.04.8) ...
Errors were encountered while processing:
libical-dev:amd64
libical-dev:amd64のインストールで失敗した模様。
$ sudo apt --fix-broken install
これで、必要なパッケージがインストールされた。
この後、念を入れて以下を実行したが、特に何かが変わった様子はなかった。
$ sudo dpkg -i *
インストール中に /etc/kopano/dagent.cfg について、更新するかどうか聞かれたのだけれども…
よくみると色々変化はあって、メールヘッダーにSpam関連のものが足されていたりするのだが、無指定のままでもある程度は標準設定でサポートしてくれるのだろうし、動くのであればそのままでいいや…と割り切ることにした。
WebApp
こちらも最新のパッケージをダウンロードしてきて展開、全てをdpkgでインストールするだけ。
この日のバージョンはwebapp-6.0.0.55.d1aa779-Ubuntu_18.04-all.tar.gzだった。
途中で出てきたメッセージに従って、Apacheでリロードしている。
$ sudo dpkg -i * (Reading database ... 156340 files and directories currently installed.) Preparing to unpack kopano-webapp_6.0.0.55-1+2025.1_all.deb ... … Setting up whatsapp4deskapp (0.1+21.1) ... $ sudo systemctl reload apache2
動作確認
基本動作だけ確認した。
WebAppでログインできて、メールが見える。
Z-Push通じてメールが見える、カレンダーが見える。
Outlookでメールが見える、カレンダーが見える。
このあたりが動けば、恐らくは基本線は動いているから、後はどうにかなるだろう。
ログに出ている問題
ぱっと見は問題なく動作しているようなので、サーバーを再起動してログを確認した。
syslog
kopano-kapid
このようなログが出ていた。
Jul 31 18:04:12 enjoy kopano-kapid[1561]: level=warning msg="grapi: waiting for proxy rest*.sock files to appear" error="no proxy rest*.sock files found in socket-path" Jul 31 18:04:12 enjoy kopano-kapid[1561]: level=warning msg="grapi: waiting for proxy notify*.sock files to appear" error="no proxy notify*.sock files found in socket-path" Jul 31 18:04:17 enjoy kopano-kapid[1561]: level=warning msg="failed to initialize OIDC provider" error="Timeout (:0x105)" iss="https://localhost"
そもそも、kopano-kapidとはなんなのか…というと、HTTP API群で提供されるREST webサービスで、Kopano Meetなど次世代クライアントを使用する場合に必要、とされている。
エラーが発生していることはあまり良いことではないが、現時点では、WebAppとZ-Push飲みを利用しているので、このままにしておくことにした。
止めるならパッケージを削除するか、サービスを無効化しておけば良いだろう。
kopano-spamd
Junkフォルダにドラッグされたメッセージで、X-Spam=YESフラグが付いていないものについて、SpamAssassinのsa-learnコマンドで学習するという仕組みらしい。
Ubuntu Manpage: kopano-spamd
WebAppで見れば、Junk E-mailというフォルダがあって、Outlookでも迷惑メールフォルダとして認識している。
Outlookで迷惑メール指定したらそこに入ってるし、機能させておいた方が便利っぽい。
Jul 31 18:04:39 enjoy kopano-spamd[1461]: [error ] Logon to file:///var/run/kopano/server.sock: Remote side closed connection. Jul 31 18:04:39 enjoy kopano-spamd[1461]: [error ] HrLogon server "default:" user "SYSTEM": network error Jul 31 18:04:39 enjoy kopano-spamd[1461]: 2021-07-31T18:04:39.322: [WARNING ] spamd - could not connect to server at 'default:', retrying in 5 sec Jul 31 18:04:44 enjoy kopano-spamd[1461]: [error ] Logon to file:///var/run/kopano/server.sock: Remote side closed connection. Jul 31 18:04:44 enjoy kopano-spamd[1461]: [error ] HrLogon server "default:" user "SYSTEM": network error Jul 31 18:04:44 enjoy kopano-spamd[1461]: 2021-07-31T18:04:44.325: [WARNING ] spamd - could not connect to server at 'default:', retrying in 5 sec
この後、kopano-spamdのログは出力されておらず、サービスもactive(running)になっていることから、問題なし。
kopano-search
全ユーザーの全メッセージをインデックス化し、検索性能を大幅に向上させる機能。
Jul 31 18:04:39 enjoy kopano-search[1159]: [error ] Logon to file:///var/run/kopano/server.sock: Remote side closed connection. Jul 31 18:04:39 enjoy kopano-search[1159]: [error ] HrLogon server "default:" user "SYSTEM": network error Jul 31 18:04:39 enjoy kopano-search[1159]: 2021-07-31T18:04:39.323: [WARNING ] search - could not connect to server at 'default:', retrying in 5 sec Jul 31 18:04:44 enjoy kopano-search[1159]: [error ] Logon to file:///var/run/kopano/server.sock: Remote side closed connection. Jul 31 18:04:44 enjoy kopano-search[1159]: [error ] HrLogon server "default:" user "SYSTEM": network error Jul 31 18:04:44 enjoy kopano-search[1159]: 2021-07-31T18:04:44.329: [WARNING ] search - could not connect to server at 'default:', retrying in 5 sec
こちらも、この後kopano-searchのログは出力されておらず、 サービスもactive(running)になっていることから、問題なし。
php-mapi
前回、スパムログを出力していたモジュールだが、今回はそうしたログは出力されていない。
Jul 31 18:05:08 enjoy php-mapi[2812]: HrLogon server "default:" user "gmother": logon failed Jul 31 18:05:09 enjoy php-mapi[2811]: HrLogon server "default:" user "gmother": logon failed
このログは後述のserver.logで分析、問題なしと判断した。
/var/log/kopano配下のログ
server.log
こんなログが出ていた。
2021-07-31T18:04:49.237842: [=======] Starting kopano-server version 11.0.2 (pid 3067 uid 113) 2021-07-31T18:05:08.599781: [warning] LDAP (simple) bind on auth@hogeserver.hogeddns.jp failed: Can't contact LDAP server 2021-07-31T18:05:08.600015: [crit ] Cannot instantiate user plugin: Failure connecting any of the LDAP servers (0x00000000) 2021-07-31T18:05:08.600042: [crit ] Unable to instantiate user plugin 2021-07-31T18:05:08.600129: [warning] LDAP (simple) bind on auth@hogeserver.hogeddns.jp failed: Can't contact LDAP server 2021-07-31T18:05:08.600230: [crit ] Cannot instantiate user plugin: Failure connecting any of the LDAP servers (0x00000000) 2021-07-31T18:05:08.600247: [crit ] Unable to instantiate user plugin
他のログと違って、これはちょっと気になる。LDAPサーバーは他に立ててあって起動しているから。
syslogに出ていたログと照らし合わせると、同じ時間に gmother から接続要求があったようだ。
その後は問題なく接続に来ているので問題なしと判断した。
spooler.log
こんなログが出ていた。
2021-07-31T18:04:08.763889: [=======] Starting kopano-spooler version 11.0.2 (pid 1318 uid 0) 2021-07-31T18:04:09.036527: [error ] Use of Python (plugin_enabled=yes) forces process_model=fork 2021-07-31T18:04:09.056925: [=======] Starting kopano-spooler version 11.0.2 (pid 1318 uid 113) 2021-07-31T18:04:09.056992: [error ] Use of Python (plugin_enabled=yes) forces process_model=fork 2021-07-31T18:04:12.935379: [error ] [ 1318] Logon to file:///var/run/kopano/server.sock: Remote side closed connection. 2021-07-31T18:04:12.935448: [error ] [ 1318] HrLogon server "default:" user "SYSTEM": network error 2021-07-31T18:04:12.935463: [error ] [ 1318] Unable to open admin session: network error (80040115) 2021-07-31T18:04:12.935471: [warning] [ 1318] Server connection lost. Reconnecting in 3 seconds... … 2021-07-31T18:04:45.946666: [error ] [ 1318] Logon to file:///var/run/kopano/server.sock: Remote side closed connection. 2021-07-31T18:04:45.946754: [error ] [ 1318] HrLogon server "default:" user "SYSTEM": network error 2021-07-31T18:04:45.946800: [error ] [ 1318] Unable to open admin session: network error (80040115) ここでログは止まっていた。
起動時に色々出ているようだが、プロセスは起動しており、その後はこのログが出力されていないようなので問題なし。
dagent.log
こんなログが出ていた。
2021-07-31T18:04:08.764019: [=======] Starting kopano-dagent version 11.0.2 (pid 1223 uid 0) (LMTP mode) 2021-07-31T18:04:09.566249: [=======] Starting kopano-dagent version 11.0.2 (pid 1223 uid 113) (LMTP mode) 2021-07-31T18:05:21.358223: [ 4452] [error ] WARNING: setrlimit(RLIMIT_NOFILE, 8192) failed: Operation not permitted. You will only be able to connect up to 4096 sockets. Either start the process as root, or increase user limits for open file descriptors.
これは、ユニットファイルを修正して対応する模様。
kopano forum / dagent open file limit
システムの設定値を見ると…十分あるように思う。
$ cat /proc/sys/fs/file-max 805378
$ sudo systemctl edit kopano-dagent
[Service] LimitNOFILE=8192:16384
既に設定されている。これ以上の手は今のところ見つかっていないので、当面はこのままとする。
gateway.log
プロセス開始のログが出ていただけで、問題はないようだ。
2021-07-31T18:04:08.762835: [kopano-gateway|T1219] [=======] Starting kopano-gateway version 11.0.2 (pid 1219 uid 0) 2021-07-31T18:04:09.014603: [kopano-gateway|T1219] [=======] Starting kopano-gateway version 11.0.2 (pid 1219 uid 113)
search.log
何も出力されていない。プロセス開始のログはsyslogに出ていて、問題なし。
念のため、/etc/kopano/search.cfg でログレベルを5に変更して様子を見たが、開始ログも5で初めて出るくらいで、syslogで開始終了を知るような感じになっている。
ical.log
何も出力されていない。使っていないので問題なし。
monitor.log
何も出力されていない。プロセスの開始ログはsyslogに出ていて、問題なし。
/var/log/z-push配下のログ
z-push.log, z-push-error.log
再起動直後に gmother に関するエラーログが出ていたが、その後は問題なく動作している。
autodiscover.log, autodiscover-error.log
ログ出力はなく、問題なし。
さいごに
気になっていた大量のログが出力されなくなり、健全なシステム運営ができるようになった。
サブジェクトが長いと表示されるヘンテコな記号もなく、真に扱いやすいシステムになって嬉しい。
コメントはこちらから お気軽にどうぞ ～ 投稿に関するご意見・感想・他