一時的に再生が停滞して10数秒後に再開

フォーラム TuneBrowser 一時的に再生が停滞して10数秒後に再開

  • このトピックには34件の返信、2人の参加者があり、最後にNoirにより11ヶ月、 3週前に更新されました。
35件の投稿を表示中 - 1 - 35件目 (全35件中)
  • 投稿者
    投稿
  • #13306
    Noir
    参加者

    Tikiさん、はじめまして。

    タイトルの現象は 5.2.2 UWP 版で以下の状況で発生しました。

    ・RAMDecode(すべて)
    ・ランダム再生
    ・WASAPI(Exclusive Event)

    現象発生中の動画を添付します。
    (*動画は466kBまでサイズを落としていますが不適切でしたら削除お願いいたします)

    現象が発生してからの記録のため途中からですが、再生時間 0:51 で Player View の Time やインジゲーターが止まり、フリーズしかたかな?!と思ったのですが、録画中に 0:52, 0:53 と普通に再生が再開しました。現象発生から10数秒くらいだと思います。

    なお、今回はじめて発生しました。これまでは以下の設定にしており、先週水木金土の4日間毎日10時間連続再生で発生しませんでした。

    ・RAMDecode(すべて)
    ・リピート再生
    ・Bit Perfect(BP2)
    ・WASAPI(Exclusive Event)

    リピート再生の有無とランダム再生の有無とBP2の有無が違いとなります。

    これだけで原因を特定することは難しいと思いますので、次回発生時に何か調査のために役立つ情報収集ができれば、と思い投稿させていただきました。

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

    Attachments:
    #13311
    Tiki
    キーマスター

    こんにちは。適切なサイズの動画ありがとうございます。

    デコード待ちが発生したのかと予想しましたが、そうではありませんでした。スペクトル表示も完全に止まっていることから、おそらくビデオカードあたりで一時的なフリーズが発生したのではないかと思います (わたしのPCも含めて、環境によってはときどき発生しています。長くなると「予期しない状態を検知した」と表示されることもあります)。

    #13313
    Noir
    参加者

    Tikiさん、早速のご返事ありがとうございます。

    恥ずかしながら Log Viewer の存在を知らなかったのですけど、フォーラムの他の投稿を拝見して存在を知りました。今度発生したときはログも参照してみます。

    #13335
    Noir
    参加者

    本日、再発しました。
    Log Viewer の「Log」を拝見すると同じ曲が短時間に呼び出されていました。

    また「Player」を拝見すると 23:08 以前のログが消えていたので Nat King Cole\St. Louis Blues\05 Stay.wav のみの確認となりますが、デバイスのリスタートがなぜか走っていて、起動後同じ 72 秒にシークして再生するも再びリスタートする、という状況が 0.12~0.15 秒程度の間隔で繰り返されている状況でした。

    UL32621: 2023/04/07 23:08:32,561: T00d2c: TL17: Restart device.
    UL32742: 2023/04/07 23:08:32,600: T00d2c: TL17: Post PlayerNotify: 8677 [Seeked]
    UL32760: 2023/04/07 23:08:32,689: T00d2c: TL17: Proc: [Seek] to 72.000 sec.
    UL32761: 2023/04/07 23:08:32,689: T00d2c: TL17: Restart device.
    UL32882: 2023/04/07 23:08:32,723: T00d2c: TL17: Post PlayerNotify: 8685 [Seeked]
    UL32900: 2023/04/07 23:08:32,837: T00d2c: TL17: Proc: [Seek] to 72.000 sec.
    UL32901: 2023/04/07 23:08:32,837: T00d2c: TL17: Restart device.
    UL33022: 2023/04/07 23:08:32,871: T00d2c: TL17: Post PlayerNotify: 8693 [Seeked]
    UL33040: 2023/04/07 23:08:32,954: T00d2c: TL17: Proc: [Seek] to 72.000 sec.
    UL33041: 2023/04/07 23:08:32,954: T00d2c: TL17: Restart device.
    UL33162: 2023/04/07 23:08:32,989: T00d2c: TL17: Post PlayerNotify: 8701 [Seeked]
    UL33180: 2023/04/07 23:08:33,305: T00d2c: TL17: Proc: [Seek] to 72.080 sec.
    UL33181: 2023/04/07 23:08:33,305: T00d2c: TL17: Restart device.
    UL33303: 2023/04/07 23:08:33,349: T00d2c: TL17: Post PlayerNotify: 8709 [Seeked]
    UL33320: 2023/04/07 23:08:33,458: T00d2c: TL17: Proc: [Seek] to 72.000 sec.
    UL33321: 2023/04/07 23:08:33,458: T00d2c: TL17: Restart device.

    Attachments:
    #13337
    Noir
    参加者

    「Log」の該当箇所を張り付けそこないましたので追記します。

    UL32606: 2023/04/07 23:08:32,423: T0199c: Calling Lua: OnPlaybackFile
    UL32607: 2023/04/07 23:08:32,423: T0199c: – C:\Users\barod\Music\Nat King Cole\St. Louis Blues\05 Stay.wav
    UL32608: 2023/04/07 23:08:32,423: T0199c: – 0
    UL32609: 2023/04/07 23:08:32,423: T0199c: Calling Lua: Results:
    UL32610: 2023/04/07 23:08:32,423: T0199c: –
    UL32611: 2023/04/07 23:08:32,423: T0199c: –
    UL32746: 2023/04/07 23:08:32,609: T0199c: Calling Lua: OnPlaybackFile
    UL32747: 2023/04/07 23:08:32,609: T0199c: – C:\Users\barod\Music\Nat King Cole\St. Louis Blues\05 Stay.wav
    UL32748: 2023/04/07 23:08:32,609: T0199c: – 0
    UL32749: 2023/04/07 23:08:32,610: T0199c: Calling Lua: Results:
    UL32750: 2023/04/07 23:08:32,610: T0199c: –
    UL32751: 2023/04/07 23:08:32,610: T0199c: –
    UL32886: 2023/04/07 23:08:32,733: T0199c: Calling Lua: OnPlaybackFile
    UL32887: 2023/04/07 23:08:32,733: T0199c: – C:\Users\barod\Music\Nat King Cole\St. Louis Blues\05 Stay.wav
    UL32888: 2023/04/07 23:08:32,733: T0199c: – 0
    UL32889: 2023/04/07 23:08:32,734: T0199c: Calling Lua: Results:
    UL32890: 2023/04/07 23:08:32,734: T0199c: –
    UL32891: 2023/04/07 23:08:32,734: T0199c: –
    UL33026: 2023/04/07 23:08:32,875: T0199c: Calling Lua: OnPlaybackFile
    UL33027: 2023/04/07 23:08:32,875: T0199c: – C:\Users\barod\Music\Nat King Cole\St. Louis Blues\05 Stay.wav
    UL33028: 2023/04/07 23:08:32,875: T0199c: – 0
    UL33029: 2023/04/07 23:08:32,875: T0199c: Calling Lua: Results:
    UL33030: 2023/04/07 23:08:32,875: T0199c: –
    UL33031: 2023/04/07 23:08:32,875: T0199c: –

    #13339
    Tiki
    キーマスター

    こんにちは。

    ログのアップありがとうございます。この事象は、最初にご報告いただいた画面・操作のフリーズが発生したあと、発生したということでしょうか?

    デバイスののスタートは、設定項目の

    ■ ツリー項目: 再生の設定 – WASAPIの設定 – (デバイス名)
    ■ プロパティ: 基本の設定 – 再生終了時にデバイスも終了させる

    がYesになっていると、シーク操作後に発生します (既定でYesになっています)。これはシーク時に一時的にデバイスを停止させた後、再開始に失敗するデバイスがあったためで、シークの都度そのように動作させるようになります。

    今回のログでは見た目には何回もシーク操作が行われたかのような動作になっています。操作がフリーズしている間に、そのような操作をされたということはないでしょうか?

    #13340
    Noir
    参加者

    こんにちは、ご返信ありがとうございます。

    はい、こちらは昨夜発生した現象になります。

    実際手動でのシーク操作はしていない状況でございます。120~150 m sec 間隔での細かい手動操作を数秒間継続して行うことは不可能だと思います。

    デバイスのリスタートの解釈が違っていたのでご教授ありがとうございます。デバイス側からリセットがかかっているわけではなかったのですね。

    このときは席を外していたので聞いていなかったのと、Log Viewer の Play には残っていなかったのですが、Log には 22:52:34,918 – 22:54:08,500 の間、22:58:15,965 ー 22:58:25,935 の間、22:58:45,592 ー 22:59:07,887  の間にも「Calling Lua: OnPlaybackFile」が連続して記録されています。

    考えられる原因はございますでしょうか?

    #13343
    Tiki
    キーマスター

    シーク操作は、短い間隔で連続して操作されたと考えているわけではなく、時間を置いて操作された結果がフリーズ解除後に一気に処理されたのかと考えました。

    他には現在のところ考えられる原因はありません。引き続き検討します。

    #13344
    Noir
    参加者

    お力添えありがとうございます。

    ログをディスクに出力できる設定項目を発見したので、本日からディスクに書き出してみます。
    また UWP版も5.2.3が配信されましたので、本日より5.2.3で運用いたします。

    お手数をおかけいたしております。
    引き続きどうぞよろしくお願いします。

    #13359
    Noir
    参加者

    こんばんは!

    土曜日は現象発生しませんでしたが、本日は現象が発生し、プレイヤーの起動から現象発生までのログが取得できましたので送ります。

    1. 17:12:13 ~ 22:08:00 までエラーなく再生
    2. 22:08:00,816 にアルバムを手動で切り替え
    3. 22:09:18,599 から Seek 77sec が連続して記録
      22:09:18,599: T00a28: TL18: Proc: [Seek] to 77.420 sec.

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

    Attachments:
    #13363
    Tiki
    キーマスター

    こんばんは。ログの送付ありがとうございました。

    内容拝見しましたが、たしかに不可思議にSeekが繰り返されていることは確認できましたが、なぜそのような動作になっているのかはわかりませんでした。

    Noirさんは、UWP版をご利用と伺いました。最近のマイクロソフトストアは、特定のユーザー向けにプライベートなリリースを行える機構がありますので、Noirさん向けに、この問題調査用の仕掛けを入れたTuneBrowserをリリースさせていただきたいと思います。

    今回のケースは経験したことのない事象のため、おそらく一度では解決できず、複数回のやりとりになると思われます。どうぞその点についてご了承ください。

    ご利用のマイクロソフトアカウントは、このフォーラムの登録メールアドレスとおなじでしょうか。異なる場合、ここにはメールアドレスは書かないで、ちがうという旨だけお知らせください。わたしから照会用のメールをお出しさせていただきます。

    #13364
    Noir
    参加者

    ご返信および多大なご協力ありがとうございます!

    2つのアカウントで使用させていただいてますが、フォーラム用のアドレスはどちらとも異なってます。

    よろしくお願いします。

    #13366
    Tiki
    キーマスター

    こんばんは。

    アカウントの情報ありがとうございました。先ほど、お届けいただいた2つのメールアドレスに対して調査用のTuneBrowserのリリース手続きを行いました。これはマイクロソフトがパッケージフライトと呼んでいるリリース方式ですが、これも通常と同様にマイクロソフトストアの審査があります。そのため少々時間がかかるかもしれません。

    今回のリリースでは、短時間にSeekが複数回発生すると(1秒間に4回です)、その状態を検出してダンプファイルを生成するようにしています。予期しない状態を検出したという文言と操作を問い合わせるダイアログボックスが表示されますので、送信を選択してください。

    この予期しない状態の検出は、連発しないように1日1回だけ行われるようにしています。

    わたしの環境では再現しない状況で検出の仕掛けを実装したので、もしかしたらうまく動作しない可能性もあります。現象が発生しているはずなのに検出できていないようであれば、お知らせくださると助かります。

    よろしくお願いします。

    #13367
    Tiki
    キーマスター

    マイクロソフトストアから、フライトが公開されたとの連絡がありました。思ったより早かったです。Version は5.2.4です。

    それともう一点、お伝えするのを忘れました。このバージョンはわたしの手許の開発中のものです。そのため5.2.3とは動作が異なるところがあります。ご了承ください。もし支障があれば、お知らせください。

    #13369
    Noir
    参加者

    ありがとうございます!

    たまたま先ほどの投稿をみてマイクロソフトストアで更新をチェックしたらダウンロードできてたので早いなー、と思ってたところです。

    マイクロソフトさんからも連絡がいくのですね。親切ですね。

    早速、この環境で再生してみますね!

    引き続きどうぞよろしくお願いいたします!!

    Attachments:
    #13379
    Noir
    参加者

    4/12-15の4日間は現象発生なしでした。

    前回、プレイリストを変えてから77秒という状況だったので、今週は試しに夕方に12-15時間分くらいのプレイリストを用意して、そのまま9-10時間TuneBrowserを操作しないで再生、という状況を試してみました。

    この条件で4日間、現象出ていません。

    そして、週明けは前回発生時のように、夕方に12-15時間分くらいのプレイリストを用意して再生をはじめるところまでは同じで、4-5時間経過後の21-22時くらいを目処に、プレイリストに含まれていない他のアルバムを選択する、という状況を試してみます。

    現象発生の有無はたまたまなのかも知れませんが、ご連絡まで。

    引き続きよろしくお願いいたします。

    #13380
    Tiki
    キーマスター

    状況のご報告ありがとうございました。

    引き続き、よろしくお願いします。

    #13410
    Noir
    参加者

    結論から申し上げますと、先週は一度も発生しませんでした。

    先週は前回発生時のように、夕方に12-15時間分くらいのプレイリストを用意して再生をはじめ、4-5時間経過後の21-22時くらいを目処に、プレイリストに含まれていない他のアルバムを選択する、という状況を月ー土と試しました。

    せっかく仕込みを入れてくださったのに、一週間まるまる現象が発生しなかった状況ははじめてで、申し訳ない気持ちでおります。本来現象が出ないのはいいことなのですが、調べたいときに出ないのは困りますね。。。

    引き続き使用してまいりますので、よろしくお願いいたします。

    #13411
    Tiki
    キーマスター

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

    もうしばらく、待ってみましょうか。よろしくお願いします。

    #13415
    Noir
    参加者

    こんばんは

    ひさしぶりに現象が発生しました!
    先ほどダンプファイルを送付させていただきました。

    1点、自動的にダイアログが表示されると思っていたのですけど、現象発生時に送信ダイアログは表示されませんでした。今回はログに以下の項目が残っていたので、手動で「ヘルプ」ー「ダンプファイル」ー「ダンプファイルの確認」を実行したところ見つかったので送付いたしました。

    UL04710: 2023/04/24 23:17:16,591: T012f4: Generating dumpfile for unexpected state.

    また、念のため現象発生時のログも添付いたします。

    ダンプファイルの生成はお伝えいただいたとおり1日1度のみの生成でしたが、現象はこのあとも別の曲で発生していることがログから確認できました。

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

    Attachments:
    #13417
    Tiki
    キーマスター

    ダンプファイル受領しました。ありがとうございます。

    内容を確認して、またご報告します。

    #13418
    Noir
    参加者

    大変お手数をおかけいたします。

    ご調査よろしくお願いいたします。

    #13419
    Tiki
    キーマスター

    こんばんは。

    内容確認しました。事象はしっかり記録されていました。

    シークが繰り返された原因は、やはり短時間の間にマウスによるシーク操作が行われたためでした (1秒間に数回以上)。Noirさんがそんなに短時間にシーク操作を行うことはできないと言われていたことは承知しています。ですが、記録上はシークバーのコントロールに対して、マウス操作が行われてイベントが発生しています。

    なにかそういった操作を発生させるような他のアプリケーションなどをご利用でないでしょうか。わたしも具体的には思いつきませんが…。

    よろしくお願いします。

    #13420
    Noir
    参加者

    ご確認ありがとうございます。

    サウンドデバイスになんらかのエラーが発生しているのかな、と思いましたが、想定外のご回答でした。

    はじめのころに送った動画ではマウスカーソルが映ってなかったように、基本的に再生中はpc自体を操作しないので謎は深まりました。

    以前と今回お送りしたログを拝見するとアルバムを切り替えて大体77秒というあたりの時間で現象がはじまってる点は気がかりです。

    (それ以降の現象発生時は77秒ではないのですが、きっかけとなる最初の発生時は77秒)

    またマウスクリックのイベントが再生や停止ボタンではなく、都合よくシークバーに行くものなのか、という疑問もございます。

    今回の現象発生時、目の前に居なかったので逆にお聞きしたいのですが、ウインドウの状態はフォアグラウンドにありましたでしょうか?

    バックグラウンドもしくは最小化することで回避できるものかわからないのですが、マウスイベントが何かしらの理由で誤クリックが発生するのであれば、最小化するという回避方法もありかな、と思いました。

    #13421
    Tiki
    キーマスター

    動画で確認できるのは、描画がフリーズしているということだったかと思います。その事象とシーク操作の連発とが、どういう関係にあるのかは、わたしにはわかりません。シーク操作が連発したから描画がフリーズしたのか、描画がフリーズする事象が発生したからシーク操作が連発したのか、という話ですが…。

    ウインドウの状態はフォアグラウンドにありましたでしょうか?

    ログをたどってみましたが、それ関係のイベントの記録はなく、わかりませんでした。

    参考になるかどうかわかりませんが、ある連続操作のところのログは以下のような感じです。CTBarSliderCtrlはシーク用のスライダコントロール、OnLButtonDownはマウスボタンを押したイベント、OnLButtonUpはマウスボタンを離したイベント、時刻の “23:17:17,004.3101” の004.3101はミリ秒です。23:17:17に4回のマウスボタン操作の記録があります。

    2023/04/24 23:17:17,004.3101 00002d34 TB::CTBarSliderCtrl::OnLButtonDown
    2023/04/24 23:17:17,009.5103 00002d34 TB::CTBarSliderCtrl::OnLButtonUp
    2023/04/24 23:17:17,016.5236 00002d34 TB::CTBarSliderCtrl::OnLButtonDown
    2023/04/24 23:17:17,019.9919 00002d34 TB::CTBarSliderCtrl::OnLButtonUp
    2023/04/24 23:17:17,029.6875 00002d34 TB::CTBarSliderCtrl::OnLButtonDown
    2023/04/24 23:17:17,033.8597 00002d34 TB::CTBarSliderCtrl::OnLButtonUp
    2023/04/24 23:17:17,082.1819 00002d34 TB::CTBarSliderCtrl::OnLButtonDown
    2023/04/24 23:17:17,146.1015 00002d34 TB::CTBarSliderCtrl::OnLButtonUp
    #13422
    Noir
    参加者

    ご連絡ありがとうございます。

    こちらでどのような情報がログに記録されるか、試してみたのですが、このマウスイベントはログファイルには記録されていないダンプファイル固有の情報のようですね。

    参考までに、キーボード入力の場合は違う記録がされますでしょうか?

    OnLButtonDown と OnLButtonUp および GetCursorPos() などでカーソル位置を取得して Player ログに出力いただくことは可能でしょうか?キーボードイベントなども記録できるとありがたいです。

    https://learn.microsoft.com/ja-jp/windows/win32/api/winuser/nf-winuser-getcursorpos

    #13424
    Noir
    参加者

    続けて失礼いたします。

    #13415で添付いたしました「2023-04-24Log.zip」のログと「OnLButtonDown」および「OnLButtonUp」の時系列が気になりましたので共有させていただきます。

    現象発生時の Log ファイルです

    UL04236: 2023/04/24 23:17:16,042: T027a0: Calling Lua: OnPlaybackFile
    UL04237: 2023/04/24 23:17:16,042: T027a0: - C:\Users\barod\Music\Harry Connick Jr\Only You\01 More.wav
    UL04238: 2023/04/24 23:17:16,042: T027a0: - 0
    UL04239: 2023/04/24 23:17:16,043: T027a0: Calling Lua: Results:
    UL04240: 2023/04/24 23:17:16,043: T027a0: -
    UL04241: 2023/04/24 23:17:16,043: T027a0: -
    UL04392: 2023/04/24 23:17:16,216: T027a0: Calling Lua: OnPlaybackFile
    UL04393: 2023/04/24 23:17:16,216: T027a0: - C:\Users\barod\Music\Harry Connick Jr\Only You\01 More.wav
    UL04394: 2023/04/24 23:17:16,216: T027a0: - 0
    UL04395: 2023/04/24 23:17:16,217: T027a0: Calling Lua: Results:
    UL04396: 2023/04/24 23:17:16,217: T027a0: -
    UL04397: 2023/04/24 23:17:16,217: T027a0: -
    UL04541: 2023/04/24 23:17:16,330: T027a0: Calling Lua: OnPlaybackFile
    UL04542: 2023/04/24 23:17:16,330: T027a0: - C:\Users\barod\Music\Harry Connick Jr\Only You\01 More.wav
    UL04543: 2023/04/24 23:17:16,330: T027a0: - 0
    UL04544: 2023/04/24 23:17:16,330: T027a0: Calling Lua: Results:
    UL04545: 2023/04/24 23:17:16,330: T027a0: -
    UL04546: 2023/04/24 23:17:16,330: T027a0: -
    UL04690: 2023/04/24 23:17:16,479: T027a0: Calling Lua: OnPlaybackFile
    UL04691: 2023/04/24 23:17:16,479: T027a0: - C:\Users\barod\Music\Harry Connick Jr\Only You\01 More.wav
    UL04692: 2023/04/24 23:17:16,479: T027a0: - 0
    UL04693: 2023/04/24 23:17:16,480: T027a0: Calling Lua: Results:
    UL04694: 2023/04/24 23:17:16,480: T027a0: -
    UL04695: 2023/04/24 23:17:16,480: T027a0: -
    UL04710: 2023/04/24 23:17:16,591: T012f4: Generating dumpfile for unexpected state.

    続いて、#13421 でお伝えいただいた「OnLButtonDown」および「OnLButtonUp」の時刻です

    2023/04/24 23:17:17,004.3101 00002d34 TB::CTBarSliderCtrl::OnLButtonDown
    2023/04/24 23:17:17,009.5103 00002d34 TB::CTBarSliderCtrl::OnLButtonUp
    2023/04/24 23:17:17,016.5236 00002d34 TB::CTBarSliderCtrl::OnLButtonDown
    2023/04/24 23:17:17,019.9919 00002d34 TB::CTBarSliderCtrl::OnLButtonUp
    2023/04/24 23:17:17,029.6875 00002d34 TB::CTBarSliderCtrl::OnLButtonDown
    2023/04/24 23:17:17,033.8597 00002d34 TB::CTBarSliderCtrl::OnLButtonUp
    2023/04/24 23:17:17,082.1819 00002d34 TB::CTBarSliderCtrl::OnLButtonDown
    2023/04/24 23:17:17,146.1015 00002d34 TB::CTBarSliderCtrl::OnLButtonUp

    同時刻の Player ログには以下のみが記録されており、ファイルやデバイスに関する処理が記録されていません。また、Log ファイルには現象発生時に記録されている Calling Lua: OnPlaybackFile の記録がないようです。

    UL04711: 2023/04/24 23:17:17,013: T02d34: TL18: Process seek message: 77.1
    UL04712: 2023/04/24 23:17:17,014: T02d34: TL18: Process seek: 77.1
    UL04713: 2023/04/24 23:17:17,014: T02d34: TL18: Apply current seek value to player: 77.1
    UL04714: 2023/04/24 23:17:17,015: T02d34: TL18: Requesting player command: [Seek]
    UL04715: 2023/04/24 23:17:17,023: T02d34: TL18: Process seek message: 77.0
    UL04716: 2023/04/24 23:17:17,027: T02d34: TL18: Process seek: 77.0
    UL04717: 2023/04/24 23:17:17,028: T02d34: TL18: Apply current seek value to player: 77.0
    UL04718: 2023/04/24 23:17:17,028: T02d34: TL18: Requesting player command: [Seek]
    UL04719: 2023/04/24 23:17:17,038: T02d34: TL18: Process seek message: 77.0
    UL04720: 2023/04/24 23:17:17,039: T02d34: TL18: Process seek: 77.0
    UL04721: 2023/04/24 23:17:17,039: T02d34: TL18: Apply current seek value to player: 77.0
    UL04722: 2023/04/24 23:17:17,039: T02d34: TL18: Requesting player command: [Seek]
    UL04723: 2023/04/24 23:17:17,150: T02d34: TL18: Process seek message: 77.0
    UL04724: 2023/04/24 23:17:17,151: T02d34: TL18: Process seek: 77.0
    UL04725: 2023/04/24 23:17:17,151: T02d34: TL18: Apply current seek value to player: 77.0
    UL04726: 2023/04/24 23:17:17,151: T02d34: TL18: Requesting player command: [Seek]

    また、それぞれのクリック速度が 5.2ms, 3.5ms, 4.2ms, 63.9ms と爆速なのでプログラムでしか実現できなさそうですが、該当マシンには自動化ツールのようなアプリをインストールしていないし思い浮かばない、という状況です。

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

    #13427
    Noir
    参加者

    Alt+Shift+x でコードに成形したらライン別になってしまいました。

    「編集」を試みたのですが一定時間経過で間に合わず。読みにくくてすみません。。。

    #13428
    Tiki
    キーマスター

    例が悪かったようですみません。前後も含めたログを再掲させていただきます。

    2023/04/24 23:17:15,994.0768 00002d34 CTBarSliderCtrl::OnLButtonUp
    2023/04/24 23:17:15,999.6647 000012f4 Processing PlayerCmd:[Seek]
    2023/04/24 23:17:16,042.9781 000027a0 Calling Lua: OnPlaybackFile
    2023/04/24 23:17:16,154.0533 00002d34 CTBarSliderCtrl::OnLButtonUp
    2023/04/24 23:17:16,159.4184 000012f4 Processing PlayerCmd:[Seek]
    2023/04/24 23:17:16,216.7780 000027a0 Calling Lua: OnPlaybackFile
    2023/04/24 23:17:16,281.9767 00002d34 CTBarSliderCtrl::OnLButtonUp
    2023/04/24 23:17:16,286.9115 000012f4 Processing PlayerCmd:[Seek]
    2023/04/24 23:17:16,330.5251 000027a0 Calling Lua: OnPlaybackFile
    2023/04/24 23:17:16,434.4246 00002d34 CTBarSliderCtrl::OnLButtonUp
    2023/04/24 23:17:16,440.0747 000012f4 Processing PlayerCmd:[Seek]
    2023/04/24 23:17:16,479.8746 000027a0 Calling Lua: OnPlaybackFile
    2023/04/24 23:17:16,586.1570 00002d34 CTBarSliderCtrl::OnLButtonUp
    2023/04/24 23:17:16,591.6618 000012f4 Processing PlayerCmd:[Seek]
    2023/04/24 23:17:16,591.6794 000012f4 UnexpectedState caused: TooManySeek.
    2023/04/24 23:17:17,009.5103 00002d34 CTBarSliderCtrl::OnLButtonUp
    2023/04/24 23:17:17,019.9919 00002d34 CTBarSliderCtrl::OnLButtonUp
    2023/04/24 23:17:17,033.8597 00002d34 CTBarSliderCtrl::OnLButtonUp
    2023/04/24 23:17:17,146.1015 00002d34 CTBarSliderCtrl::OnLButtonUp

    ここで、2023/04/24 23:17:16,591.6794で予期しない状態を検出しており、その後の2023/04/24 23:17:17以降のシークはこのログの範囲では処理されていませんでした。ここで挙げたログでは、23:17:15~23:17:16の間にも同様の事象が発生しています。気にされていたCalling Luaの行も含めてあります。

    お詳しいようですのでさらに付加情報を申し上げると、00002d34とか000012f4はスレッドのIDです。2023/04/24 23:17:16,591.6794で再生制御を行っているスレッドが予期しない状態を検出しているため、23:17:17以降の操作はすぐには処理されない状態になっています。

    スライダーによるシーク操作が短時間に連発していることについて、不思議に思われるのは当然と思います。わたしにもわかりません。すくなくともそのタイミングでのリアルタイムでのマウス操作ではないような気がします。ただTuneBrowserから見ると、スライダーが連続で操作されてその処理を行ったようにしか見えません。

    ログの追加のご依頼もありましたが、すみませんがこれ以上のTuneBrowserを改修しての対応はご容赦いただければと思います。

    あと、キーボード操作はマウスボタンではないので、一般にはキーボード操作をしたからといってマウスイベントが発生することはありません。

    #13429
    Noir
    参加者

    ありがとうございます

    連投してしまったので抜けてしまったと思いますが、こちらはキーボードのキー押下操作とは別で、必ずマウスクリックになりますでしょうか?

    こちらで見えればある程度進められるのですが、見えない部分なので細かくお尋ねしてすみません。

    #13430
    Tiki
    キーマスター

    キーボード操作はマウスボタンではないので、一般にはキーボード操作をしたからといってマウスイベントが発生することはありません。

    #13431
    Noir
    参加者

    ご回答ありがとうございます。

    独自のログ出力だったのでマウスクリック以外も同じ記録がされないか気になっておりました。

    お尋ねした理由は TuneBrowser ウィンドウ内のフォーカスが「スライダー」に当たった状態で Enter や Space などのキーが押下されて短時間にリピートされるほうがまだ現実的にありえるかな、という意図でお尋ねしました。
    ですがマウスのボタンクリックということで想定は間違っていることが確認できました。ありがとうございます。

    もう1点、ご確認なのですが、

    現象発生時の時間近辺で「スライダー以外」の場所にマウス クリックが発生しているか確認できますでしょうか?

    これは謎の超高速クリック現象が「スライダーだけ」なのか「スライダー以外にも全方位的に発生」なのかを切り分けたいという意図になります。

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

    なお、こちらではモニター画面をカメラで動画を撮り始めました。(PC内のツールでは動作に影響がある可能性もありますのでモニターを撮り続けております)

    昨日と今日は現象出ていませんので、いつ発生するかわからないのですけど、わたし自身も音飛びなどをトリガーに事後に画面を見るという状況で、一度も発生までの過程を見ておりません。取得出来ましたら、ダンプ解析やログ解析での想定と、実際の画面の動きを照らし合わせたいと思っております。

    #13432
    Tiki
    キーマスター

    こんばんは。

    ログをみるかぎりでは、スライダー以外ではマウスイベントは発生していないようでした。

    簡単ですが、よろしくお願いします。

    #13433
    Tiki
    キーマスター

    念のため、なのですが、トピックタイトルにある「一時的に再生が停滞して10数秒後に再開」という現象は、最初にも書いたようにわたしの環境でも発生します。一昨日は、ある用途でUSB3.2 Gen2のディスクに大きな負荷をかけたときに、まさに描画も再生も停滞して十数秒後に再開する動作が発生しました。

    その事象が起きたとしても、TuneBrowserからはどうにもできません。

    いまここで議論をしているのは、シークが連発するという動作のほうですよね。今回お送りいただいたダンプファイル上は、シーク連発中、動作の停滞が発生しているようには見受けられませんでした (だからマウスイベントを処理できているわけですが)。ただダンプファイル上は性能への影響を抑制するため1秒~数秒間程度しか詳細のログがとれないようにしているので、それより前になにか起きていた可能性は否定はできません。

    #13434
    Noir
    参加者

    ご回答ありがとうございます。

    はい、現在は「スライダーに超高速クリックが連発されることでシークが短時間に繰り返され再生が途切れる」という現象です。

    Tikiさんのご協力のおかげで、当初の「再生が途切れる、そのとき描画が固まっていた」というぼんやりした状況から具体的に絞り込むことができました。また、スライダー以外へのクリックが記録されていなかった、とのことでまたひとつ絞り込めました。ありがとうございます。

    以前お渡しした描画が止まった時の動画を撮影した当時は、まだログの存在を知らなかったので厳密な比較はできないのですけど、スライダーにシーク時間のポップアップが動画の前半で確認できます。

    シーク時間のポップアップが確認されたため、同じようにスライダーへの超高速クリックが連発していたと想像しており、同一の現象と考えております。

35件の投稿を表示中 - 1 - 35件目 (全35件中)
  • このトピックに返信するにはログインが必要です。