GStreamerのデコード停止について

いつもお世話になっております.

現在,armadillo-840でGStreamerを用いた映像を繰り返すプログラムを動作させています.
ある程度再生を繰り返していると再生できなくなってしまいます.
プログラムを停止し,再度動かすと再生できるようになります.

現在動かしているプログラムは,どうやらデコードが上手くいかなくなり停止してしまうようです.
自分のプログラムのバグの可能性も否定できませんが,
アットマークテクノさんの以下のページを拝見させていただき,カーネルによるバグの影響の可能性があると考えています.
http://armadillo.atmark-techno.com/node/1574

映像再生を繰り返し,デコードが停止してしまったとき,
プログラムを終了せずに,すみやかにデコードの停止を解除したいと考えています.
どうすればデコード停止を解除できるのか,どうしてデコードが停止してしまうかなど,
デコード停止について知っている方がいらっしゃいましたら教えていただけたらと思います.

使用している言語はC言語で,以下のページのソースコードを参考にしました.
http://oss.infoscience.co.jp/gstreamer/chapter-helloworld.html

よろしくお願いいたします.

製品: 
Armadillo-840

再生するデータによって発生頻度等に変化はあるでしょうか。
 
ArmadilloのsysfsにAVコーデックミドルウェアのデバッグメッセージを出力するフラグ
があるので、再生停止発生時のログを取得していただけますか。
次の2つのパラメーターを設定すると、/var/log/message にログが出力 されます。
 

[Armadillo ~]# echo 7 > /sys/module/acm/parameters/rto_debug 
[Armadillo ~]# echo 7 > /sys/module/acm/parameters/h264dec_debug 

 
再生停止発生からアプリケーションを停止した後を含むログがあると調査しやすいです。
 
また、ユーザーアプリケーションのプロセスを停止して、再度動かすと再生できる
ケースは当社では確認できていません。
 
- 当社で確認した条件
   -- gst-launchを使用して再生
   -- デコード停止からの復帰には一旦sysfsからコーデックのモードを
       noneまたはencoderに変更するまでデコード不能

もし可能であれば、再生停止の発生する最小構成のコードを教えていただけないでしょうか。

at_ohsawa様:

返信ありがとうございます.

教えていただいた方法でデバッグのログを取得しました.
添付してありますので,ご確認よろしくお願いいたします.

> 再生するデータによって発生頻度等に変化はあるでしょうか。
現在似たようなサイズの動画を再生していますが,1回目は同じ回数で落ちます.
プログラムの再起動を繰り返していると,次第に少ない再生回数で落ちるようになり,
最終的には再生できなくなりました.
明らかにサイズの違う動画の再生は未実験なので,これから確認してみます.

プログラム上でエラーメッセージを吐き出すようにしているのですが,
再生できなくなる前に以下のようなメッセージが出ます.(testはプログラム名)
================================================================================
(test:3642): GStreamer-CRITICAL **: gst_poll_write_control: assertion `set != NULL' failed

(test:3642): GStreamer-CRITICAL **: gst_poll_read_control: assertion `set != NULL' failed

(test:3642): GStreamer-CRITICAL **: gst_poll_write_control: assertion `set != NULL' failed

(test:3642): GStreamer-CRITICAL **: gst_poll_read_control: assertion `set != NULL' failed

(test:3642): GStreamer-CRITICAL **: gst_poll_write_control: assertion `set != NULL' failed

(test:3642): GStreamer-CRITICAL **: gst_poll_free: assertion `set != NULL' failed

(test:3642): GStreamer-CRITICAL **: gst_poll_write_control: assertion `set != NULL' failed

(test:3642): GStreamer-CRITICAL **: gst_poll_free: assertion `set != NULL' failed
=============================================================================

> もし可能であれば、再生停止の発生する最小構成のコードを教えていただけないでしょうか。

ほとんど参考にしたこちらのページとほぼ同じですが,念のために画像再生のソースを添付しておきます.
http://oss.infoscience.co.jp/gstreamer/chapter-helloworld.html
コンパイルの方法も同じHPを参考にしました.
http://oss.infoscience.co.jp/gstreamer/section-helloworld-compilerun.html

