MariaDB 5.5から10.6にアップデートして死にかけた件(utf8が無くなった)


CentOS7上で動いているMariaDB 5.5サーバをMariaDB 10.6にアップデートして死にかけた。

2022/10/28追記:この件に関するMariaDB公式のお知らせ的な物。どうやらold_mode を設定するらしい

データベースのアップデート自体は問題なかったのだが、アプリケーション側で問題発生。

/var/log/messages に下記の様なメッセージが多発

Jul 13 10:50:11 ホスト名 kernel: dict[23339]: segfault at a8 ip 00007f99c6fa9fa1 sp 00007ffc4641fe50 error 4 in libmysqlclient.so.18.0.0[7f99c6f4b000+320000]
Jul 13 10:50:11 ホスト名 mariadbd: 2021-07-13 10:50:11 7 [Warning] Aborted connection 7 to db: 'unconnected' user: 'unauthenticated' host: 'localhost' (This connection closed normally without authentication)
Jul 13 10:50:11 ホスト名 kernel: dict[23340]: segfault at a8 ip 00007f3950ee4fa1 sp 00007ffe8bec4f70 error 4 in libmysqlclient.so.18.0.0[7f3950e86000+320000]
Jul 13 10:50:11 ホスト名 kernel: dict[23341]: segfault at a8 ip 00007f89b3d8efa1 sp 00007ffed464d830 error 4 in libmysqlclient.so.18.0.0[7f89b3d30000+320000]
Jul 13 10:50:11 ホスト名 mariadbd: 2021-07-13 10:50:11 8 [Warning] Aborted connection 8 to db: 'unconnected' user: 'unauthenticated' host: 'localhost' (This connection closed normally without authentication)
Jul 13 10:50:33 ホスト名 kernel: auth[23362]: segfault at a8 ip 00007f197609dfa1 sp 00007ffe82dc98a0 error 4 in libmysqlclient.so.18.0.0[7f197603f000+320000]

authとdictでlibmysqlclient.so.18.0.0 のsegmentation faultが発生しているという・・・

で・・このauthとdictというのはdovecot/authとdovecot/dictで、そこで何か起こっているようだ

/var/log/dovecot/dovecot.log を見てみる

Jul 13 10:50:05 ホスト名1 dovecot: dict(23024): Error: mysql(127.0.0.1): Connect failed to database (vmail): Can't connect to MySQL s
erver on '127.0.0.1' (111 "Connection refused") - waiting for 5 seconds before retry
Jul 13 10:50:05 ホスト名1 dovecot: dict(23024): Error: mysql(127.0.0.1): Connect failed to database (vmail): Can't connect to MySQL s
erver on '127.0.0.1' (111 "Connection refused") - waiting for 5 seconds before retry
Jul 13 10:50:10 ホスト名1 dovecot: dict: Error: #007Character set 'utf8' is not a compiled character set and is not specified in the '/usr/share/mysql/charsets/Index.xml' file
Jul 13 10:50:10 ホスト名1 dovecot: dict(23024): Error: mysql(127.0.0.1): Connect failed to database (vmail): Can't initialize character set utf8 (path: /usr/share/mysql/charsets/) - waiting for 25 seconds before retry
Jul 13 10:50:10 ホスト名1 dovecot: dict: Error: #007Character set 'utf8' is not a compiled character set and is not specified in the '/usr/share/mysql/charsets/Index.xml' file
Jul 13 10:50:10 ホスト名1 dovecot: dict(23024): Error: mysql(127.0.0.1): Connect failed to database (vmail): Can't initialize character set utf8 (path: /usr/share/mysql/charsets/) - waiting for 25 seconds before retry
Jul 13 10:50:11 ホスト名1 dovecot: dict: Error: #007Character set 'utf8' is not a compiled character set and is not specified in the '/usr/share/mysql/charsets/Index.xml' file
Jul 13 10:50:11 ホスト名1 dovecot: dict(23338): Error: mysql(127.0.0.1): Connect failed to database (vmail): Can't initialize character set utf8 (path: /usr/share/mysql/charsets/) - waiting for 1 seconds before retry

mariadb 10.6で文字コード utf8の指定ができないというエラーなようだ。

