Skip to content
This repository has been archived by the owner on Jun 28, 2024. It is now read-only.

IndexError when track wasn't added because length too long #279

Closed
mweinelt opened this issue May 22, 2021 · 8 comments · Fixed by #280
Closed

IndexError when track wasn't added because length too long #279

mweinelt opened this issue May 22, 2021 · 8 comments · Fixed by #280
Labels

Comments

@mweinelt
Copy link
Contributor

Describe the bug
We have an empty playlist and try to add a youtube url that is above our configured limit of 180 minutes, the bot subsequently crashes with an IndexError.

[18:15:01] (Channel) $user: !url https://www.youtube.com/watch?v=7AOOhgLN3oY
[18:15:02] (Channel) musique.lossy.network: Download of https://www.youtube.com/watch?v=7AOOhgLN3oY in progress...
[18:15:03] (Channel) musique.lossy.network: Best of Starbucks Cafe Music Collection - 3 Hours of Smooth Jazz Piano is too long (3:16:47 > 3:00:00), removed from playlist!
[18:15:03] musique.lossy.network left channel and disconnected.

This only happens when the playlist is empty.

Affected version
33a9e75

To Reproduce
Steps to reproduce the behavior:

  1. Clear the playlist
  2. Add an item that is too long
  3. Observe the bot erroring out

Expected behavior
Use for each loops instead of using explicit iterators.

Additional context

[youtube] 7AOOhgLN3oY: Downloading webpage
[youtube] Downloading just video 7AOOhgLN3oY because of --no-playlist
[May 22 18:15:03 INFO] url: https://www.youtube.com/watch?v=7AOOhgLN3oY has a duration of 196.78333333333333 min -- too long
[May 22 18:15:03 INFO] url: fetching metadata of url https://www.youtube.com/watch?v=7AOOhgLN3oY
[youtube] 7AOOhgLN3oY: Downloading webpage
Traceback (most recent call last):
  File "/nix/store/vvlrp87i77yd9jm6fk4l69fm6mmj0pla-botamusique-unstable-2021-05-16/share/botamusique/.mumbleBot.py-wrapped", line 900, in <module>
    var.bot.loop()
  File "/nix/store/vvlrp87i77yd9jm6fk4l69fm6mmj0pla-botamusique-unstable-2021-05-16/share/botamusique/.mumbleBot.py-wrapped", line 554, in loop
    current = var.playlist.current_item()
  File "/nix/store/vvlrp87i77yd9jm6fk4l69fm6mmj0pla-botamusique-unstable-2021-05-16/share/botamusique/media/playlist.py", line 267, in current_item
    return self[self.current_index]
IndexError: list index out of range
@TerryGeng
Copy link
Collaborator

Hi. I can't reproduce this problem. But somehow the order of the log is unexpectedly messed up.
Would you post the log from the verbose mode?

@mweinelt
Copy link
Contributor Author

mweinelt commented May 23, 2021

Wait for the bot to connect.

The playlist is empty, mode is one-shot.

!url https://www.youtube.com/watch?v=7AOOhgLN3oY

Crash.

Notice, that the track is longer than the maximum time allowed. This also happens when the request ends in HTTP 429 from YouTugbe.

