音が途切れる原因はNASだった
Raspberry piでミュージックプレーヤー 12
今年の初夏のころから我が家のネットワークオーディオではちょっとしたトラブルがときどき発生していました。
症状は「音の途切れ」です。
データ転送が間に合っていないような感じです。
気にせずほっとけば復旧しますが、夏の盛りのころから症状が頻発するようになり、長時間の曲で再生開始から8～10分くらいでほぼ確実に起きるようになってきました。
夏の暑さにやられたかとラズパイにファンを付けたり、NASのストレージをSSDにしてみましたが改善される気配がありません。
涼しくなって発生頻度は気持ち下がったような気もしますが、NASのOpenMediaVaultを3.xから4.xにしても、ラズパイを4Bにしても、ネットワークをギガビットにしてもやはり発生します。
このままではお気に入りのアナログレコードからダビング（死語）したアルバムを聴くのにストレスMaxです。
これは本格的に治さないと。と思い、まずはmpdのログを取ってみました。
すると、途切れが発生するタイミングで、NASの応答遅延が起きていることがわかりました。
さらにNAS側のログを見てみたら、途切れが発生するタイミングでなにやらリセットが走って、ディスクの再マウントがおきていることが判明。
ログメッセージの文言でググってみたら、UAS(usb attached scsi)のバグだかなんかだかで、UASを使わないようにするしか回避方法がなさげです。
おあつらえ向きにNanoPiNeo2での事例があったので、参考にさせていただきました。
以下、備忘を兼ねた復旧手順のまとめです。
症状：NASからファイル転送中に転送が止まり、しばらくするとまた動き出す。
具体的には、ラズパイのmpdでNASの楽曲ファイルを再生中に音が途切れる。
NAS：NanoPi Neo2+NASキット+SSD960GB+OpenMediaVault(4.1.29-1)
発症時のsyslog：
kernel: [36204.806807] sd 0:0:0:0: [sda] tag#0 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD
kernel: [36204.806825] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 16 78 51 80 00 01 00 00
kernel: [36204.806843] sd 0:0:0:0: [sda] tag#1 uas_eh_abort_handler 0 uas-tag 2 inflight: CMD
kernel: [36204.806852] sd 0:0:0:0: [sda] tag#1 CDB: opcode=0x28 28 00 16 78 50 80 00 01 00 00
kernel: [36208.390932] sd 0:0:0:0: [sda] tag#2 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD
kernel: [36208.390951] sd 0:0:0:0: [sda] tag#2 CDB: opcode=0x2a 2a 00 37 c4 2e 70 00 00 18 00
kernel: [36208.406932] scsi host0: uas_eh_device_reset_handler start
kernel: [36208.542926] usb 4-1: reset high-speed USB device number 2 using ehci-platform
kernel: [36208.700136] scsi host0: uas_eh_device_reset_handler success
原因：UAS(usb attached scsi)の意図しない中断(abort)に伴うリセットの発生。
（debian系の発生情報が多い感じで、同様の不具合はカーネル3.xの頃から綿々と引き継がれている模様。）
対策：UASを無効化し、旧来のusb storageとしてドライブをマウントさせる。
手順
・rootでログイン
・UASデバイスの確認
~# lsusb -t
/: Bus 09.Port 1: Dev 1, Class=root_hub, Driver=musb-hdrc/1p, 480M
/: Bus 08.Port 1: Dev 1, Class=root_hub, Driver=ohci-platform/1p, 12M
/: Bus 07.Port 1: Dev 1, Class=root_hub, Driver=ohci-platform/1p, 12M
/: Bus 06.Port 1: Dev 1, Class=root_hub, Driver=ohci-platform/1p, 12M
/: Bus 05.Port 1: Dev 1, Class=root_hub, Driver=ehci-platform/1p, 480M
/: Bus 04.Port 1: Dev 1, Class=root_hub, Driver=ehci-platform/1p, 480M
|__ Port 1: Dev 2, If 0, Class=Mass Storage, Driver=uas, 480M
/: Bus 03.Port 1: Dev 1, Class=root_hub, Driver=ehci-platform/1p, 480M
/: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ohci-platform/1p, 12M
/: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-platform/1p, 480M
Bus 04 Port 1 Dev 2がUASで接続されています。
・該当ドライブのベンダーID、デバイスIDを確認
~# lsusb
Bus 008 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 005 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 007 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 004 Device 002: ID 152d:0578 JMicron Technology Corp. / JMicron USA Technology Corp. JMS567 SATA 6Gb/s bridge
Bus 004 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 006 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 009 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 04 Port 1 Dev 2のID “152d:0578”を使います。
（装置毎に変わる値なので参考にされる方はご自分の環境で確認してください）
・ブラックリスト作成
UASのブラックリストに対象のID”152d:0578:u”を 登録します。
~# echo options usb-storage quirks=152d:0578:u | tee /etc/modprobe.d/blacklist-uas.conf
・ブートイメージを更新
~# update-initramfs -u
普通のLinuxだとこれだけでいいみたいなんですが、NanoPi（というかarmbian）はusb-storageがカーネル組み込みなのでブートローダーでも指定する必要があります。
・ブートオプション確認
usbstoragequirksの設定状況を確認します。
~# cat /proc/cmdline
verbosity=1
console=both
overlay_prefix=sun50i-h5
overlays=usbhost1 usbhost2
rootdev=UUID=3c6046aa-1375-4e50-b09e-b8d7e4ca6152
rootfstype=btrfs
usbstoragequirks=0x2537:0x1066:u,0x2537:0x1068:u
・ブートオプション変更
usbstoragequirksに”152d:0578:u”を追加します。
~# nano /boot/armbianEnv.txt
usbstoragequirks=0x2537:0x1066:u,0x2537:0x1068:u
↓
usbstoragequirks=0x2537:0x1066:u,0x2537:0x1068:u,152d:0578:u
保存して終了。
・リブートします。
・該当ドライブがusb-storageになっていることを確認
~# lsusb -t
/: Bus 09.Port 1: Dev 1, Class=root_hub, Driver=musb-hdrc/1p, 480M
/: Bus 08.Port 1: Dev 1, Class=root_hub, Driver=ohci-platform/1p, 12M
/: Bus 07.Port 1: Dev 1, Class=root_hub, Driver=ohci-platform/1p, 12M
/: Bus 06.Port 1: Dev 1, Class=root_hub, Driver=ohci-platform/1p, 12M
/: Bus 05.Port 1: Dev 1, Class=root_hub, Driver=ehci-platform/1p, 480M
/: Bus 04.Port 1: Dev 1, Class=root_hub, Driver=ehci-platform/1p, 480M
|__ Port 1: Dev 2, If 0, Class=Mass Storage, Driver=usb-storage, 480M
/: Bus 03.Port 1: Dev 1, Class=root_hub, Driver=ehci-platform/1p, 480M
/: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ohci-platform/1p, 12M
/: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-platform/1p, 480M
Bus 04 Port 1 Dev 2がusb-storageで接続されていることがわかります。
以上で完了です。
やっとこさ、悩まされていた再生中の音切れが解消しました。