ご確認よろしくお願いいたします.

ファイル名 ファイルの説明
logmessage0623_00.txt デバッグのログ
play.c ソース

Armadillo-840 ACMデコーダ不具合修正 テスト用ファイルが出ましたので,
イメージを書き換えて,繰り返し動画再生プログラムを実行しました.
ですが,相変わらず途中でデコードができなくなってしまいます.

以前見落としていたのですが,デコードができなくなったときに以下のエラーメッセージが出ます.

Could not decode stream.
acm_aacdec: Failed to v4l2_m2m_streamoff

v4l2_m2m_streamoffを調べてみましたが,よくわかりませんでした.
何か知っている方がいらっしゃいましたら,教えていただけたらと思います.

資料として,デコードができなくなった時の/var/log/messageのログを添付してあります.
よろしくお願いします.

ファイル名 ファイルの説明
log.txt /var/log/messageです.

ご報告ありがとうございます。

こちらでも再現試験と解析を行いたいと思います。
昨年頂いた再現用のコードでは acm_aacdec を使っていないため
今回のテントでは別のコード使われているかと思います。
 
解析のため下記のコマンドで acm_aacdec のデバッグログも
有効にしたログをいただけないでしょうか。

 
[Armadillo ~]# echo 7 > /sys/module/acm/parameters/aacdec_debug 

 
また、再現試験と解析のため 、今回の繰り返し動画再生で利用された
コードとビルド済みバイナリ、再現する最小サイズのmp4ファイルも
頂けないでしょうか。

> 動画再生で利用されたコードとビルド済みバイナリ

加えて電源投入から再生停止までのテスト手順(テスト用のファイルの配置、
ストレージのマウント等の操作)も教えていただけると幸甚です。

at_ohsawa様:

返答ありがとうございます.

> こちらでも再現試験と解析を行いたいと思います。
> 昨年頂いた再現用のコードでは acm_aacdec を使っていないため
> 今回のテントでは別のコード使われているかと思います。

時間が空いていたため,ごちゃごちゃになっていました.すみません.
以前アップロードした,プログラムでも再現実験をおこないましたが,デコードが停止してしまいました.
acm_aacdecを使用したコードを提出ができませんので,
今回再現実験をしたプログラムとビルド済みバイナリを添付しておきます.
再現実験には,AVコーデックミドルウェアのセットに入っていたbig-buck-bunny-30sec-fullhd.mp4を使用しています.

再現実験は以下の手順でやっております.
1:起動
2:デコーダーを有効: echo decoder > sys/devices/platform/acm.0/codec
3:ビデオモード設定: echo D:1920x1080p-60 > /sys/class/graphics/fb0/mode
4:動画の入っているSDカードマウント: mount -t vfat /dev/mmcblk0p1 /mnt
5:/rootにバイナリを設置
6:動作再生スタート

今回添付したバイナリでは,/mnt/test.mp4の動画が再生されます.
また,デコードが停止すると,プログラムが終了するようになっています.

ファイル名 ファイルの説明
play.bin バイナリデータ
play1.c ソースコード

上で添付したソースコードファイルですが,
バイナリと読込んでいる動画ファイル名が違います.
ビルドする場合は,82行目を修正して下さい.
申し訳ありません.

ありがとうございます。
こちらでも再現テスト行ってみます。

hakamata 様

ご報告いただき、ありがとうございます。
再現いたしました。

play1.cのwhileループの最後に、500ms程度のsleepを入れると
とりあえずは回避できるかと思います。

停止した際の状況がこちらと同様かは、テスト時に

GST_DEBUG=3 ./play.bin

 
というようにWARNまでのメッセージ表示を有効にすると
停止の際に下記のメッセージが見えると思います。
 

