音飛び対策
ジャーナリング無しなボリュームにすることで、ほとんど音飛びしなくなったが
まれに起きているような気がする。そもそもG4レベルのパフォーマンスがあって
2Chくらいの書き込みに失敗しているのは、なにかおかしい気がするのだが。
iopending(DTrace)を使って確認してみたところG4の10.5では録音中に30秒に一回
500Kバイト弱のディスクへのio書き込みが発生している。これはupdate(8)に
よる書き込みと思われる。
2013 May 11 17:52:09, load: 0.39, disk_r: 0 KB, disk_w: 496 KB
value ------------- Distribution ------------- count
< 0 | 0
0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 4993
1 | 5
2 | 0
3 | 2
4 | 0
2013 May 11 17:52:14, load: 0.44, disk_r: 0 KB, disk_w: 0 KB
value ------------- Distribution ------------- count
< 0 | 0
0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 5001
1 | 0
fs_usageで見ると、pwriteが1秒間に3回程度発生している。
Wがついているところは、待ち時間が含まれるようだが、特に大きく遅くなっている
感じはない。
18:20:04 pwrite 0.000201 Cat
18:20:05 pwrite 0.000199 Cat
18:20:05 pwrite 0.000185 Cat
18:20:05 pwrite 0.000246 Cat
18:20:06 pwrite 0.000241 W Cat
18:20:06 pwrite 0.000185 Cat
18:20:06 pwrite 0.000196 Cat
18:20:07 pwrite 0.000192 Cat
実際の処理はAudio UnitのコールバックでExtAudioFileWriteAsyncでおこなっている。
48K,2ch,16bitを4Kのバッファで処理すると、1秒間に48回のコールバックが
呼び出される計算になる。
ExtAudioFileWriteAsyncがエラーの場合はログを吐くようにしているが、特に
エラーは起きていないような気がする。
Audio Unitのバッファを大きくする事も出来るようにしているが、効果が
ないような気もする。
バッファは4つ用意しているが、これもあまり効果が無いような気がしている。
再現性が非常に低く、デバッグが難しいのだが、それほど複雑なコードでは
ないので、コードの確認で問題に気がつく事はもうほとんどないと思う。
DTraceを使ったシステムの挙動の観察と、壊れたファイルの確認が手立てかと
思っている。壊れたファイルはfaad2の変換で見つけられるのかな？
$ ./frontend/faad -o /dev/null /Volumes/SSD2/AirCheck/20121024_225900.m4a
*********** Ahead Software MPEG-4 AAC Decoder V2.7 ******************
Build: May 18 2013
Copyright 2002-2004: Ahead Software AG
http://www.audiocoding.com
Floating point version
This program is free software; you can redistribute it and/or modify
it under the terms of the GNU General Public License.
**************************************************************************
/Volumes/SSD2/AirCheck/20121024_225900.m4a file info:
LC AAC 3716.761 secs, 2 ch, 44100 Hz
album: Jazz
---------------------
| Config: 2 Ch |
---------------------
| Ch | Position |
---------------------
| 00 | Left front |
| 01 | Right front |
---------------------
Decoding /Volumes/SSD2/AirCheck/20121024_22500.m4a took: 62.64 sec. 59.34x real
-time.
実際飛んでいるところは、0.1秒程度な感じがあるので、コールバックが正しく
処理されない事があるのかな？
完全な音飛びの対策が出来たら、2.0にしようと思っているが、あまり起きないので
デバッグする気もあまり起きず、いつになるである。
今時PPCのデバッグなど、仕事では全く見向きもされない事だろうが、まったくの
趣味なのでつべこべ言われる事はない。最近のAppleはすぐに古いものを捨てるが
10.5でDTraceをPPCにも乗せた頃の心意気が気に入っているので、調べてみようと
思っている。
ちょっと調べてみたら10.5の頃はiPhoneの開発もあったはずなのに、Darwinチーム
はよくG4まで手を入れられたものだと思う。なんらかの想いがあったように思う。
もってねがらの（庄内弁）古いものを大切にす志は見習いたい。
久しぶりに音飛びが見つかったので、確認してみたがfaad2で変換してもエラーに
ならなかった。こうなると間違ったものを書いてしまっている可能性が高くなる。
コールバックのAudioUnitRender()のエラーをチェックしていないのだが、そもそも
エラーが起きるのかドキュメントに記載がない。Doug WyattのOpenALのコードを
見るとエラーが起きた場合はそのまま抜けるようになってるが、それでいいのかな。。。
たまたま気がついたのだがPro Toolsのマニュアルに、環境設定の省エネルギにある
「可能な場合はハードディスクをスリープさせる」をチェックを外すように書いてある。
私の環境はSSDで効果があるか疑問なのだが。
DtraceについてDebugging Cocoa with DTrace on Mac OS Xというpdfがあって、参考に
なりそうだ。日本語の資料もいくつかあるようだ。
$ cat count.d
pid$target::$1:entry
{
@total = count();
}
$ sudo dtrace -s ./count.d -p 186 InputProc
dtrace: script './count.d' matched 1 probe
dtrace: pid 186 has exited
133
5秒くらいの録音でコールバックは133回呼ばれているようだ。バッファを大きく
しているので一秒間に26回くらいとなっている。
$ cat time.d
pid$target::$1:entry
{
self->ts[probefunc] = timestamp;
}
pid$target::$1:return
{
@time[probefunc] = sum(timestamp - self->ts[probefunc]);
}
$ sudo dtrace -s time.d -p 115 InputProc
dtrace: script 'time.d' matched 2 probes
dtrace: pid 115 has exited
InputProc 257736003
60秒の録音の処理時間。timestampはナノ秒のようなので、0.258秒位の模様。
本題から外れるがOBJCのdtraceでの集計は以下のような感じ。
$ cat objc.m
#include <Foundation/NSObject.h>
#include <stdio.h>
@interface HelloWorld : NSObject
- (void) hello;
@end
@implementation HelloWorld
- (void) hello{
printf("Hello World.\n");
}
@end
int main(int argc, char **argv){
id obj = [HelloWorld alloc];
[obj hello];
return 0;
}
$ gcc objc.m -o objc -framework Foundation
$ cat ocount.d
objc$target:HelloWorld:-hello:entry
{
@total = count();
}
$ sudo dtrace -s ocount.d -c ./objc
dtrace: script 'ocount.d' matched 1 probe
Hello World.
dtrace: pid 273 has exited
1
C++については
ここに記事があった。Man OS XのDTraceではxmangledオプションがが必要になる
ようだ。コンパル後のシンボルを使わなければならずかなり不便な感じがする。
$ cat cpptest.cpp
#include <iostream>
using namespace std;
class Test {
public:
void print() {
cout << "Hello World?n";
}
};
int main() {
sleep(2);
Test *obj = new Test();
obj->print();
return 0;
}
$ g++ -o cpptest cpptest.cpp
$ nm cpptest | grep print
0000000100000d28 T __ZN4Test5printEv
$ sudo dtrace -s count.d -xmangled -c ./cpptest __ZN4Test5printEv
dtrace: script 'count.d' matched 1 probe
Hello World
dtrace: pid 369 has exited
1
ついでにJavaも調べてみた。
$ cat jtest.java
public class jtest {
public static void main (String[] args) {
try{
Thread.sleep(20000);
}catch(InterruptedException e){}
hello();
}
static void hello() {
System.out.println("Hello World");
}
}
$ javac jtest.java
$ java -XX:+ExtendedDTraceProbes jtest
Hello World
-cオプションが使えなかったので、以下を別のウインドウで実行
$ cat jcount.d
hotspot*:::method-entry
/copyinstr(arg3)=="hello"/
{
@total = count();
}
$ sudo dtrace -s jcount.d -p `jps | awk '/jtest/{print $1}'`
dtrace: script 'jc.d' matched 1 probe
dtrace: pid 532 has exited
1
あたり前田のクラッカーだが、すぐに終了してしまうコマンドをdtraceすると、dtrace
が捕まえる前に終了されてしまいNo such processになってしまう。main()の最初に
sleep(2)とか入れると解決できる。
$ sudo dtrace -s count.d -c ./a.out abc
dtrace: failed to compile script count.d: line 1: failed to create entry probe f
or 'abc': No such process
もう一つ、あたり前田のクラッカーだが、stripするとdtraceが捕捉できなくなる。
しつこくてすみません。
$ strip a.out
$ sudo dtrace -s count.d -c ./a.out abc
dtrace: failed to compile script count.d: line 1: probe description pid370::abc:
entry does not match any probes
fs_usageもDTraceかと思ったら違っていた。よくよく考えてみると基本的なシステムの
集計機能はUNIXのかなり早い時期からあったようだ。DTraceは全く新しいものではなく、
古くからあった考え方を拡張したものと思える。selectを拡張したkqueueのように。
プローブの一覧は、dtrace -lで確認できる。Mac OS Xでは6万近い一覧になっている。
Javaなどのユーザーランドのプローブは実行されていないと出てこないので、これより
も多い事になると思う。ただCoreAudioの直接のプローブは見当たらない。
コールバックにエラーログを吐くようにしたバイナリでもエラーは出ずに音飛びが
ある。
ExtAudioFileのディスクリプタを見つけて、むりやり一秒毎にfsyncしてみたが、
数分で音飛びが確認され一段と悪くなった。fs_usageで見るとこんな感じ。
07:29:10 pwrite 0.000211 Cat
07:29:10 pwrite 0.000191 Cat
07:29:11 pwrite 0.000178 Cat
07:29:11 fcntl 0.000028 Cat
07:29:11 fcntl 0.000002 Cat
07:29:11 fcntl 0.000001 Cat
07:29:11 fcntl 0.000009 Cat
07:29:11 fcntl 0.000005 Cat
07:29:11 fcntl 0.000005 Cat
07:29:11 fcntl 0.000006 Cat
07:29:11 fsync 0.000534 W Cat
10.5(ppc)でXcode 3.1.4のThread Viewerで確認してみた。
thr 512bがpwriteをおこなっていると思われるが、緑がRunningでありコストが
高そうなので、ここがコールバックのthr 04933をブロックすることで、音飛び
になっているのではないだろうか。
Thread ViewerはXcode 3.2系ではなぜか無くなっている。
WIFIの調子が悪かったので有線のLAN接続にしたところ、音飛びが起きなくなったよう
な気がする。そもそも留守録中はWIFIルータの電源を落としていて、OSが定期的に
アクセスポイントのスキャンをしていて、このときに接続できないので、処理コストが
大きくなっていたのかもしれない。考えてみるとiBook G3の頃は有線LAN接続していて、
この頃の方が安定していたような気がしていた。Pro Toolsの設定マニュアルにもWIFI
はOFFにしろと書いてある。ということで、この調査はこれで終わりになる事を
祈りたい。(2014/02/22)
Copyright (C) 2013 Hiroki Mori All Rights Reserved.