/usr/share/mysql/charsets/ に utf8の定義があるか確認してみる

# ls -l /usr/share/mysql/charsets/
合計 236
-rw-r--r-- 1 root root 23531  7月  5 19:47 Index.xml
-rw-r--r-- 1 root root  1749  7月  5 19:47 README
-rw-r--r-- 1 root root  5526  7月  5 19:47 armscii8.xml
-rw-r--r-- 1 root root  5512  7月  5 19:47 ascii.xml
-rw-r--r-- 1 root root  8241  7月  5 19:47 cp1250.xml
-rw-r--r-- 1 root root  8365  7月  5 19:47 cp1251.xml
-rw-r--r-- 1 root root  5569  7月  5 19:47 cp1256.xml
-rw-r--r-- 1 root root  8902  7月  5 19:47 cp1257.xml
-rw-r--r-- 1 root root  5506  7月  5 19:47 cp850.xml
-rw-r--r-- 1 root root  5528  7月  5 19:47 cp852.xml
-rw-r--r-- 1 root root  5613  7月  5 19:47 cp866.xml
-rw-r--r-- 1 root root  6529  7月  5 19:47 dec8.xml
-rw-r--r-- 1 root root  5516  7月  5 19:47 geostd8.xml
-rw-r--r-- 1 root root  5728  7月  5 19:47 greek.xml
-rw-r--r-- 1 root root  5517  7月  5 19:47 hebrew.xml
-rw-r--r-- 1 root root  5502  7月  5 19:47 hp8.xml
-rw-r--r-- 1 root root  5529  7月  5 19:47 keybcs2.xml
-rw-r--r-- 1 root root  5510  7月  5 19:47 koi8r.xml
-rw-r--r-- 1 root root  6532  7月  5 19:47 koi8u.xml
-rw-r--r-- 1 root root  9816  7月  5 19:47 latin1.xml
-rw-r--r-- 1 root root  7238  7月  5 19:47 latin2.xml
-rw-r--r-- 1 root root  5515  7月  5 19:47 latin5.xml
-rw-r--r-- 1 root root  7438  7月  5 19:47 latin7.xml
-rw-r--r-- 1 root root  8047  7月  5 19:47 macce.xml
-rw-r--r-- 1 root root  8058  7月  5 19:47 macroman.xml
-rw-r--r-- 1 root root  6530  7月  5 19:47 swe7.xml
# grep utf8 /usr/share/mysql/charsets/Index.xml
<charset name="utf8mb3">
  <collation name="utf8mb3_general_ci"  id="33">
  <collation name="utf8mb3_bin"         id="83">
#

なんと無い。

/usr/share/mysql/charsets/Index.xml のutf8関連記述を見てみる

<charset name="utf8mb3">
  <family>Unicode</family>
  <description>UTF-8 Unicode</description>
  <alias>utf-8</alias>
  <collation name="utf8mb3_general_ci"  id="33">
   <flag>primary</flag>
   <flag>compiled</flag>
  </collation>
  <collation name="utf8mb3_bin"         id="83">
    <flag>binary</flag>
    <flag>compiled</flag>
  </collation>
</charset>

おやぁ???

以前mariadb 10.5にアップデートしたサーバの/usr/share/mysql/charsets/Index.xmlの該当箇所と比較すると、いままでは utf8だったエントリが utf8mb3 に置き換わっているようだ。

<charset name="utf8">
  <family>Unicode</family>
  <description>UTF-8 Unicode</description>
  <alias>utf-8</alias>
  <collation name="utf8_general_ci"     id="33">
   <flag>primary</flag>
   <flag>compiled</flag>
  </collation>
  <collation name="utf8_bin"            id="83">
    <flag>binary</flag>
    <flag>compiled</flag>
  </collation>
</charset>

で・・・ /etc/my.cnf の設定で言語に関する設定は下記の様になっていた

[mysqld]
<略>
# character-set-server に関する値は未設定
<略>
[client]
default-character-set=utf8

クライアントからのアクセス時のデフォルトがutf8と設定されていた。

そこで/etc/my.cnf の文字コード指定を utf8mb3 に変更

[mysqld]
<略>
character-set-server=utf8mb3
<略>
[client]
default-character-set=utf8mb3