May 23 04:33:56 juno systemd[1]: Started botamusique.service.
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,045] > [MainThread] > [cache.py:113] library: rebuild directory cache
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,071] > [MainThread] > [.mumbleBot.py-wrapped:40] bot: botamusique version unknown, starting...
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,159] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: shortlist
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,160] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: sl
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,160] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: addtag
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,160] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: password
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,161] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: clear
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,161] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: np
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,161] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: now
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,161] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: delete
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,162] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: duck
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,162] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: duckthres
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,162] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: duckv
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,162] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: findtagged
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,162] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: ft
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,163] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: help
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,163] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: joinme
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,163] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: last
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,164] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: listfile
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,164] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: mode
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,164] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: pause
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,164] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: p
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,164] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: play
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,165] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: file
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,165] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: f
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,165] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: filematch
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,165] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: fm
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,165] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: playlist
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,166] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: radio
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,163] > [UpdateThread] > [util.py:111] update: checking for updates...
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,166] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: tag
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,169] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: url
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,169] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: queue
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,169] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: random
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,169] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: rbplay
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,170] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: rbquery
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,170] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: rm
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,170] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: untag
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,170] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: repeat
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,170] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: web
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,172] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: rescan
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,172] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: search
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,172] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: skip
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,172] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: stop
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,173] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: oust
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,173] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: version
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,173] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: volume
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,173] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: yplay
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,173] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: ysearch
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,174] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: webuseradd
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,174] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: dropdatabase
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,174] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: kill
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,174] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: webuserlist
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,175] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: webuserdel
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,175] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: update
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,175] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: urlban
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,175] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: urlbanlist
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,175] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: urlunban
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,175] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: urlunwhitelist
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,176] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: urlunw
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,176] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: urlwhitelist
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,176] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: urlw
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,176] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: urlwhitelistlist
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,176] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: urlwls
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,176] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: userban
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,177] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: userunban
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,177] > [MainThread] > [.mumbleBot.py-wrapped:229] bot: command added: rtrms
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,178] > [MainThread] > [.mumbleBot.py-wrapped:884] bot: load playlist from previous session
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,179] > [MainThread] > [.mumbleBot.py-wrapped:896] Starting web interface on localhost:8181
May 23 04:33:58 juno botamusique[4550]:  * Serving Flask app "interface" (lazy loading)
May 23 04:33:58 juno botamusique[4550]:  * Environment: development
May 23 04:33:58 juno botamusique[4550]:  * Debug mode: off
May 23 04:33:58 juno botamusique[4550]:  * Running on http://localhost:8181/ (Press CTRL+C to quit)
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,409] > [UpdateThread] > [util.py:115] update: new version 7.2 found, current installed version unknown.
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,422] > [UpdateThread] > [util.py:116] update: changelog: <p>After being silent for a few months, we are back! Thank you guys for using botamusique and keep supporting us to make it a better little bot. This release features two new translations: Italian and German, contributed by @LelieL91 and @SnejPro. We also fixed some bugs and cooked some new features. Especially, we optimized our translation streamline powered by @azlux's CI, hoping it will make contributing translations a more joyful experience for people.</p>
May 23 04:33:58 juno botamusique[4550]: <p>And, as usual, we're always looking forward to all kinds of bug reports, feature requests, and contributions! Feel free to open an issue or PR, and say hello to us at #mumble @freenote.net :).</p>
May 23 04:33:58 juno botamusique[4550]: <h2 id="features">Features</h2>
May 23 04:33:58 juno botamusique[4550]: <ul>
May 23 04:33:58 juno botamusique[4550]: <li>47687a5 Feature: Skip unnecessary MP3 conversion via FFmpeg after audio download (PR #205, thank @Gert-dev for his PR).</li>
May 23 04:33:58 juno botamusique[4550]: <li>312599e Feature: Allow deletion of music files to be disabled in the config file. Implement #202.</li>
May 23 04:33:58 juno botamusique[4550]: </ul>
May 23 04:33:58 juno botamusique[4550]: <h2 id="fixes">Fixes</h2>
May 23 04:33:58 juno botamusique[4550]: <ul>
May 23 04:33:58 juno botamusique[4550]: <li>fceb50e Fix: Crash triggering by stop and play when the playlist is empty. (Fixed #206. Thank @Gert-dev for reporting).</li>
May 23 04:33:58 juno botamusique[4550]: <li>0140863 Fix: Bot failed when executing 'mode random' (Fixed #222, Thank @seijikun for reporting).</li>
May 23 04:33:58 juno botamusique[4550]: <li>8c81ba2 Fix: Exceptions when executing <code>!duck</code> (Thank @KnightWhoSaysNeeeowWumPing for reporting).</li>
May 23 04:33:58 juno botamusique[4550]: <li>892a186 Fix: Erroneous logic for determining if FFmpeg dies prematurely, causing the bot to get stuck if FFmpeg fails. (Fixed #223. Thank @Elinvention for reporting).</li>
May 23 04:33:58 juno botamusique[4550]: <li>2546e3b Fix: Auto-update not checking update when testing version was selected.</li>
May 23 04:33:58 juno botamusique[4550]: <li>ff5b1cb1 Upgrade assets of the interface, <em>further reduced the size of the web interface</em> (PR #219, thank @TylerVigario for his contributions).</li>
May 23 04:33:58 juno botamusique[4550]: </ul>
May 23 04:33:58 juno botamusique[4550]: [2021-05-23 04:33:58,481] > [Thread-1] > [.mumbleBot.py-wrapped:613] bot: ducking triggered
May 23 04:34:43 juno botamusique[4550]: [2021-05-23 04:34:43,028] > [Thread-16] > [.mumbleBot.py-wrapped:265] bot: received command "url" with arguments "https://www.youtube.com/watch?v=7AOOhgLN3oY" from hexa-
May 23 04:34:43 juno botamusique[4550]: [2021-05-23 04:34:43,135] > [MainThread] > [.mumbleBot.py-wrapped:537] bot: next into the song: [url]  (https://www.youtube.com/watch?v=7AOOhgLN3oY)
May 23 04:34:43 juno botamusique[4550]: [2021-05-23 04:34:43,136] > [MainThread] > [.mumbleBot.py-wrapped:436] bot: current music isn't ready, start downloading.
May 23 04:34:43 juno botamusique[4550]: [2021-05-23 04:34:43,137] > [MainThread] > [.mumbleBot.py-wrapped:429] bot: start preparing item in thread: [url]  (https://www.youtube.com/watch?v=7AOOhgLN3oY)
May 23 04:34:43 juno botamusique[4550]: [2021-05-23 04:34:43,140] > [Validating] > [playlist.py:224] playlist: start validating...
May 23 04:34:43 juno botamusique[4550]: [2021-05-23 04:34:43,140] > [Thread-16] > [command.py:398] cmd: add to playlist: [url]  (https://www.youtube.com/watch?v=7AOOhgLN3oY)
May 23 04:34:43 juno botamusique[4550]: [2021-05-23 04:34:43,141] > [Validating] > [playlist.py:237] playlist: validating [url]  (https://www.youtube.com/watch?v=7AOOhgLN3oY)
May 23 04:34:43 juno botamusique[4550]: [2021-05-23 04:34:43,144] > [Prepare-e276d08] > [url.py:128] url: fetching metadata of url https://www.youtube.com/watch?v=7AOOhgLN3oY
May 23 04:34:43 juno botamusique[4550]: [youtube] 7AOOhgLN3oY: Downloading webpage
May 23 04:34:44 juno botamusique[4550]: [youtube] Downloading just video 7AOOhgLN3oY because of --no-playlist
May 23 04:34:44 juno botamusique[4550]: [2021-05-23 04:34:44,361] > [Prepare-e276d08] > [url.py:106] url: https://www.youtube.com/watch?v=7AOOhgLN3oY has a duration of 196.78333333333333 min -- too long
May 23 04:34:44 juno botamusique[4550]: [2021-05-23 04:34:44,362] > [Validating] > [url.py:128] url: fetching metadata of url https://www.youtube.com/watch?v=7AOOhgLN3oY
May 23 04:34:44 juno botamusique[4550]: [2021-05-23 04:34:44,370] > [Prepare-e276d08] > [cache.py:104] library: cache freed for item: [url] Best of Starbucks Cafe Music Collection - 3 Hours of Smooth Jazz Piano (https://www.youtube.com/watch?v=7AOOhgLN3oY)
May 23 04:34:44 juno botamusique[4550]: [youtube] 7AOOhgLN3oY: Downloading webpage
May 23 04:34:44 juno botamusique[4550]: Traceback (most recent call last):
May 23 04:34:44 juno botamusique[4550]:   File "/nix/store/vvlrp87i77yd9jm6fk4l69fm6mmj0pla-botamusique-unstable-2021-05-16/share/botamusique/.mumbleBot.py-wrapped", line 900, in <module>
May 23 04:34:44 juno botamusique[4550]:     var.bot.loop()
May 23 04:34:44 juno botamusique[4550]:   File "/nix/store/vvlrp87i77yd9jm6fk4l69fm6mmj0pla-botamusique-unstable-2021-05-16/share/botamusique/.mumbleBot.py-wrapped", line 554, in loop
May 23 04:34:44 juno botamusique[4550]:     current = var.playlist.current_item()
May 23 04:34:44 juno botamusique[4550]:   File "/nix/store/vvlrp87i77yd9jm6fk4l69fm6mmj0pla-botamusique-unstable-2021-05-16/share/botamusique/media/playlist.py", line 267, in current_item
May 23 04:34:44 juno botamusique[4550]:     return self[self.current_index]
May 23 04:34:44 juno botamusique[4550]: IndexError: list index out of range
May 23 04:34:44 juno systemd[1]: botamusique.service: Main process exited, code=exited, status=1/FAILURE

@TerryGeng
Copy link
Collaborator

Wait for the bot to connect.

The playlist is empty, mode is one-shot.

!url https://www.youtube.com/watch?v=7AOOhgLN3oY

This is the exact procedure I have followed. However, no crash happened.

Would you add

print(len(self))
print(self.current_index)

right before L267 of /media/playlist.py and paste the result here?

@mweinelt
Copy link
Contributor Author

May 23 04:54:19 juno botamusique[5628]: [2021-05-23 04:54:19,788] > [Thread-3] > [.mumbleBot.py-wrapped:265] bot: received command "url" with arguments "https://www.youtube.com/watch?v=7AOOhgLN3oY" from hexa-
May 23 04:54:19 juno botamusique[5628]: [2021-05-23 04:54:19,857] > [MainThread] > [.mumbleBot.py-wrapped:537] bot: next into the song: [url]  (https://www.youtube.com/watch?v=7AOOhgLN3oY)
May 23 04:54:19 juno botamusique[5628]: [2021-05-23 04:54:19,858] > [MainThread] > [.mumbleBot.py-wrapped:436] bot: current music isn't ready, start downloading.
May 23 04:54:19 juno botamusique[5628]: [2021-05-23 04:54:19,858] > [MainThread] > [.mumbleBot.py-wrapped:429] bot: start preparing item in thread: [url]  (https://www.youtube.com/watch?v=7AOOhgLN3oY)
May 23 04:54:19 juno botamusique[5628]: [2021-05-23 04:54:19,860] > [Prepare-e276d08] > [url.py:128] url: fetching metadata of url https://www.youtube.com/watch?v=7AOOhgLN3oY
May 23 04:54:19 juno botamusique[5628]: [2021-05-23 04:54:19,918] > [Validating] > [playlist.py:224] playlist: start validating...
May 23 04:54:19 juno botamusique[5628]: [2021-05-23 04:54:19,918] > [Thread-3] > [command.py:398] cmd: add to playlist: [url]  (https://www.youtube.com/watch?v=7AOOhgLN3oY)
May 23 04:54:19 juno botamusique[5628]: [2021-05-23 04:54:19,919] > [Validating] > [playlist.py:237] playlist: validating [url]  (https://www.youtube.com/watch?v=7AOOhgLN3oY)
May 23 04:54:22 juno botamusique[5628]: [youtube] 7AOOhgLN3oY: Downloading webpage
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: [youtube] Downloading just video 7AOOhgLN3oY because of --no-playlist
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:22 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:23 juno botamusique[5628]: [2021-05-23 04:54:23,349] > [Prepare-e276d08] > [url.py:106] url: https://www.youtube.com/watch?v=7AOOhgLN3oY has a duration of 196.78333333333333 min -- too long
May 23 04:54:23 juno botamusique[5628]: [2021-05-23 04:54:23,353] > [Validating] > [url.py:128] url: fetching metadata of url https://www.youtube.com/watch?v=7AOOhgLN3oY
May 23 04:54:23 juno botamusique[5628]: [2021-05-23 04:54:23,379] > [Prepare-e276d08] > [cache.py:104] library: cache freed for item: [url] Best of Starbucks Cafe Music Collection - 3 Hours of Smooth Jazz Piano (https://www.youtube.com/watch?v=7AOOhgLN3oY)
May 23 04:54:23 juno botamusique[5628]: [youtube] 7AOOhgLN3oY: Downloading webpage
May 23 04:54:23 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:23 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:23 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:23 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:23 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:23 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:23 juno botamusique[5628]: len: 1, idx: 0
May 23 04:54:23 juno botamusique[5628]: len: 0, idx: 0
May 23 04:54:23 juno botamusique[5628]: Traceback (most recent call last):
May 23 04:54:23 juno botamusique[5628]:   File "/nix/store/jz7x4kzgv08vs96jqlbgh45ahddmc8r8-botamusique-unstable-2021-05-16/share/botamusique/.mumbleBot.py-wrapped", line 900, in <module>
May 23 04:54:23 juno botamusique[5628]:     var.bot.loop()
May 23 04:54:23 juno botamusique[5628]:   File "/nix/store/jz7x4kzgv08vs96jqlbgh45ahddmc8r8-botamusique-unstable-2021-05-16/share/botamusique/.mumbleBot.py-wrapped", line 554, in loop
May 23 04:54:23 juno botamusique[5628]:     current = var.playlist.current_item()
May 23 04:54:23 juno botamusique[5628]:   File "/nix/store/jz7x4kzgv08vs96jqlbgh45ahddmc8r8-botamusique-unstable-2021-05-16/share/botamusique/media/playlist.py", line 269, in current_item
May 23 04:54:23 juno botamusique[5628]:     return self[self.current_index]
May 23 04:54:23 juno botamusique[5628]: IndexError: list index out of range
May 23 04:54:23 juno systemd[1]: botamusique.service: Main process exited, code=exited, status=1/FAILURE

@TerryGeng
Copy link
Collaborator

Okay. It's clear to me that this is another example of racing condition.

I added a mutex to avoid conflicts when accessing the playlist in my newest PR. Would you like to have a look?

Meanwhile, I assume this bug is quite platform-dependent (or based on your report, your platform is somehow rather prone to have such kinds of threading problems). You are welcomed to submit new bug reports should you encounter another bug of this kind in the future since the platforms @azlux and I have don't usually expose them.

@mweinelt
Copy link
Contributor Author

This is an x86_64-linux VM (1 Core, 2 GB RAM) on Hetzner Cloud. I'm not sure why it would be particular prone to races.

Hetzner CX11
https://www.hetzner.com/de/cloud

TerryGeng added a commit to TerryGeng/botamusique that referenced this issue May 23, 2021
TerryGeng added a commit to TerryGeng/botamusique that referenced this issue May 24, 2021
@mweinelt
Copy link
Contributor Author

mweinelt commented May 24, 2021

Yup, that fixes it for me.
TerryGeng@b65e7b2

@TerryGeng
Copy link
Collaborator

Thanks for letting me know.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants