フォーラムへの返信
-
投稿者投稿
-
Noir参加者
ご回答ありがとうございます。
はい、現在は「スライダーに超高速クリックが連発されることでシークが短時間に繰り返され再生が途切れる」という現象です。
Tikiさんのご協力のおかげで、当初の「再生が途切れる、そのとき描画が固まっていた」というぼんやりした状況から具体的に絞り込むことができました。また、スライダー以外へのクリックが記録されていなかった、とのことでまたひとつ絞り込めました。ありがとうございます。
以前お渡しした描画が止まった時の動画を撮影した当時は、まだログの存在を知らなかったので厳密な比較はできないのですけど、スライダーにシーク時間のポップアップが動画の前半で確認できます。
シーク時間のポップアップが確認されたため、同じようにスライダーへの超高速クリックが連発していたと想像しており、同一の現象と考えております。
Noir参加者ご回答ありがとうございます。
独自のログ出力だったのでマウスクリック以外も同じ記録がされないか気になっておりました。
お尋ねした理由は TuneBrowser ウィンドウ内のフォーカスが「スライダー」に当たった状態で Enter や Space などのキーが押下されて短時間にリピートされるほうがまだ現実的にありえるかな、という意図でお尋ねしました。
ですがマウスのボタンクリックということで想定は間違っていることが確認できました。ありがとうございます。もう１点、ご確認なのですが、
現象発生時の時間近辺で「スライダー以外」の場所にマウス クリックが発生しているか確認できますでしょうか？
これは謎の超高速クリック現象が「スライダーだけ」なのか「スライダー以外にも全方位的に発生」なのかを切り分けたいという意図になります。
よろしくお願いいたします。
なお、こちらではモニター画面をカメラで動画を撮り始めました。（PC内のツールでは動作に影響がある可能性もありますのでモニターを撮り続けております）
昨日と今日は現象出ていませんので、いつ発生するかわからないのですけど、わたし自身も音飛びなどをトリガーに事後に画面を見るという状況で、一度も発生までの過程を見ておりません。取得出来ましたら、ダンプ解析やログ解析での想定と、実際の画面の動きを照らし合わせたいと思っております。
Noir参加者ありがとうございます
連投してしまったので抜けてしまったと思いますが、こちらはキーボードのキー押下操作とは別で、必ずマウスクリックになりますでしょうか？
こちらで見えればある程度進められるのですが、見えない部分なので細かくお尋ねしてすみません。
Noir参加者Alt+Shift+x でコードに成形したらライン別になってしまいました。
「編集」を試みたのですが一定時間経過で間に合わず。読みにくくてすみません。。。
Noir参加者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: OnPlaybackFileNoir参加者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: OnPlaybackFileNoir参加者続けて失礼いたします。
#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 と爆速なのでプログラムでしか実現できなさそうですが、該当マシンには自動化ツールのようなアプリをインストールしていないし思い浮かばない、という状況です。
よろしくお願いいたします。
Noir参加者aaaa
aaaNoir参加者ご連絡ありがとうございます。
こちらでどのような情報がログに記録されるか、試してみたのですが、このマウスイベントはログファイルには記録されていないダンプファイル固有の情報のようですね。
参考までに、キーボード入力の場合は違う記録がされますでしょうか？
OnLButtonDown と OnLButtonUp および GetCursorPos() などでカーソル位置を取得して Player ログに出力いただくことは可能でしょうか？キーボードイベントなども記録できるとありがたいです。
https://learn.microsoft.com/ja-jp/windows/win32/api/winuser/nf-winuser-getcursorpos
Noir参加者ご確認ありがとうございます。
サウンドデバイスになんらかのエラーが発生しているのかな、と思いましたが、想定外のご回答でした。
はじめのころに送った動画ではマウスカーソルが映ってなかったように、基本的に再生中はpc自体を操作しないので謎は深まりました。
以前と今回お送りしたログを拝見するとアルバムを切り替えて大体77秒というあたりの時間で現象がはじまってる点は気がかりです。
（それ以降の現象発生時は77秒ではないのですが、きっかけとなる最初の発生時は77秒）
またマウスクリックのイベントが再生や停止ボタンではなく、都合よくシークバーに行くものなのか、という疑問もございます。
今回の現象発生時、目の前に居なかったので逆にお聞きしたいのですが、ウインドウの状態はフォアグラウンドにありましたでしょうか？
バックグラウンドもしくは最小化することで回避できるものかわからないのですが、マウスイベントが何かしらの理由で誤クリックが発生するのであれば、最小化するという回避方法もありかな、と思いました。
Noir参加者大変お手数をおかけいたします。
ご調査よろしくお願いいたします。
Noir参加者こんばんは
ひさしぶりに現象が発生しました！
先ほどダンプファイルを送付させていただきました。１点、自動的にダイアログが表示されると思っていたのですけど、現象発生時に送信ダイアログは表示されませんでした。今回はログに以下の項目が残っていたので、手動で「ヘルプ」ー「ダンプファイル」ー「ダンプファイルの確認」を実行したところ見つかったので送付いたしました。
UL04710: 2023/04/24 23:17:16,591: T012f4: Generating dumpfile for unexpected state.
また、念のため現象発生時のログも添付いたします。
ダンプファイルの生成はお伝えいただいたとおり１日１度のみの生成でしたが、現象はこのあとも別の曲で発生していることがログから確認できました。
よろしくお願いいたします。
Attachments:
Noir参加者結論から申し上げますと、先週は一度も発生しませんでした。
先週は前回発生時のように、夕方に12-15時間分くらいのプレイリストを用意して再生をはじめ、4-5時間経過後の21-22時くらいを目処に、プレイリストに含まれていない他のアルバムを選択する、という状況を月ー土と試しました。
せっかく仕込みを入れてくださったのに、一週間まるまる現象が発生しなかった状況ははじめてで、申し訳ない気持ちでおります。本来現象が出ないのはいいことなのですが、調べたいときに出ないのは困りますね。。。
引き続き使用してまいりますので、よろしくお願いいたします。
Noir参加者4/12-15の4日間は現象発生なしでした。
前回、プレイリストを変えてから77秒という状況だったので、今週は試しに夕方に12-15時間分くらいのプレイリストを用意して、そのまま9-10時間TuneBrowserを操作しないで再生、という状況を試してみました。
この条件で4日間、現象出ていません。
そして、週明けは前回発生時のように、夕方に12-15時間分くらいのプレイリストを用意して再生をはじめるところまでは同じで、4-5時間経過後の21-22時くらいを目処に、プレイリストに含まれていない他のアルバムを選択する、という状況を試してみます。
現象発生の有無はたまたまなのかも知れませんが、ご連絡まで。
引き続きよろしくお願いいたします。
Noir参加者ありがとうございます！
たまたま先ほどの投稿をみてマイクロソフトストアで更新をチェックしたらダウンロードできてたので早いなー、と思ってたところです。
マイクロソフトさんからも連絡がいくのですね。親切ですね。
早速、この環境で再生してみますね！
引き続きどうぞよろしくお願いいたします！！
Attachments:
Noir参加者ご返信および多大なご協力ありがとうございます！
２つのアカウントで使用させていただいてますが、フォーラム用のアドレスはどちらとも異なってます。
よろしくお願いします。
Noir参加者こんばんは！
土曜日は現象発生しませんでしたが、本日は現象が発生し、プレイヤーの起動から現象発生までのログが取得できましたので送ります。
- 17:12:13 ～ 22:08:00 までエラーなく再生
- 22:08:00,816 にアルバムを手動で切り替え
- 22:09:18,599 から Seek 77sec が連続して記録
22:09:18,599: T00a28: TL18: Proc: [Seek] to 77.420 sec.
よろしくお願いいたします。
Attachments:
Noir参加者お力添えありがとうございます。
ログをディスクに出力できる設定項目を発見したので、本日からディスクに書き出してみます。
また UWP版も5.2.3が配信されましたので、本日より5.2.3で運用いたします。お手数をおかけいたしております。
引き続きどうぞよろしくお願いします。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」が連続して記録されています。
考えられる原因はございますでしょうか？
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: –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:
Noir参加者Tikiさん、早速のご返事ありがとうございます。
恥ずかしながら Log Viewer の存在を知らなかったのですけど、フォーラムの他の投稿を拝見して存在を知りました。今度発生したときはログも参照してみます。
-
投稿者投稿