これで接続できない、という事象はなくなった。

なくなったが、/var/log/messages には下記のメッセージが出続けている。

Jul 13 13:10:01 ホスト名 mariadbd: 2021-07-13 13:10:01 925 [Warning] Aborted connection 925 to db: 'unconnected' user: 'unauthenticated' host: 'localhost' (This connection closed normally without authentication)
Jul 13 13:10:02 ホスト名 mariadbd: 2021-07-13 13:10:02 934 [Warning] Aborted connection 934 to db: 'unconnected' user: 'unauthenticated' host: 'localhost' (This connection closed normally without authentication)
Jul 13 13:10:06 ホスト名 mariadbd: 2021-07-13 13:10:06 935 [Warning] Aborted connection 935 to db: 'unconnected' user: 'unauthenticated' host: 'localhost' (This connection closed normally without authentication)
Jul 13 13:10:06 ホスト名 mariadbd: 2021-07-13 13:10:06 936 [Warning] Aborted connection 936 to db: 'unconnected' user: 'unauthenticated' host: 'localhost' (This connection closed normally without authentication)
Jul 13 13:10:22 ホスト名 mariadbd: 2021-07-13 13:10:22 811 [Warning] Aborted connection 811 to db: 'amavisd' user: 'amavisd' host: 'localhost' (Got timeout reading communication packets)
Jul 13 13:11:01 ホスト名 mariadbd: 2021-07-13 13:11:01 786 [Warning] Aborted connection 786 to db: 'amavisd' user: 'amavisd' host: 'localhost' (Got timeout reading communication packets)
Jul 13 13:12:26 ホスト名 mariadbd: 2021-07-13 13:12:26 839 [Warning] Aborted connection 839 to db: 'amavisd' user: 'amavisd' host: 'localhost' (Got timeout reading communication packets)
Jul 13 13:12:26 ホスト名 mariadbd: 2021-07-13 13:12:26 828 [Warning] Aborted connection 828 to db: 'amavisd' user: 'amavisd' host: 'localhost' (Got timeout reading communication packets)

iRedMailフォーラム「mysqld [Warning] Aborted connection」によると、ログレベル下げろ、とのこと

mysqlを起動しようとしたら問題が・・・

# mysql -u root
ERROR 2019 (00000): Can't initialize character set utf8mb3 (path: compiled_in)
#

とりあえず /etc/my.cnf の最後に下記を追加

[mysql]
default-character-set=utf8

警告はでるのもの操作は可能(なお、default-character-set=utf8mb3 だと起動できなかった)

# mysql -u root
mysql: Warning: Charset id '33' csname 'utf8mb3' trying to replace existing csname 'utf8'
mysql: Warning: Charset id '83' csname 'utf8mb3' trying to replace existing csname 'utf8'
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 1103
Server version: 10.6.3-MariaDB-log MariaDB Server

Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MariaDB [(none)]>

起動したのでフォーラムにあった設定を入れる。

MariaDB [(none)]> show global variables like '%log_warnings%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_warnings  | 2     |
+---------------+-------+
1 row in set (0.002 sec)

MariaDB [(none)]> set global log_warnings=1;
Query OK, 0 rows affected (0.000 sec)

MariaDB [(none)]> show global variables like '%log_warnings%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_warnings  | 1     |
+---------------+-------+
1 row in set (0.002 sec)

MariaDB [(none)]> quit
Bye
#

しばらく放置・・・