Movie Times = 203
2:13:32.010273957  4987    0xce6c0 ERROR            acmv4l2util gstacmv4l2_util.c:144:gst_acm_v4l2_open: Could not open device '/dev/video1' for reading and writing.
2:13:32.010487040  4987    0xce6c0 ERROR            acmv4l2util gstacmv4l2_util.c:144:gst_acm_v4l2_open: Could not open device '/dev/video0' for reading and writing.
2:13:32.010825040  4987    0xce6c0 ERROR            acmv4l2util gstacmv4l2_util.c:133:gst_acm_v4l2_open: Cannot identify device '(null)'.
2:13:32.010994373  4987    0xce6c0 WARN              acmh264dec gstacmh264dec.c:501:gst_acm_h264_dec_open:<acmh264-decoder> error: Failed open device (null). (Bad address)
2:13:32.011207790  4987    0xce6c0 WARN            videodecoder gstvideodecoder.c:2043:gst_video_decoder_change_state:<acmh264-decoder> error: Failed to open decoder
Running...
Error: Resource not found.
Returned, stopping playback
Deleting pipeline

これは、停止が発生した最後の周回で、acm_h264decエレメントが、acm_h264decの
デバイスファイルを探すために、/dev/video0(acm_h264dec), /dev/video1(acm_aacdec)
をopenして失敗している事を示しています。

ACMデバイスドライバでは、多重openを禁止しているのですが、その処理にバグがある
可能性が高いです。
デバイスドライバ側の修正か、libgstreamerを使う際にEOS後の処理で対応する見込みで
調査中です。

次回のアップデートに組込みたいと思います。
重ねてお礼申し上げます。

at_ohsawa様

検証ありがとうございました.
アップデートでの修正を待ちたいと思います.

あと,念のためにご報告なのですが,
play1.cのwhileループの最後にsleepを入れましたが,停止の回避はできませんでした.
長めにとって3secのsleepしましたが,同じ回数で止まってしまいます.

以上,失礼いたしました.

大変遅くなってしまい、申し訳ございません。

> armadillo-840でGStreamerを用いた映像を繰り返すプログラムを動作させています.
> ある程度再生を繰り返していると再生できなくなってしまいます.
上記の問題を修正しました。
最新のソフトウェアで試してみてください。

アップデートの詳細は下記ページをご覧ください。

Armadillo 製品アップデートのお知らせ (2015年2月/Armadillo-800シリーズ対象)
http://armadillo.atmark-techno.com/news/20150225/software-update-a800

at_kojiro.yamada様

2月にアップデートされた標準イメージファイルをArmadillo840にいれて確認してみました.
停止するまでの回数が延びましたが,以前と同じように毎回同じ回数で停止します.

GST_DEBUG=3 ./play.bin
上記で実行してみたところ,停止してしまう回で以下のWARNが出ました.

0:45:16.718016827  6468    0xce6c0 WARN            acmfbdevsink gstacmfbdevsink.c:588:gst_acm_fbdevsink_start:<device> error: error with ioctl(FBIOGET_DMABUF) 24 (Too many open files)

以上,です.

> 大変遅くなってしまい、申し訳ございません。
>
> > armadillo-840でGStreamerを用いた映像を繰り返すプログラムを動作させています.
> > ある程度再生を繰り返していると再生できなくなってしまいます.
> 上記の問題を修正しました。
> 最新のソフトウェアで試してみてください。
>
> アップデートの詳細は下記ページをご覧ください。
>
> Armadillo 製品アップデートのお知らせ (2015年2月/Armadillo-800シリーズ対象)
> http://armadillo.atmark-techno.com/news/20150225/software-update-a800
>

お手数ですが下記コマンドを実行した時のログをいただけますか?

※最後のコマンドは play.bin の再生が停止した後に実行

[Armadillo]# gst-inspect-1.0 acmfbdevsink
[Armadillo]# GST_DEBUG=3 ./play.bin &
[Armadillo]# ps aux | grep "play.bin"
[Armadillo]# ls -l /proc/<play.binのpid>/fd/

申し訳ありません。
以下、訂正いたします。


> ※最後のコマンドは play.bin の再生が停止した後に実行

※最後のコマンドは play.bin の再生が停止する前に複数回実行

以下、補足になります。

gst-inspect-1.0 acmfbdevsinkで

  Version:              1.0.1

が表示されていれば、以下の問題が修正されたイメージで起動できています。

修正前のイメージではファイルのクローズ漏れがあったため、
ls /proc/< play.binのpid>/fd で表示される数値が増えていくのですが、
修正後のイメージでは、増えていかないはずです。

at_kojiro.yamada様

ログをとりましたので,ご確認よろしくお願いします.

acmfbdevsink.txt :[Armadillo]# gst-inspect-1.0 acmfbdevsink
play.txt :[Armadillo]# GST_DEBUG=3 ./play.bin & (長いので最初と最後)
ps.txt :[Armadillo]# ps aux | grep "play.bin" (終了直前のログ)
proc_pid_fd.txt :[Armadillo]# ls -l /proc//fd/

何度か/proc/pdi/fdの中身を見ましたが,どんどん増えているようです.

Armadillo-840には最新の以下の標準イメージファイルをいれております.
linux-a840-v1.07.bin.gz
romfs-a840-v1.05.img.gz
squashfs-a800-firmware-v3.01.img

何かお気づきの点がありましたら,よろしくお願いします.
失礼いたしました.

ファイル名 ファイルの説明
acmfbdevsink.txt
play.txt
proc_pid_fd.txt
ps.txt

大変申し訳ございません。
今回修正した箇所とは別の箇所でクローズ漏れが起きているようです。

いただいたログをもとに解析し、問題修正の後、再度お知らせいたします。

以上、よろしくお願いいたします。

acmfbdevsink と acmh264dec の間で共有しているファイルディスクリプタの
close漏れを修正しました。

リリース前のテスト版として修正パッチを作成しましたので、
修正後のプラグイン(libgstacmfbdevsink.so, libgstacmh264dec.so)
と共に添付します。
/usr/lib/gstreamer-1.0/以下の
  libgstacmfbdevsink.so
  libgstacmh264dec.so
を添付したプラグインと差し替えてご利用ください。

play.binを実行してファイルディスクリプタがリークしていない
ことを確認しています。

■動作確認方法
Armadillo起動後、添付した
  libgstacmfbdevsink.so
  libgstacmh264dec.so
をArmadilloに移動させ、以下のコマンドを実行します。

[Armadillo]# cp ./libgstacmfbdevsink.so /usr/lib/gstreamer-1.0/libgstacmfbdevsink.so
[Armadillo]# cp ./libgstacmh264dec.so /usr/lib/gstreamer-1.0/libgstacmh264dec.so
[Armadillo]# GST_DEBUG=3 ./play.bin &
[Armadillo]# ps aux | grep "play.bin"
[Armadillo]# ls -l /proc/<play.binのpid>/fd/

■パッチのあて方
添付したパッチをダウンロードし、以下のコマンドを実行します。

[ATDE]$ wget http://download.atmark-techno.com/armadillo-840/cross-dev/source/gst-plugins-at-acm_1.0.1.tar.gz
[ATDE]$ ls gst-plugins-acm_1.0.1_fix-fd-leaks.patch gst-plugins-at-acm_1.0.1.tar.gz
gst-plugins-acm_1.0.1_fix-fd-leaks.patch gst-plugins-at-acm_1.0.1.tar.gz
[ATDE]$ tar xzvf gst-plugins-at-acm_1.0.1.tar.gz
[ATDE]$ cd gst-plugins-at-acm_1.0.1
[ATDE]$ patch --dry-run -p2 < ../gst-plugins-acm_1.0.1_fix-fd-leaks.patch
ファイル名 ファイルの説明
fixed_gst-plugins-acm_1.0.1.tar.gz 修正後のプラグイン(libgstacmfbdevsink.so, libgstacmh264dec.so)のアーカイブ
gst-plugins-acm_1.0.1_fix-fd-leaks.patch fdリーク修正パッチ

at_kojiro.yamada様

修正後のプラグインをArmadilloにコピーして動作確認をおこないました。
play.binを1日回してみましたが、/proc//fd/の中のファイルが増えることなく、
停止せずに動画の連続再生ができました。
音声再生を組み込んだプログラムでも半日ほど回していますが、問題はなさそうです。
ありがとうございました。

また何かありました時には、ご質問等させていただくと思います。
その際にもよろしくお願いします。

https://users.atmark-techno.com/comment/1640#comment-1640
で添付したパッチとは実装が異なりますが、
gst-plugins-at-acm_1.0.2で問題は修正されました。

ATDE5には、v20150423から
上記の問題修正済みのプラグインがインストールされています。