Ubuntu 20.04でAsteriskからmsmtpでメールを送信できない

echo test | sudo -u asterisk strace sendmail hogehoge@hogehoge.com

上記のようなコマンドを実行したら、次のような結果になった。

newfstatat(AT_FDCWD, “/var/lib/asterisk/.msmtprc”, {st_mode=S_IFREG|0600, st_size=170, …}, 0) = 0
geteuid() = 112
openat(AT_FDCWD, “/var/lib/asterisk/.msmtprc”, O_RDONLY) = -1 EACCES (Permission denied)

しかし、パーミッションは600で何も問題がない。

SELinuxは入っていないっぽいし、何故だと思いつつ、調べてみたら、UbuntuにはAppArmorというものが入っているらしい。

/etc/apparmor.d/usr.bin.msmtpを開いてみたら、owner @{HOME}/.msmtp*, rという行があった。これを参考にして owner /owner/var/lib/asterisk/.msmtp*, r を追加した。

追加されたら、sudo apparmor_parser -r /etc/apparmor.d/usr.bin.msmtpを実行して反映させる。

これで、Asteriskだけ別のアカウントを使ってメールが送信できるようになった。

AsteriskでFAX送信

https://www.northwind.mydns.jp/samples/blog/?p=1732

上記サイトに従ってFAX送信を試みた。

次のようなエラーが/var/log/asterisk/messagesに流れてきて送信できなかった。

[Apr 22 20:46:58] ERROR[508][C-00000006] res_fax.c: access failure.  Verify '/tmp/foo2.tif' exists and check permissions.

これは原因がよくわかっていないが、/var/spool/asterisk/tmp/にtiffファイルを置くことで解決した。

進んだのは良いが、今度は次のような警告が出て、結局FAXが送れなかった。

[Apr 22 21:06:02] WARNING[639][C-0000000b]: res_fax_spandsp.c:438 spandsp_log: WARNING T.30 Cannot open source TIFF file '/var/spool/asterisk/tmp/foo.tif'

これは、こちらのサイトに書かれている情報に従って
convert -compress fax -monochrome -units pixelsperinch -resample 204x98 filea.pdf filea4.tif を実行して変換したら進んだ。

stretchからbusterにしたらWordPressが壊れた?

Google Analytics的な所から500でblogが見ることができないエラーの警告が出ていたので対応した。

お使いのサーバーの PHP では WordPress に必要な MySQL 拡張を利用できないようです。

上記のようなエラーメッセージが表示されていた。

php-mysqlをインストールしたが解決されず。結局、apt autoremove php7.0で古いPHPを消してapt install php7.3で最新のPHPを入れることで解決した。どうもphp7.3用のphp-mysqlモジュールが入っているのにphp7.0で動いていたので読み込まれなかったようだ。

GCPでstretchをbusterに上げたらSSH鍵が転送されなくなった

久しぶりに投稿する。何とかフルタイムの仕事が見つかって、忙しい日々を送っている。

さて、Debian busterが出て結構経っているので、上げた。そして、久しぶりにCloud Consoleから入ろうとした。

プロジェクト メタデータへの鍵転送に異常に長い時間がかかっています。インスタンス メタデータに転送する方が所要時間は短くなる可能性がありますが、鍵が転送されるのはこの VM のみになります。この仮想マシンから他の仮想マシンに SSH 接続する場合は、鍵を適切に転送する必要があります。

上記のようなエラーが出ていくら待っても入れなかった。シリアルコンソールを利用するという手段もあるが、なんとかして鍵を適切に転送するようにしたい。

結局、ゲスト環境パッケージのインストールを行ったら直った。google-compute-engine-osloginとgoogle-compute-engineが入っていなかったようだ。

logrotateができない

Arch Linuxで次のようなエラーが出てうまくいかなかった

error: failed to rename /usr/local/var/log/mirakurun.stderr.log to /usr/local/var/log/mirakurun.stderr.log-20190517: Read-only file system

しかし、普通にsudo logrotate /etc/logrotate.d/mirakurunとか実行するとうまくいく。ちなみに /etc/logrotate.d/mirakurun は次のような感じ

/usr/local/var/log/mirakurun.std*.log
{
  su root root
  weekly
  compress
  rotate 52
  missingok
  notifempty
  compresscmd /usr/bin/xz
  uncompresscmd /usr/bin/unxz
  compressext .xz
  dateext
  postrotate
    pm2 reloadLogs
  endscript
}

何気なくlogrotate.serviceを眺めてみたら原因っぽいことが分かった

$ cat /usr/lib/systemd/system/logrotate.service
[Unit]
Description=Rotate log files
Documentation=man:logrotate(8) man:logrotate.conf(5)
RequiresMountsFor=/var/log
ConditionACPower=true

[Service]
Type=oneshot
ExecStart=/usr/sbin/logrotate /etc/logrotate.conf

# performance options
Nice=19
IOSchedulingClass=best-effort
IOSchedulingPriority=7