Jul 13 13:40:01 ホスト名 mariadbd: 2021-07-13 13:40:01 313 [Warning] Aborted connection 313 to db: 'unconnected' user: 'unauthenticated' host: 'localhost' (This connection closed normally without authentication)
Jul 13 13:40:02 ホスト名 mariadbd: 2021-07-13 13:40:02 314 [Warning] Aborted connection 314 to db: 'unconnected' user: 'unauthenticated' host: 'localhost' (This connection closed normally without authentication)
Jul 13 13:40:04 ホスト名 mariadbd: 2021-07-13 13:40:04 315 [Warning] Aborted connection 315 to db: 'unconnected' user: 'unauthenticated' host: 'localhost' (This connection closed normally without authentication)
Jul 13 13:42:53 ホスト名 mariadbd: 2021-07-13 13:42:53 359 [Warning] Aborted connection 359 to db: 'vmail' user: 'vmail' host: 'localhost' (Got an error reading communication packets)
Jul 13 13:42:53 ホスト名 mariadbd: 2021-07-13 13:42:53 352 [Warning] Aborted connection 352 to db: 'vmail' user: 'vmail' host: 'localhost' (Got an error reading communication packets)
Jul 13 13:42:53 ホスト名 mariadbd: 2021-07-13 13:42:53 357 [Warning] Aborted connection 357 to db: 'vmail' user: 'vmail' host: 'localhost' (Got an error reading communication packets)
Jul 13 13:42:53 ホスト名 mariadbd: 2021-07-13 13:42:53 351 [Warning] Aborted connection 351 to db: 'vmail' user: 'vmail' host: 'localhost' (Got an error reading communication packets)

うーん?

あれ?反映されてない

# mysql -u root
mysql: Warning: Charset id '33' csname 'utf8mb3' trying to replace existing csname 'utf8'
mysql: Warning: Charset id '83' csname 'utf8mb3' trying to replace existing csname 'utf8'
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 474
Server version: 10.6.3-MariaDB-log MariaDB Server

Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MariaDB [(none)]> show global variables like '%log_warnings%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_warnings  | 2     |
+---------------+-------+
1 row in set (0.002 sec)

MariaDB [(none)]> set global log_warnings=1;
Query OK, 0 rows aff
MariaDB [(none)]>

なんだろ?とりあえず再設定・・・

今度は大丈夫か?

…2時間経過

大丈夫そうだな


2021/07/15追記

注:下記はmariadbのserverとclientのバージョンが違っていたことによる問題でなので参考情報です

iredmailでは/usr/local/bin/fail2ban_banned_dbがcronにより毎分実行されているのだが、これがmysqlコマンドを使ってデータベース操作をしているようで、下記のメールが届くようになってしまった・・・

mysql: Warning: Charset id '33' csname 'utf8mb3' trying to replace existing csname 'utf8'
mysql: Warning: Charset id '83' csname 'utf8mb3' trying to replace existing csname 'utf8'

mysqlコマンドを実行した際のメッセージをなんとしてでも消さなければならないようだ。

utf8がutf8mb3になった変更について「MariaDB Server/MDEV-8334/Rename utf8 to utf8mb3

MariaDBの「OLD_MODE」という設定

# mysql -u root
mysql: Warning: Charset id '33' csname 'utf8mb3' trying to replace existing csname 'utf8'
mysql: Warning: Charset id '83' csname 'utf8mb3' trying to replace existing csname 'utf8'
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 38510
Server version: 10.6.3-MariaDB-log MariaDB Server

Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MariaDB [(none)]> SELECT REPLACE(@@OLD_MODE, ',', '\n');
+--------------------------------+
| REPLACE(@@OLD_MODE, ',', '\n') |
+--------------------------------+
| UTF8_IS_UTF8MB3                |
+--------------------------------+
1 row in set (0.023 sec)

MariaDB [(none)]>

現状は「UTF8_IS_UTF8MB3」が設定されているので、UTF8=UTF8MB3扱いになるらしいが、設定されていない場合は「UTF8=UTF8MB4」となるそうな。

だったら、「utf8」でアクセスした場合でも勝手に読み替えて欲しいもんなんだけど、どうなっているのか???

MariaDB [(none)]> show variables like 'char%';
+--------------------------+----------------------------+
| Variable_name            | Value                      |
+--------------------------+----------------------------+
| character_set_client     | utf8mb3                    |
| character_set_connection | utf8mb3                    |
| character_set_database   | utf8mb3                    |
| character_set_filesystem | binary                     |
| character_set_results    | utf8mb3                    |
| character_set_server     | utf8mb3                    |
| character_set_system     | utf8mb3                    |
| character_sets_dir       | /usr/share/mysql/charsets/ |
+--------------------------+----------------------------+
8 rows in set (0.002 sec)

MariaDB [(none)]>
MariaDB [(none)]> show global variables like '%character_set%';
+--------------------------+----------------------------+
| Variable_name            | Value                      |
+--------------------------+----------------------------+
| character_set_client     | utf8mb3                    |
| character_set_connection | utf8mb3                    |
| character_set_database   | utf8mb3                    |
| character_set_filesystem | binary                     |
| character_set_results    | utf8mb3                    |
| character_set_server     | utf8mb3                    |
| character_set_system     | utf8mb3                    |
| character_sets_dir       | /usr/share/mysql/charsets/ |
+--------------------------+----------------------------+
8 rows in set (0.002 sec)

MariaDB [(none)]> show global variables like 'collation%';
+----------------------+--------------------+
| Variable_name        | Value              |
+----------------------+--------------------+
| collation_connection | utf8mb3_general_ci |
| collation_database   | utf8mb3_general_ci |
| collation_server     | utf8mb3_general_ci |
+----------------------+--------------------+
3 rows in set (0.002 sec)

MariaDB [(none)]>

ん?????

トラブル生じた時に、MariaDB10.5にしなかったっけ?と

# rpm -qa | grep MariaDB
MariaDB-client-10.5.11-1.el7.centos.x86_64
MariaDB-compat-10.6.3-1.el7.centos.x86_64
MariaDB-common-10.6.3-1.el7.centos.x86_64
MariaDB-server-10.6.3-1.el7.centos.x86_64
#

あー・・・MariaDB-clientとMariaDB-serverのバージョンがずれていました。

そんなわけで、MariaDB-clientの方も 10.6.3に揃えて再実行

# mysql -u root
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 405
Server version: 10.6.3-MariaDB-log MariaDB Server

Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MariaDB [(none)]> exit
Bye
#

というわけで、解決しました。

Windows Live メール 2012で「メッセージを表示できませんでした」となる


注: 必要な作業は「レジストリを設定してOS再起動」です。Liveメールの設定を確認する必要はありません。設定確認はきちんとした原因調査したい場合に行う操作です。

2020/12/23追記

2020年5月リリースのWindows 10 20H2適用後、「0x800c013e 不明なエラー」というエラーで使えなくなる、という件が発生しているようで来訪が多い。

うちのテスト用Windows10はこの記事を書いた10月時点ですでにWindows 10 20H2になっており「0x800c013e 不明なエラー」が発生していました。

そこで、このページのレジストリ設定を行ったところ、Windows Liveメール2012を使ったメール送受信は可能となりました。2020/12/23時点でもIMAP/POP3メール受信,SMTPメール送信ともに出来ています。

また、エラーがでたのでメールアカウントの再設定などを試そうとしている場合の注意点があります。

Windows Liveメールはサポートが切れて数年経ちますので、各メールサーバの設定案内で記述が削除されており、他のメールソフトの設定ページにある設定を利用しているのではないかと思います。

しかし、Windows Liveメールで使えるメールサーバ設定は10年以上前のメールサーバ用の設定であり、2020年のメールサーバが備えてる設定ではアクセスができないものがあります。

詳細については「Windows Liveメール2012で使えるメールサーバ設定」を見てください。

追記終了


メールサーバを管理しているといろんなユーザがいるわけです。

とっくにサポートが切れたWindows Live メール 2012をWindows10上で使っている人、とかね。

そんな人からの問い合わせに対応するために検証用Windows10にWindows Live メールをセットアップしてみたら、メールが表示されない。

「メッセージを表示出来ませんでした」ってなんだ?

いろいろ調査してみると、[オプション]-[メール]-[詳細設定]の「メンテナンス」でどんな状態にあるか確認できるらしい(注:これは調査のための操作なので、特にやる必要はありません)

これの「トラブルシューティング」の「全般」と「メール」にチェックを入れて、「保存先フォルダー」に書かれたディレクトリにあるWindowsLiveMail.log にログが出力されるようになる。

受信トレイのメールをクリックしてみると下記の様な「Zone_MailChk ERROR: (storutil.cpp:3965), failed with 0x800C013E」などのエラーが出力される。

[15:11:00.34] 4138                 Mail:            Zone_MailChk ERROR: (msgfldr.cpp:2741), failed with 0x800C013E  
[15:11:00.34] 4138                 Mail:            Zone_MailChk ERROR: (msgfldr.cpp:905), failed with 0x800C013E  
[15:11:00.34] 4138                 Mail:            Zone_MailChk ERROR: (storutil.cpp:3965), failed with 0x800C013E  

この情報を元に検索したところ、2020/08/26付けの「Windows Live Mail」というマイクロソフトコミュニティの書き込みを発見。

レジストリエディッタで「HKEY_CURRENT_USER\SOFTWARE\Microsoft\Windows Live Mail」直下にDWORD(32bit)で3つのキーを値「1」で新規作成して、Windowsを再起動してWindows Liveメールを開き直すとメッセージが読めるようになる、と。

作成するDWORDキー
  RecreateFolderIndex
  RecreateStreamIndex
  RecreateUIDLIndex

(該当する3つのキーの値は1回Windows Liveメールを起動することで「0」に戻ります)

この手順を実施したところ、ちゃんとメッセージが読めるようになりました。

Outlook2019で iredmail(postfix/dovecot)環境を登録しようとするとエラーになる


Becky!やThunderbird、Windows Live 2012では問題なく動いていたのだが、Outlook 2019(およびOffice 365のOutlook)に対してメールを新規登録した場合、うまく動かない、というクレームがあったので調査

姉妹記事:「Windows Liveメール2012で使えるメールサーバ設定」Outlookについての言及もあり

要点

その1: SSL対応するならちゃんとすること

自己署名SSLや、メールサーバとして指定したホスト名がSSL証明書に含まれていないとエラーになる。

Let’s Encryptでやっても良いが、POP3/IMAP/SMTPサーバ名でSSL証明書が発行されていること。

その2: Outlook側の「ユーザー情報」の「名前」が空欄は不許可

ここが空欄になっていると、メール送信がエラー(エラーコード 0x800c8101) になる。

成功例:IMAP設定の場合

上記では送信サーバ(SMTP)のポートが「587」となっているが、プロバイダ側で許可されている場合はポート25でも良い。

成功例:POP3の場合

上記では送信サーバ(SMTP)のポートが「587」となっているが、プロバイダ側で許可されている場合はポート25でも良い。


エラーログ集

SMTPサーバ指定を暗号化なしに設定した場合

使用する暗号化接続の種類を「なし」に設定した場合、エラーになった

Outlook側エラー「テスト電子メール メッセージの送信: このクライアントでサポートされている認証方法が、サーバーでサポートされていません。」

サーバ側のmaillog出力

Oct 13 10:41:28 mailserver postfix/submission/smtpd[16308]: connect from test.example.com[xxx.xxx.xxx.xxx]
Oct 13 10:41:28 mailserver postfix/submission/smtpd[16308]: lost connection after EHLO from test.example.com[xxx.xxx.xxx.xxx]
Oct 13 10:41:28 mailserver postfix/submission/smtpd[16308]: disconnect from test.example.com[xxx.xxx.xxx.xxx]

SMTPサーバ指定をSSL/TLSに設定した場合

送信サーバの使用する暗号化接続の種類を「SSL/TLS」に設定した場合もエラーになった。

Outlook側のエラーメッセージ

テスト電子メール メッセージの送信: このサーバーは、指定した種類の接続暗号化をサポートしていません。暗号化方式を変更してください。詳細については、メール サーバーの管理者かインターネット サービス プロバイダー (ISP) に問い合わせてください。

メールサーバ側maillogのエラーメッセージ

Oct 13 10:46:34 mailserver postfix/submission/smtpd[18081]: connect from test.example.com[xxx.xxx.xxx.xxx]
Oct 13 10:46:34 mailserver postfix/submission/smtpd[18081]: lost connection after UNKNOWN from test.example.com[xxx.xxx.xxx.xxx]
Oct 13 10:46:34 mailserver postfix/submission/smtpd[18081]: disconnect from test.example.com[xxx.xxx.xxx.xxx]

存在しないポートを指定した場合

誤って不適切なポートを指定した場合、下記の様なエラーとなります。

テスト電子メール メッセージの送信: 送信 (SMTP) メール サーバーに接続できません。このメッセージを引き続き受信する場合は、サーバー管理者かインターネット サービス プロバイダー (ISP) に問い合わせてください。

iredmail運用メモ 2021/09/09版


2019/12/06版:新規作成
2021/09/09版:更新


2021/09/09版前書き