# hardening options
#  details: https://www.freedesktop.org/software/systemd/man/systemd.exec.html
#  no ProtectHome for userdir logs
#  no PrivateNetwork for mail deliviery
#  no ProtectKernelTunables for working SELinux with systemd older than 235
MemoryDenyWriteExecute=true
PrivateDevices=true
PrivateTmp=true
ProtectControlGroups=true
ProtectKernelModules=true
ProtectSystem=full
RestrictRealtime=true

ProtectSystemが怪しい。説明を見てみると、次のようなことが書いてあった。

If true, mounts the /usr and /boot directories read-only for processes invoked by this unit.

https://www.freedesktop.org/software/systemd/man/systemd.exec.htm

どうやら/usrがread-onlyになるようだ。ReadWritePaths=/usr/local/var/logでも指定すればいいのだろうか。後ほど試すことにする。

追記:試したがpm2 reloadLogsがコアダンプを起こして終了していた。MemoryDenyWriteExecuteが怪しい気がするが、あきらめる。

ローカルアカウントからMicrosoftアカウントに切り替え

https://answers.microsoft.com/ja-jp/windows/forum/windows_8-security/%e3%83%ad%e3%83%bc%e3%82%ab%e3%83%ab%e3%82%a2/c12dcd31-a550-46ec-afd4-d9771558c7b9?messageId=5f1641f2-ed27-493e-be4b-3fd19b606a6e

https://answers.microsoft.com/ja-jp/windows/forum/all/microsoft%E3%82%A2%E3%82%AB%E3%82%A6%E3%83%B3/3d531e7f-42a8-47ce-ad3c-d71d52b96bc4

https://answers.microsoft.com/en-us/windows/forum/windows_10-security/another-user-on-this-device-uses-this-microsoft/3920bd03-bc04-40e3-b51e-9ceabe7a5842?page=2

切り替えようとしたが、すぐにはできなかった。日本語での情報に乏しいので英語で検索したら、それっぽいのが見つかった。regeditで
HKEY_USERS\S-1-5-18\Software\Microsoft\IdentityCRL\StoredIdentities\にあるメールアドレスを消すと良いらしい。しかし、これをやっても駄目だった。netplwizを開いて、詳細の詳細を出して、ユーザーの一覧を表示させたところ、Microsoftアカウントでセットアップするとデフォルトで設定されるユーザー名のユーザーが存在していたので消した。そしたら、切り替えができるようになった

F2FSを測ってみた

新しいmicroSDに容量15GB程度のパーティション切って、ext4かF2FSでフォーマットした。USBのmicroSDリーダーを使い、Raspberry Pi 3上のarchlinux armでfioを実行した。結果は以下の通り。

結果

ext4

  1. IOPS=337, BW=1350KiB/s
  2. IOPS=348, BW=1392KiB/s

F2FS

  1. IOPS=695, BW=2781KiB/s
  2. IOPS=644, BW=2579KiB/s
[akimasa@alarmpi ~]$ sudo mkfs.ext4 /dev/sda2
mke2fs 1.44.5 (15-Dec-2018)
Creating filesystem with 3786752 4k blocks and 948416 inodes
Filesystem UUID: db43a860-db0f-40dd-8aac-f8c6b978dd60
Superblock backups stored on blocks:
32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 2654208
Allocating group tables: done
Writing inode tables: done
Creating journal (16384 blocks): done
Writing superblocks and filesystem accounting information: done
[akimasa@alarmpi ~]$ mount /dev/sda2 mountpoint/
mount: only root can do that
[akimasa@alarmpi ~]$ sudo mount /dev/sda2 mountpoint/
[akimasa@alarmpi ~]$ cd mountpoint/
[akimasa@alarmpi mountpoint]$ sudo fio -filename=./testtmp -direct=1 -rw=randwrite -bs=4k -size=1000M -numjobs=16 -runtime=20 -group_reporting -name=file1
file1: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=psync, iodepth=1

fio-3.13
Starting 16 processes
file1: Laying out IO file (1 file / 1000MiB)
Jobs: 16 (f=16): [w(16)][100.0%][w=664KiB/s][w=166 IOPS][eta 00m:00s]
file1: (groupid=0, jobs=16): err= 0: pid=2528: Mon Mar 11 15:49:01 2019
write: IOPS=337, BW=1350KiB/s (1382kB/s)(26.4MiB/20034msec); 0 zone resets
clat (usec): min=1185, max=1532.3k, avg=47337.89, stdev=86609.63
lat (usec): min=1189, max=1532.3k, avg=47341.86, stdev=86609.70
clat percentiles (msec):
| 1.00th=[ 28], 5.00th=[ 30], 10.00th=[ 31], 20.00th=[ 31],
| 30.00th=[ 32], 40.00th=[ 32], 50.00th=[ 33], 60.00th=[ 34],
| 70.00th=[ 34], 80.00th=[ 35], 90.00th=[ 68], 95.00th=[ 92],
| 99.00th=[ 326], 99.50th=[ 584], 99.90th=[ 1435], 99.95th=[ 1502],
| 99.99th=[ 1536]
bw ( KiB/s): min= 127, max= 2064, per=100.00%, avg=1433.52, stdev=37.13, samples=602
iops : min= 31, max= 516, avg=357.70, stdev= 9.29, samples=602
lat (msec) : 2=0.31%, 4=0.03%, 10=0.04%, 20=0.06%, 50=85.73%
lat (msec) : 100=9.35%, 250=2.90%, 500=1.05%, 750=0.07%, 1000=0.09%
cpu : usr=0.07%, sys=1.04%, ctx=13585, majf=0, minf=282
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued rwts: total=0,6761,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
Run status group 0 (all jobs):
WRITE: bw=1350KiB/s (1382kB/s), 1350KiB/s-1350KiB/s (1382kB/s-1382kB/s), io=26.4MiB (27.7MB), run=20034-20034msec
Disk stats (read/write):
sda: ios=0/6961, merge=0/188, ticks=0/24691, in_queue=24620, util=91.29%
[akimasa@alarmpi mountpoint]$ sudo fio -filename=./testtmp -direct=1 -rw=randwrite -bs=4k -size=1000M -numjobs=16 -runtime=20 -group_reporting -name=file1
file1: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=psync, iodepth=1

fio-3.13
Starting 16 processes
Jobs: 16 (f=16): [w(16)][100.0%][w=1212KiB/s][w=303 IOPS][eta 00m:00s]
file1: (groupid=0, jobs=16): err= 0: pid=2547: Mon Mar 11 15:49:25 2019
write: IOPS=348, BW=1392KiB/s (1426kB/s)(27.6MiB/20313msec); 0 zone resets
clat (usec): min=1181, max=2296.1k, avg=45784.22, stdev=113933.76
lat (usec): min=1185, max=2296.1k, avg=45788.25, stdev=113933.93
clat percentiles (msec):
| 1.00th=[ 22], 5.00th=[ 27], 10.00th=[ 27], 20.00th=[ 28],
| 30.00th=[ 29], 40.00th=[ 29], 50.00th=[ 29], 60.00th=[ 31],
| 70.00th=[ 31], 80.00th=[ 32], 90.00th=[ 42], 95.00th=[ 73],
| 99.00th=[ 489], 99.50th=[ 776], 99.90th=[ 1888], 99.95th=[ 2106],
| 99.99th=[ 2299]
bw ( KiB/s): min= 128, max= 2327, per=100.00%, avg=1623.82, stdev=40.57, samples=556
iops : min= 32, max= 581, avg=405.26, stdev=10.13, samples=556
lat (msec) : 2=0.35%, 4=0.11%, 10=0.04%, 20=0.11%, 50=90.14%
lat (msec) : 100=5.49%, 250=1.91%, 500=0.86%, 750=0.45%, 1000=0.11%
cpu : usr=0.08%, sys=0.46%, ctx=14162, majf=0, minf=305
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued rwts: total=0,7070,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
Run status group 0 (all jobs):
WRITE: bw=1392KiB/s (1426kB/s), 1392KiB/s-1392KiB/s (1426kB/s-1426kB/s), io=27.6MiB (28.0MB), run=20313-20313msec
Disk stats (read/write):
sda: ios=0/7279, merge=0/8, ticks=0/27596, in_queue=27660, util=96.94%
[akimasa@alarmpi mountpoint]$ cd
[akimasa@alarmpi ~]$ sudo umount /home/akimasa/mountpoint
[akimasa@alarmpi ~]$ sudo mkfs.f2fs -f /dev/sda2
F2FS-tools: mkfs.f2fs Ver: 1.12.0 (2018-11-21)
Info: Disable heap-based policy
Info: Debug level = 0
Info: Trim is enabled
Info: [/dev/sda2] Disk Model: SD Transcend
Info: Segments per section = 1
Info: Sections per zone = 1
Info: sector size = 512
Info: total sectors = 30294016 (14792 MB)
Info: zone aligned segment0 blkaddr: 512
Info: format version with
"Linux version 4.19.25-2-ARCH (builduser@leming) (gcc version 8.2.1 20181127 (GCC)) #1 SMP PREEMPT Tue Feb 26 01:20:52 UTC 2019"
Info: [/dev/sda2] Discarding device
Info: This device doesn't support BLKSECDISCARD
Info: This device doesn't support BLKDISCARD
Info: Overprovision ratio = 1.650%
Info: Overprovision segments = 248 (GC reserved = 129)
Info: format successful
[akimasa@alarmpi ~]$ sudo mount /dev/sda2 mountpoint/
[akimasa@alarmpi ~]$ cd mountpoint/
[akimasa@alarmpi mountpoint]$ sudo fio -filename=./testtmp -direct=1 -rw=randwrite -bs=4k -size=1000M -numjobs=16 -runtime=20 -group_reporting -name=file1
file1: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=psync, iodepth=1

fio-3.13
Starting 16 processes
file1: Laying out IO file (1 file / 1000MiB)
Jobs: 16 (f=16): [w(16)][100.0%][w=1309KiB/s][w=327 IOPS][eta 00m:00s]
file1: (groupid=0, jobs=16): err= 0: pid=2588: Mon Mar 11 15:50:39 2019
write: IOPS=695, BW=2781KiB/s (2848kB/s)(54.4MiB/20021msec); 0 zone resets
clat (usec): min=1089, max=422480, avg=22966.77, stdev=15612.63
lat (usec): min=1093, max=422484, avg=22970.51, stdev=15612.67
clat percentiles (msec):
| 1.00th=[ 18], 5.00th=[ 19], 10.00th=[ 19], 20.00th=[ 20],
| 30.00th=[ 20], 40.00th=[ 21], 50.00th=[ 21], 60.00th=[ 21],
| 70.00th=[ 21], 80.00th=[ 23], 90.00th=[ 24], 95.00th=[ 40],
| 99.00th=[ 69], 99.50th=[ 86], 99.90th=[ 300], 99.95th=[ 372],
| 99.99th=[ 397]
bw ( KiB/s): min= 568, max= 3408, per=99.98%, avg=2779.55, stdev=44.26, samples=640
iops : min= 142, max= 852, avg=693.95, stdev=11.07, samples=640
lat (msec) : 2=0.39%, 4=0.02%, 10=0.01%, 20=37.73%, 50=57.36%
lat (msec) : 100=4.10%, 250=0.28%, 500=0.11%
cpu : usr=0.12%, sys=0.95%, ctx=27860, majf=0, minf=310
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued rwts: total=0,13919,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
Run status group 0 (all jobs):
WRITE: bw=2781KiB/s (2848kB/s), 2781KiB/s-2781KiB/s (2848kB/s-2848kB/s), io=54.4MiB (57.0MB), run=20021-20021msec
Disk stats (read/write):
sda: ios=0/13763, merge=0/0, ticks=0/18738, in_queue=18730, util=94.04%
[akimasa@alarmpi mountpoint]$ sudo fio -filename=./testtmp -direct=1 -rw=randwrite -bs=4k -size=1000M -numjobs=16 -runtime=20 -group_reporting -name=file1
file1: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=psync, iodepth=1

fio-3.13
Starting 16 processes
Jobs: 16 (f=16): [w(16)][100.0%][w=2116KiB/s][w=529 IOPS][eta 00m:00s]
file1: (groupid=0, jobs=16): err= 0: pid=2607: Mon Mar 11 15:51:04 2019
write: IOPS=644, BW=2579KiB/s (2641kB/s)(51.4MiB/20388msec); 0 zone resets
clat (usec): min=1091, max=855416, avg=24717.84, stdev=36849.00
lat (usec): min=1095, max=855420, avg=24721.44, stdev=36849.03
clat percentiles (msec):
| 1.00th=[ 19], 5.00th=[ 19], 10.00th=[ 19], 20.00th=[ 20],
| 30.00th=[ 20], 40.00th=[ 21], 50.00th=[ 21], 60.00th=[ 21],
| 70.00th=[ 22], 80.00th=[ 23], 90.00th=[ 23], 95.00th=[ 25],
| 99.00th=[ 108], 99.50th=[ 262], 99.90th=[ 592], 99.95th=[ 844],
| 99.99th=[ 852]
bw ( KiB/s): min= 149, max= 3296, per=100.00%, avg=2625.05, stdev=56.50, samples=640
iops : min= 35, max= 824, avg=655.40, stdev=14.14, samples=640
lat (msec) : 2=0.34%, 4=0.04%, 10=0.04%, 20=37.87%, 50=57.97%
lat (msec) : 100=2.59%, 250=0.63%, 500=0.31%, 750=0.13%, 1000=0.08%
cpu : usr=0.14%, sys=0.81%, ctx=26326, majf=0, minf=298
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued rwts: total=0,13147,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
Run status group 0 (all jobs):
WRITE: bw=2579KiB/s (2641kB/s), 2579KiB/s-2579KiB/s (2641kB/s-2641kB/s), io=51.4MiB (53.8MB), run=20388-20388msec
Disk stats (read/write):
sda: ios=0/13141, merge=0/0, ticks=0/19400, in_queue=19470, util=95.13%
[akimasa@alarmpi mountpoint]$

F2FSの威力を測る(簡易版)

ふと、F2FSだとパフォーマンスが上がるのか?と思ったのでベンチマークしてみた。ext4のファイルシステム上にあるloopファイルでやったので、かなり誤差を含んでいると思う。

ベンチマーク結果

ext4

  1. write: IOPS=652, BW=2612KiB/s
  2. write: IOPS=378, BW=1514KiB/s

F2FS

  1. write: IOPS=1155, BW=4622KiB/s
  2. write: IOPS=675, BW=2703KiB/s
  3. write: IOPS=1180, BW=4721KiB/s
[akimasa@alarmpi ~]$ rm testdisk
[akimasa@alarmpi ~]$ truncate -s1G testdisk
[akimasa@alarmpi ~]$ mkfs.ext4 testdisk
mke2fs 1.44.5 (15-Dec-2018)
Discarding device blocks: done
Creating filesystem with 262144 4k blocks and 65536 inodes
Filesystem UUID: 732ef760-3977-4470-8586-cb53b3bcf40d
Superblock backups stored on blocks:
32768, 98304, 163840, 229376
Allocating group tables: done
Writing inode tables: done
Creating journal (8192 blocks): done
Writing superblocks and filesystem accounting information: done
[akimasa@alarmpi ~]$ sudo mount testdisk mountpoint/
[akimasa@alarmpi ~]$ cd mountpoint/
[akimasa@alarmpi mountpoint]$ sudo fio -filename=./testtmp -direct=1 -rw=randwrite -bs=4k -size=800M -numjobs=16 -runtime=20 -group_reporting -name=file1
file1: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=psync, iodepth=1

fio-3.13
Starting 16 processes
file1: Laying out IO file (1 file / 800MiB)
Jobs: 13 (f=13): [w(1),(1),w(4),(1),w(2),(1),w(6)][26.5%][w=12KiB/s][w=3 IOPSJobs: 13 (f=13): [w(1),(1),w(4),(1),w(2),(1),w(6)][27.7%][eta 01m:00s] Jobs: 11 (f=11): [w(1),(2),w(3),(1),w(2),(1),w(3),(1),w(2)][18.9%][w=7KiB/s]Jobs: 11 (f=11): [w(1),(2),w(3),(1),w(2),(1),w(3),(1),w(2)][19.7%][eta 01m:4Jobs: 11 (f=11): [w(1),(2),w(3),(1),w(2),(1),w(3),(1),w(2)][20.5%][eta 01m:4Jobs: 11 (f=11): [w(1),(2),w(3),(1),w(2),(1),w(3),(1),w(2)][21.3%][eta 01m:4Jobs: 11 (f=11): [w(1),(2),w(3),(1),w(2),(1),w(3),(1),w(2)][22.0%][eta 01m:3Jobs: 6 (f=6): [(5),w(1),(2),w(1),(1),w(3),(2),w(1)][10.9%][w=20KiB/s][w=5 IOPS][eta 03m:57s]
file1: (groupid=0, jobs=16): err= 0: pid=507: Sun Mar 10 21:39:42 2019
write: IOPS=652, BW=2612KiB/s (2675kB/s)(75.1MiB/29460msec); 0 zone resets
clat (usec): min=74, max=10535k, avg=22279.36, stdev=317342.34
lat (usec): min=76, max=10535k, avg=22281.62, stdev=317342.36
clat percentiles (msec):
| 1.00th=[ 3], 5.00th=[ 3], 10.00th=[ 3], 20.00th=[ 3],
| 30.00th=[ 3], 40.00th=[ 3], 50.00th=[ 3], 60.00th=[ 3],
| 70.00th=[ 4], 80.00th=[ 6], 90.00th=[ 6], 95.00th=[ 6],
| 99.00th=[ 10], 99.50th=[ 651], 99.90th=[ 5403], 99.95th=[ 9463],
| 99.99th=[10537]
bw ( KiB/s): min= 160, max=21141, per=100.00%, avg=9711.92, stdev=420.95, samples=254
iops : min= 40, max= 5285, avg=2427.36, stdev=105.25, samples=254
lat (usec) : 100=0.01%, 250=0.15%, 500=0.18%, 750=0.04%, 1000=0.01%
lat (msec) : 4=71.01%, 10=27.64%, 20=0.06%, 50=0.01%, 100=0.09%
lat (msec) : 250=0.15%, 500=0.03%, 750=0.17%, 1000=0.01%
cpu : usr=0.12%, sys=1.23%, ctx=38554, majf=0, minf=342
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued rwts: total=0,19237,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
Run status group 0 (all jobs):
WRITE: bw=2612KiB/s (2675kB/s), 2612KiB/s-2612KiB/s (2675kB/s-2675kB/s), io=75.1MiB (78.8MB), run=29460-29460msec
Disk stats (read/write):
loop0: ios=0/19864, merge=0/0, ticks=0/96576, in_queue=81260, util=89.63%
[akimasa@alarmpi mountpoint]$ sudo fio -filename=./testtmp -direct=1 -rw=randwrite -bs=4k -size=800M -numjobs=16 -runtime=20 -group_reporting -name=file1
file1: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=psync, iodepth=1

fio-3.13
Starting 16 processes
Jobs: 14 (f=14): [w(9),(1),w(4),(1),w(1)][37.5%][w=8KiB/s][w=2 IOPS][eta 00m:4Jobs: 14 (f=14): [w(9),(1),w(4),(1),w(1)][38.9%][eta 00m:44s] Jobs: 14 (f=14): [w(9),(1),w(4),(1),w(1)][47.2%][eta 00m:38s]
file1: (groupid=0, jobs=16): err= 0: pid=533: Sun Mar 10 21:40:29 2019
write: IOPS=378, BW=1514KiB/s (1550kB/s)(50.8MiB/34351msec); 0 zone resets
clat (usec): min=59, max=15945k, avg=40995.53, stdev=639574.37
lat (usec): min=60, max=15945k, avg=40998.16, stdev=639574.36
clat percentiles (usec):
| 1.00th=[ 1123], 5.00th=[ 1156], 10.00th=[ 1172],
| 20.00th=[ 1205], 30.00th=[ 1237], 40.00th=[ 1434],
| 50.00th=[ 2212], 60.00th=[ 2245], 70.00th=[ 2311],
| 80.00th=[ 2376], 90.00th=[ 2507], 95.00th=[ 2573],
| 99.00th=[ 6063], 99.50th=[ 608175], 99.90th=[15904801],
| 99.95th=[15904801], 99.99th=[15904801]
bw ( KiB/s): min= 144, max=32681, per=100.00%, avg=12826.52, stdev=835.84, samples=130
iops : min= 36, max= 8168, avg=3205.88, stdev=208.95, samples=130
lat (usec) : 100=0.12%, 250=0.56%, 500=0.07%, 750=0.01%
lat (msec) : 2=42.50%, 4=55.51%, 10=0.35%, 20=0.21%, 50=0.05%
lat (msec) : 750=0.15%
cpu : usr=0.06%, sys=0.26%, ctx=25993, majf=0, minf=331
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued rwts: total=0,12999,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
Run status group 0 (all jobs):
WRITE: bw=1514KiB/s (1550kB/s), 1514KiB/s-1514KiB/s (1550kB/s-1550kB/s), io=50.8MiB (53.2MB), run=34351-34351msec
Disk stats (read/write):
loop0: ios=0/12999, merge=0/0, ticks=0/63750, in_queue=67480, util=97.72%
[akimasa@alarmpi mountpoint]$ cd
[akimasa@alarmpi ~]$ sudo umount /home/akimasa/mountpoint
[akimasa@alarmpi ~]$ mkfs.f2fs -f testdisk
F2FS-tools: mkfs.f2fs Ver: 1.12.0 (2018-11-21)
Info: Disable heap-based policy
Info: Debug level = 0
Info: Trim is enabled
Info: Segments per section = 1
Info: Sections per zone = 1
Info: sector size = 512
Info: total sectors = 2097152 (1024 MB)
Info: zone aligned segment0 blkaddr: 512
Info: format version with
"Linux version 4.19.25-2-ARCH (builduser@leming) (gcc version 8.2.1 20181127 (GCC)) #1 SMP PREEMPT Tue Feb 26 01:20:52 UTC 2019"
Info: [testdisk] Discarding device
Info: Overprovision ratio = 6.360%
Info: Overprovision segments = 68 (GC reserved = 39)
Info: format successful
(reverse-i-search)`s': gst-launch-1.0 souphttpsrc location="http://192.168.0.9:40772/api/channels/GR/27/services/1024/stream" ! queue ! t^Cemux ! queue ! faad ! queue ! audioconvert ! audioresample ! queue ! opusenc ! oggmux ! tcpserversink port=10000 host=192.168.0.25
[akimasa@alarmpi ~]$ sudo mount testdisk mountpoint/
[akimasa@alarmpi ~]$ cd mountpoint/
[akimasa@alarmpi mountpoint]$ sudo fio -filename=./testtmp -direct=1 -rw=randwrite -bs=4k -size=800M -numjobs=16 -runtime=20 -group_reporting -name=file1
file1: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=psync, iodepth=1

fio-3.13
Starting 16 processes
file1: Laying out IO file (1 file / 800MiB)
Jobs: 16 (f=16): [w(16)][0.9%][eta 46m:07s]
file1: (groupid=0, jobs=16): err= 0: pid=571: Sun Mar 10 21:41:53 2019
write: IOPS=1155, BW=4622KiB/s (4733kB/s)(120MiB/26665msec); 0 zone resets
clat (usec): min=62, max=12800k, avg=13822.79, stdev=374463.88
lat (usec): min=63, max=12800k, avg=13825.05, stdev=374463.89
clat percentiles (usec):
| 1.00th=[ 163], 5.00th=[ 1188], 10.00th=[ 1205],
| 20.00th=[ 1221], 30.00th=[ 1237], 40.00th=[ 1270],
| 50.00th=[ 1319], 60.00th=[ 1418], 70.00th=[ 2343],
| 80.00th=[ 2442], 90.00th=[ 2573], 95.00th=[ 2671],
| 99.00th=[ 2999], 99.50th=[ 4817], 99.90th=[10267657],
| 99.95th=[12817794], 99.99th=[12817794]
bw ( KiB/s): min= 398, max=43200, per=100.00%, avg=27369.00, stdev=856.03, samples=144
iops : min= 98, max=10800, avg=6841.78, stdev=214.04, samples=144
lat (usec) : 100=0.72%, 250=0.45%, 500=0.05%, 750=0.01%, 1000=0.01%
lat (msec) : 2=64.20%, 4=33.95%, 10=0.40%, 50=0.05%, 250=0.05%
cpu : usr=0.18%, sys=0.72%, ctx=61631, majf=0, minf=478
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued rwts: total=0,30809,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
Run status group 0 (all jobs):
WRITE: bw=4622KiB/s (4733kB/s), 4622KiB/s-4622KiB/s (4733kB/s-4733kB/s), io=120MiB (126MB), run=26665-26665msec
Disk stats (read/write):
loop0: ios=0/30793, merge=0/0, ticks=0/12368, in_queue=25030, util=93.83%
[akimasa@alarmpi mountpoint]$ sudo fio -filename=./testtmp -direct=1 -rw=randwrite -bs=4k -size=800M -numjobs=16 -runtime=20 -group_reporting -name=file1
file1: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=psync, iodepth=1

fio-3.13
Starting 16 processes
Jobs: 16 (f=16): [w(16)][0.5%][eta 01h:19m:15s]
file1: (groupid=0, jobs=16): err= 0: pid=591: Sun Mar 10 21:42:23 2019
write: IOPS=675, BW=2703KiB/s (2768kB/s)(59.3MiB/22466msec); 0 zone resets
clat (usec): min=59, max=20792k, avg=23623.54, stdev=673819.89
lat (usec): min=61, max=20792k, avg=23626.06, stdev=673819.87
clat percentiles (usec):
| 1.00th=[ 1074], 5.00th=[ 1106], 10.00th=[ 1123],
| 20.00th=[ 1139], 30.00th=[ 1156], 40.00th=[ 1205],
| 50.00th=[ 1418], 60.00th=[ 2180], 70.00th=[ 2245],
| 80.00th=[ 2311], 90.00th=[ 2442], 95.00th=[ 2540],
| 99.00th=[ 2835], 99.50th=[ 3425], 99.90th=[17112761],
| 99.95th=[17112761], 99.99th=[17112761]
bw ( KiB/s): min=10432, max=42238, per=100.00%, avg=30327.00, stdev=753.64, samples=64
iops : min= 2608, max=10558, avg=7581.00, stdev=188.38, samples=64
lat (usec) : 100=0.14%, 250=0.47%, 500=0.05%, 750=0.01%, 1000=0.01%
lat (msec) : 2=51.43%, 4=47.53%, 10=0.26%
cpu : usr=0.10%, sys=0.43%, ctx=30358, majf=0, minf=319
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued rwts: total=0,15183,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
Run status group 0 (all jobs):
WRITE: bw=2703KiB/s (2768kB/s), 2703KiB/s-2703KiB/s (2768kB/s-2768kB/s), io=59.3MiB (62.2MB), run=22466-22466msec
Disk stats (read/write):
loop0: ios=0/15177, merge=0/0, ticks=0/32370, in_queue=32390, util=95.38%
[akimasa@alarmpi mountpoint]$ sudo fio -filename=./testtmp -direct=1 -rw=randwrite -bs=4k -size=800M -numjobs=16 -runtime=20 -group_reporting -name=file1
file1: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=psync, iodepth=1

fio-3.13
Starting 16 processes
Jobs: 16 (f=16): [w(16)][1.0%][eta 44m:38s]
file1: (groupid=0, jobs=16): err= 0: pid=610: Sun Mar 10 21:42:57 2019
write: IOPS=1180, BW=4721KiB/s (4834kB/s)(124MiB/26802msec); 0 zone resets
clat (usec): min=61, max=11993k, avg=13529.91, stdev=358536.31
lat (usec): min=62, max=11993k, avg=13532.38, stdev=358536.32
clat percentiles (usec):
| 1.00th=[ 1045], 5.00th=[ 1074], 10.00th=[ 1106],
| 20.00th=[ 1139], 30.00th=[ 1156], 40.00th=[ 1221],
| 50.00th=[ 2008], 60.00th=[ 2212], 70.00th=[ 2278],
| 80.00th=[ 2343], 90.00th=[ 2442], 95.00th=[ 2540],
| 99.00th=[ 2868], 99.50th=[ 3458], 99.90th=[10536092],
| 99.95th=[12012487], 99.99th=[12012487]
bw ( KiB/s): min= 4896, max=46156, per=100.00%, avg=25290.80, stdev=934.24, samples=160
iops : min= 1224, max=11538, avg=6322.20, stdev=233.59, samples=160
lat (usec) : 100=0.17%, 250=0.30%, 500=0.03%, 750=0.01%
lat (msec) : 2=49.50%, 4=49.51%, 10=0.28%, 500=0.10%
cpu : usr=0.18%, sys=0.77%, ctx=63277, majf=0, minf=436
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued rwts: total=0,31634,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
Run status group 0 (all jobs):
WRITE: bw=4721KiB/s (4834kB/s), 4721KiB/s-4721KiB/s (4834kB/s-4834kB/s), io=124MiB (130MB), run=26802-26802msec
Disk stats (read/write):
loop0: ios=0/31618, merge=0/0, ticks=0/14719, in_queue=25080, util=93.89%
[akimasa@alarmpi mountpoint]$ cd
[akimasa@alarmpi ~]$ sudo umount /home/akimasa/mountpoint
[akimasa@alarmpi ~]$

Windows 10 OEMキーは使えない

GPU-Zの配布元のtechpowerupGuru3Dで紹介されていたので、大丈夫だろうと思っていたら、大丈夫じゃなかった。

ライセンス認証は問題なく通るかもしれないが、詳しく調べるとVolume License Keyで少なくとも日本ではライセンス違反になり、合法的に使えないキーが手に入ることになる。

マイクロソフトに問い合わせ(1度目)

フリーダイヤルの技術サポート窓口で、Windows->ライセンス認証->その他の問い合わせを行う。ボリュームライセンスキーを売られた疑いがあるので調べてほしいと伝えた。担当者がさらに詳しい人に聞いているためか、数分時間がかかった。結果、ボリュームライセンスキーだと確認できた。個人で使うとライセンス違反になると伝えられた。

逸般的な誤家庭で個人でVolume LicenseつかってSoftware Assuranceを購入した経験があるのでライセンス違反の疑いがあると理解ができた。VLキーが単体で販売されるわけがない。OEMを一時期のWindows 8のDSP版の仕様だろうと都合よく解釈してしまったが、違ったようだ。昔のDSP版はMicrosoftによるサポートが無い(代わりに販売店がサポートを提供することになっている)単体のWindowsとして販売されていた。あと、OEM=DSPだと思っていたのも敗因の一つか。

urcdkeyに問い合わせ (1度目)

ライセンス違反で使えない的なことを伝えたら、すぐに再発行された。(ライセンス認証が通らないと向こうは受け取ったのかもしれない)

マイクロソフトに問い合わせ(2度目)

先ほどと同じくその他の問い合わせにつなぎ、先ほどの問い合わせ終了時に受け取った受付番号を伝えた。記録としてはライセンスキーに関する問い合わせとしか残っていないらしいので、再び説明する。そして、ライセンスキーを伝えたら、有効なキーとすぐに分かったが、VLキーかどうかは不明なので、調べてもらう。数分後、やはりVLキーだと判明する。教育機関や学校向けとか言っていた気がする。urcdkeyでの問い合わせは原則スクリーンショットが必要なので、メールでライセンス違反だと説明する文章を送ってくれないか頼んでみたが、ダメだった。

urcdkeyに問い合わせ (2度目)

日本で合法的に使えないキーで、返金を求めると伝えたら、キーを使ったかどうかだけ聞かれて、使っていないので使ってないと答えた。もう一度キーを(ほかの人に?)売るので12時間後に再び問い合わせると返金が行われるとのことだった。というわけで12時間待っている。

追記:24時間経過したら返金されていた。

openocdでSEGGER RTTを使う

使えないかと思っていたらパッチが投稿されていた。まだマージされていないが、使うことができる。

$ git clone git://repo.or.cz/openocd.git
$ git fetch http://openocd.zylin.com/openocd refs/changes/55/4055/8 && git checkout FETCH_HEAD
$ cd openocd/
$ ./bootstrap
$ ./configure --enable-sysfsgpio --enable-bcm2835gpio --prefix=$HOME/openocd-rtt
$ make -j4
$ make install

上記のコマンドを実行すればopenocdのバイナリができる。configureの際にprefixオプションを付けて、最初からに入っているopenocdと被らないようにしたが、必要がなければprefixは消してもらいたい。

さて、バイナリがインストールされたら、普段通りにopenocdを実行する。localhost:4444のコンソールから操作するが、以下のようなコマンドを実行する。0x2000321cは環境によって異なるので変える必要がある。

> rtt setup 0x2000321c 512 "SEGGER RTT" 
> rtt start
> rtt channels
> rttserver start 5555 0

そうすると、localhost:5555にtelnetで接続できるようなる。あとは出力を眺めるだけ。

コントロールブロックの探し方

さて、0x2000321cは環境によって異なると書いたが、見つけ方はいくつかある。

.mapを見る

nRF5 SDKでコンパイラはarmgccを使った。_build\nrf51422_xxac.mapを開く。

_build\nrf51422_xxac.mapを開く。

COMMON         0x2000321c       0x78 _build/nrf51422_xxac_SEGGER_RTT.c.o
0x2000321c _SEGGER_RTT

すると、上記のような部分が見つかる。ここにある0x2000321cが入力するアドレスになる。

GDBを使う(推奨)

eval "monitor rtt setup %p 512 SEGGER\\ RTT", &_SEGGER_RTT
monitor rtt start
monitor rtt channels
monitor rttserver start 5555 0

上記のコマンドをGDBで実行してもRTTのコントロールブロックのアドレスを与えることができる。こちらの方が楽だ。

これでUARTつないでいなくても出力を眺めることができるので非常に便利なる。デバッグがはかどりそうだ。数千円かけてJ-Linkを買わないといけないのか…と思っていたが、手元にあるRasPi Zero Wでも同じことができた。