2019年7月ぐらいから postfix+dovecot+iredmail環境の運用を開始し、2年が経過しました。

追加1:salesforce.comからのメールに対するgreylist適用取りやめ

salesforce.comからのメールは「23sadf984tasd.49fv2fdsdf.k54hsd74.ap23.bnc.salesforce.com」というような差し出しアドレスで送信されており、このアドレスはユーザごとに違うらしいようで、自動処理がうまくできませんでした。

調べて見るとiredmailフォーラム「How do I whitelist this sender?」にて、「python2 greylisting_admin.py –disable –from @.salesforce.com を実行してgreylist対象外にしろ」という回答が・・・

[root@mailserver ~]# /opt/iredapd/tools/greylisting_admin.py --disable --from @.salesforce.com
* Disable greylisting: @.salesforce.com -> @.
[root@mailserver ~]#

これで、salesforce.comからのメールは全て届くようになりました。

追加2:特定IPアドレスから送信されるメールの取り扱い

ユーザが開設しているウェブにあるフォームから送られてくるメールの送信者設定がうまく調整できないらしく、不適切なもので送信されてくる。

仕方が無いので、そのウェブサーバのIPアドレスから送られてくるメールへのgreylist適用をやめた

[root@mailserver ~]# /opt/iredapd/tools/greylisting_admin.py --disable --from  1xx.2xxx.1xx.1xxx
* Disable greylisting: 1xx.2xxx.1xx.1xxx -> @.
[root@mailserver ~]#


2019/12/06版前書き

qmail+vpopmailの環境からpostfix+dovecot+iredmail環境にテスト移行してもうすぐ1年、本稼働させて5ヶ月経ちました。

いろいろ行った対処についてのまとめです。

その1: Windows Live Mail 2012ユーザがいる場合の問題

iredmailの標準設定ではWindows Live Mail 2012でのPOP3アクセスによるメール受信に失敗します。原因はWindows Live Mail 2012はSSL無し+メールパスワードを平文で送ってしまうが、iredmail側では平文拒否+SSLのみ受付、という設定であるため拒否されているためです。

また、メール送信時も、Windows Live Mail 2012がメールサーバに送るホスト名情報(HELOコマンド)がiredmailが期待する書式になっていないために拒否されます。

この2点を解消するためにdovecotの設定と、postfixの設定を変更する必要があります。詳細は下記を参照のこと。

詳細:[postfix/dovecotメールサーバでWindows Live Mail 2012がエラーになる]

その2: WebメールのRoundcubeをアップデートする場合の問題

iredmailではWebメールとしてRoundcubeSOGoを利用できます。

SOGoはRPM提供なのでアップデートは簡単ですが、Roundcubeはphpコマンドを利用してのアップデートとなっています。

しかし、iredmail標準設定ではセキュリティ強化のphp設定がされているため、Roundcubeのアップデートスクリプトが必要とするphpの機能が使用できない状態となっています。

phpの設定を変更せずにroundcubeのアップデートスクリプトを実行するには下記を参照してください。

詳細:[php.iniを変更せずにdisable_functionsの内容を無効化してroundcubeのアップグレードスクリプトを動作させる方法]

その3: 自サーバ以外で送信されたメールが受信拒否になる問題

iredmail標準設定では、iredmailサーバ以外から送信された自ドメインメールを受信拒否します。

これは、iredapdの機能で拒否しています。

iredapdの設定にSPFレコードに登録されているサーバからの送信であれば許可する、という設定があるのでそれを有効にして回避します。

詳細:[postfixを使用したiredmailで他サーバで送信された自ドメインメールが受信拒否される]

その4: Barracudacentralがメールを拒否しすぎる問題

本格運用しはじめてからログを確認してみると、BarracudacentralのSPAMデータベースを参照にしたメール受信拒否率がとても高いことが判明。

ちょっとでも疑われたら登録されているレベルのようなので誤爆率がかなり高い。特に中小企業からのメールと(ちゃんとした)メルマガ系での拒否率が高すぎた。

このため、うちのサイトの運用ではbarracudacentralの使用はやめて、spamhaus.orgのみの運用にしている。

[iRedMailの初期設定から変えたところ 2018/08/21版]

その5: mail.goo.ne.jpメールが拒否される問題

iredmailが用意している/etc/postfix/helo_access.pcreを見てみると、なんとmail.goo.ne.jpメールが明示的に拒否されていた。

いったい過去に何をやらかしたのか・・・と驚愕しつつも受信できるように設定変更している。

[iRedMailの初期設定から変えたところ 2018/08/21版]

その6: ホスト名にIPアドレスっぽい文字列が入っていると拒否される問題

SPAMを送信してくるIPアドレスについてホスト名を調べて見るとIPアドレスっぽいホスト名( network-192-168.0.100.ぷろばいだ.ne.jp )であることが多い。

このため、iredmail標準設定ではこういったホスト名からのメールは拒否しているが、拒否ログを確認してみると、Amazon AWSサービスを使っているところからのメールが結構そんな感じのホスト名で送られていて、拒否率も高かった。

このため、IPアドレスっぽいホスト名からのメールは拒否、という設定を外した。

[iRedMailの初期設定から変えたところ 2018/08/21版]

その7: メールがすぐに届かず30分程度遅延する問題

SPAMメールの送信システムは再送処理は行わず、送信できなかったらすぐに次を送るような実装になっていることが多い。

このため、iredmailでは1回目の送信処理では、今忙しいからあとでもう1回送って、と返して、15分後から受信するようになっている。

しかし、分かっているドメインからのメールだったらすぐに受信できるようにしたい、という場合はwhitelistdomainを設定することで、該当するドメインでDNSのSPFレコードに登録されているメールサーバからのメールであればすぐに受信する、という設定を行っている。

[iRedMailの初期設定から変えたところ 2018/08/21版]

その6: vpopmailからユーザパスワードを移行した場合の問題点

これは該当する人があまりいないと思いますが、vpopmailで使っていたパスワード文字列(MD5エンコード)をそのままiredmailに持ってくると、dovecotとpostfixでは使えます。

しかし、SOGoとiredmailの管理画面ではSHA256エンコードであると想定した処理となっているため使えず、ログインできません。

これはどうしようもないので、パスワードを再設定してください。

[ユーザバックエンドがSQLのiredmailのSOGoでユーザがログインできない]

RoundcubeでUID THREAD Internal error occurredが出た


iRedmailによる統合メールサーバ環境でRoundcubeによるWebメール機能を使っていたら、一部のアカウントで「UID THREAD : Internal error occurred」といったエラーがでた。

iRedmail環境ではRoundcubeのログ、というより、IMAPアクセス時のログを追う感じで調査する必要があり、該当のログは /var/log/dovecot/imap.log にあった。

Jul 25 09:34:29 サーバホスト名 dovecot: imap-login: Login: user=<メールアドレス>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=19537, secured, session=
Jul 25 09:34:29 サーバホスト名 dovecot: imap(メールアドレス): Logged out in=60 out=804
Jul 25 09:34:31 サーバホスト名 dovecot: imap-login: Login: user=<メールアドレス>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=19541, secured, session=<9T/TlnaOYtB/AAAB>
Jul 25 09:34:31 サーバホスト名 dovecot: imap(メールアドレス): Error: open(/var/vmail/vmail1/ドメイン名/a/c/c/account//Maildir/cur/1549258275.M236704P2463.サーバホスト名,S=5291,W=5417:2,) failed: Permission denied (euid=150(vmail) egid=2000(vmail) missing +r perm: /var/vmail/vmail1/ドメイン名/a/c/c/account//Maildir/cur/1549258275.M236704P2463.サーバホスト名,S=5291,W=5417:2,)
Jul 25 09:34:31 サーバホスト名 dovecot: imap(メールアドレス): Logged out in=94 out=1035

えーと・・・

[root@ホスト名 ~]# ls -l /var/vmail/vmail1/ドメイン名/a/c/c/account//Maildir/cur/1549258275*
-rw------- 1 root root 5291  2月  4 14:35 /var/vmail/vmail1/ドメイン名/a/c/c/account//Maildir/cur/1549258275.M236704P2463.サーバホスト名,S=5291,W=5417:2,
[root@ホスト名 ~]#

なんでだろう???

とりあえずchownでvmail:vmailに変えて解決しました。