storm crashed on scan

[baldurmen]

OS: Debian Jessie Supysonic version: commit 2b3155ceb80e4297574567f501799d026a4fb024

python-storm crashes when I try to scan my music folder.

foo@bar:~# supysonic-cli folder scan Musique
Scanning 'Musique': 0% (1/10797)
Scanning 'Musique': 2% (315/10797)
Scanning 'Musique': 5% (636/10797)
Scanning 'Musique': 8% (949/10797)
Scanning 'Musique': 11% (1272/10797)
Scanning 'Musique': 14% (1563/10797)
Scanning 'Musique': 16% (1831/10797)
Scanning 'Musique': 19% (2131/10797)
Scanning 'Musique': 22% (2455/10797)
Scanning 'Musique': 25% (2772/10797)
Scanning 'Musique': 28% (3091/10797)
Scanning 'Musique': 31% (3403/10797)
Scanning 'Musique': 34% (3717/10797)
Scanning 'Musique': 37% (4043/10797)
Scanning 'Musique': 40% (4359/10797)
Scanning 'Musique': 43% (4688/10797)
Scanning 'Musique': 46% (5000/10797)
Scanning 'Musique': 49% (5313/10797)
Scanning 'Musique': 52% (5631/10797)
Scanning 'Musique': 55% (5955/10797)
Scanning 'Musique': 58% (6276/10797)
Scanning 'Musique': 61% (6594/10797)
Scanning 'Musique': 64% (6911/10797)
Scanning 'Musique': 66% (7230/10797)
Scanning 'Musique': 69% (7547/10797)
Scanning 'Musique': 72% (7864/10797)
Scanning 'Musique': 75% (8172/10797)
Scanning 'Musique': 78% (8484/10797)
Scanning 'Musique': 81% (8811/10797)
Scanning 'Musique': 84% (9129/10797)
Scanning 'Musique': 87% (9440/10797)
Scanning 'Musique': 90% (9767/10797)
Scanning 'Musique': 93% (10098/10797)
Scanning 'Musique': 96% (10415/10797)
Scanning 'Musique': 99% (10729/10797)
Scanning 'Musique': 100% (10797/10797)
Traceback (most recent call last):
  File "/usr/local/bin/supysonic-cli", line 233, in <module>
    cli.onecmd(' '.join(sys.argv[1:]))
  File "/usr/lib/python2.7/cmd.py", line 221, in onecmd
    return func(arg)
  File "/usr/local/bin/supysonic-cli", line 51, in method
    return func(** { key: vars(args)[key] for key in vars(args) if key != 'action' })
  File "/usr/local/bin/supysonic-cli", line 151, in folder_scan
    scanner.scan(folder, TimedProgressDisplay(folder.name))
  File "/usr/local/lib/python2.7/dist-packages/supysonic/scanner.py", line 94, in scan
    self.remove_file(track.path)
  File "/usr/local/lib/python2.7/dist-packages/supysonic/scanner.py", line 201, in remove_file
    tr = self.__store.find(Track, Track.path == path).one()
  File "/usr/lib/python2.7/dist-packages/storm/store.py", line 1145, in one
    raise NotOneError("one() used with more than one result available")
storm.exceptions.NotOneError: one() used with more than one result available
Exception Exception: Exception("There's still something to check. Did you run Scanner.finish()?",) in <bound method Scanner.__del__ of <supysonic.scanner.Scanner instance at 0x7f7efcaa27e8>> ignored

i've tried to delete the folder to try to fix the problem but it seems the fact that the scan does not finish correctly makes it impossible to do.

foo@bar:~# supysonic-cli folder delete Musique
Traceback (most recent call last):
  File "/usr/local/bin/supysonic-cli", line 233, in <module>
    cli.onecmd(' '.join(sys.argv[1:]))
  File "/usr/lib/python2.7/cmd.py", line 221, in onecmd
    return func(arg)
  File "/usr/local/bin/supysonic-cli", line 51, in method
    return func(** { key: vars(args)[key] for key in vars(args) if key != 'action' })
  File "/usr/local/bin/supysonic-cli", line 126, in folder_delete
    ret = FolderManager.delete_by_name(self.__store, name)
  File "/usr/local/lib/python2.7/dist-packages/supysonic/managers/folder.py", line 104, in delete_by_name
    return FolderManager.delete(store, folder.id)
  File "/usr/local/lib/python2.7/dist-packages/supysonic/managers/folder.py", line 88, in delete
    scanner.remove_file(track.path)
  File "/usr/local/lib/python2.7/dist-packages/supysonic/scanner.py", line 201, in remove_file
    tr = self.__store.find(Track, Track.path == path).one()
  File "/usr/lib/python2.7/dist-packages/storm/store.py", line 1145, in one
    raise NotOneError("one() used with more than one result available")
storm.exceptions.NotOneError: one() used with more than one result available
Exception Exception: Exception("There's still something to check. Did you run Scanner.finish()?",) in <bound method Scanner.__del__ of <supysonic.scanner.Scanner instance at 0x7f5f7b4f8d88>> ignored

I "fixed" the problem by deleting the DB and recreating it from scratch, but I made a dump before so I can test things out if you want.

Fun fact: if that can help, Dsub was still working but one artist (I had only one album from her and I replaced it from a mp3 source to a FLAC source a few days ago) was shown multiple times.

I've been doing that a lot lately (replacing mp3 albums by FLAC ones) and it seems that it is what triggered that bug for me.

[spl0k]

It seems you had two (or more) tracks in database with the same path. Unless you ran several scanning processes at the same time when you added those specific tracks I don't understand how that could happen. I ran some quick tests (modifying several tags of a single file, replacing a FLAC file by an mp3, ...) and wasn't able to reproduce.

[baldurmen]

Hmm, I still have this problem and have been able to reproduce it. I'll try to flesh out this bug report as soon as I can, but I'm quite busy. Sorry for the delay.

[baldurmen]

Sorry for taking so long to add details to this bug report.

It seems the problem happens only when I replace m4a files in a directory by flac files... It's weird since the m4a files are not even read by supysonic in the first place.

Here's part of my config file:

; Restrict scanner to these extensions
scanner_extensions = mp3 ogg flac

Here's a step by step explanation on how I'm able to reproduce the bug:

1 - Create a new test folder, add the m4a version of an ABBA album and scan it:

$ mkdir /tmp/Test
$ supysonic-cli folder add Test /tmp/Test
$ cp -R /tmp/ABBA-m4a /tmp/Test/ABBA
$ supysonic-cli folder scan Test

Scanning done
Added: 0 artists, 0 albums, 0 tracks
Deleted: 0 artists, 0 albums, 0 tracks

Here's a tree of the Test folder with the m4a files:

└── Test
    └── ABBA
      ├── The Best Of (The Millennium Collection)
      │   ├── 01 Waterloo.m4a
      │   ├── 02 S.O.S..m4a
      │   ├── 03 I Do, I Do, I Do, I Do, I Do.m4a
      │   ├── 04 Mamma Mia.m4a
      │   ├── 05 Fernando.m4a
      │   ├── 06 Dancing Queen.m4a
      │   ├── 07 Knowing Me, Knowing You.m4a
      │   ├── 08 The Name Of The Game.m4a
      │   ├── 09 Take A Chance On Me.m4a
      │   ├── 10 Chiquita.m4a
      │   ├── 11 The Winner Takes It All.m4a
      │   └── Folder.jpg
      └── Thumbs.db

1 directory, 13 files

2 - Delete the m4a ABBA folder

$ rm -R /tmp/Test/ABBA

3 - Copy the flac ABBA folder where the m4a one once was:

$ cp -R /tmp/ABBA-flac /tmp/Test/ABBA

Here's a tree of the Test folder with the flac files:

└── Test
    └── ABBA
        └── Gold: Greatest Hits (40th Anniversary Edition)
            ├── ABBA - Gold_ Greatest Hits.json
            ├── CD1
            │   ├── 01 - Dancing Queen.flac
            │   ├── 02 - Knowing Me, Knowing You.flac
            │   ├── 03 - Take a Chance On Me.flac
            │   ├── 04 - Mamma Mia.flac
            │   ├── 05 - Lay All Your Love On Me.flac
            │   ├── 06 - Super Trouper.flac
            │   ├── 07 - I Have a Dream.flac
            │   ├── 08 - The Winner Takes It All.flac
            │   ├── 09 - Money, Money, Money.flac
            │   ├── 10 - S.O.S..flac
            │   ├── 11 - Chiquitita.flac
            │   ├── 12 - Fernando.flac
            │   ├── 13 - Voulez-Vous.flac
            │   ├── 14 - Gimme! Gimme! Gimme! (A Man After Midnight).flac
            │   ├── 15 - Does Your Mother Know.flac
            │   ├── 16 - One of Us.flac
            │   ├── 17 - The Name of the Game.flac
            │   ├── 18 - Thank You for the Music.flac
            │   ├── 19 - Waterloo (English Version).flac
            │   ├── ABBA - Gold- Greatest Hits (40th Anniversary Edition) CD1.cue
            │   ├── ABBA - Gold- Greatest Hits (40th Anniversary Edition) CD1.log
            │   └── cover.jpg
            ├── CD2
            │   ├── 01 - Summer Night City.flac
            │   ├── 02 - Angeleyes.flac
            │   ├── 03 - The Day Before You Came.flac
            │   ├── 04 - Eagle.flac
            │   ├── 05 - I Do, I Do, I Do, I Do, I Do.flac
            │   ├── 06 - So Long.flac
            │   ├── 07 - Honey Honey.flac
            │   ├── 08 - The Visitors.flac
            │   ├── 09 - Our Last Summer.flac
            │   ├── 10 - On & on & on.flac
            │   ├── 11 - Ring Ring.flac
            │   ├── 12 - I Wonder (Departure).flac
            │   ├── 13 - Lovelight.flac
            │   ├── 14 - Head Over Heels.flac
            │   ├── 15 - When I Kissed the Teacher.flac
            │   ├── 16 - I Am the City.flac
            │   ├── 17 - Cassandra.flac
            │   ├── 18 - Under Attack.flac
            │   ├── 19 - When All Is Said and Done.flac
            │   ├── 20 - The Way Old Friends Do.flac
            │   ├── ABBA - Gold- Greatest Hits (40th Anniversary Edition) CD2.cue
            │   ├── ABBA - Gold- Greatest Hits (40th Anniversary Edition) CD2.log
            │   └── cover.jpg
            └── CD3
                ├── 01 - She's My Kind of Girl.flac
                ├── 02 - I Am Just a Girl.flac
                ├── 03 - Gonna Sing You My Love Song.flac
                ├── 04 - King Kong Song.flac
                ├── 05 - I've Been Waiting For You.flac
                ├── 06 - Rock Me.flac
                ├── 07 - Man In the Middle.flac
                ├── 08 - Intermezzo No.1.flac
                ├── 09 - That's Me.flac
                ├── 10 - Crazy World.flac
                ├── 11 - Happy Hawaii.flac
                ├── 12 - I'm a Marionette.flac
                ├── 13 - Medley  Pick a Bale of Cotton.flac
                ├── 14 - Kisses of Fire.flac
                ├── 15 - The King Has Lost His Crown.flac
                ├── 16 - Elaine.flac
                ├── 17 - The Piper.flac
                ├── 18 - Andante, Andante.flac
                ├── 19 - Should I Laugh or Cry.flac
                ├── 20 - Soldiers.flac
                ├── ABBA - Gold- Greatest Hits (40th Anniversary Edition) CD3.cue
                ├── ABBA - Gold- Greatest Hits (40th Anniversary Edition) CD3.log
                └── cover.jpg

7 directories, 69 files

4 - Run the scanner once again (it crashes):

$ supysonic-cli folder scan Test

Traceback (most recent call last):
  File "/usr/local/bin/supysonic-cli", line 243, in <module>
    cli.onecmd(' '.join(sys.argv[1:]))
  File "/usr/lib/python2.7/cmd.py", line 221, in onecmd
    return func(arg)
  File "/usr/local/bin/supysonic-cli", line 51, in method
    return func(** { key: vars(args)[key] for key in vars(args) if key != 'action' })
  File "/usr/local/bin/supysonic-cli", line 160, in folder_scan
    scanner.scan(folder, TimedProgressDisplay(folder.name))
  File "/usr/local/lib/python2.7/dist-packages/supysonic/scanner.py", line 87, in scan
    self.scan_file(path)
  File "/usr/local/lib/python2.7/dist-packages/supysonic/scanner.py", line 175, in scan_file
    tralbum = self.__find_album(albumartist, album)
  File "/usr/local/lib/python2.7/dist-packages/supysonic/scanner.py", line 235, in __find_album
    ar = self.__find_artist(artist)
  File "/usr/local/lib/python2.7/dist-packages/supysonic/scanner.py", line 250, in __find_artist
    ar = self.__store.find(Artist, Artist.name == artist).one()
  File "/usr/lib/python2.7/dist-packages/storm/store.py", line 1145, in one
    raise NotOneError("one() used with more than one result available")
storm.exceptions.NotOneError: one() used with more than one result available

[baldurmen]

If you want I can send you the two directories via a link by email for you to debug.

[spl0k]

🙄 weirder and weirder, now the error happens elsewhere. If you can send me the files that might help me investigate further.

[spl0k]

spl0k@ubu-vbox:~/supysonic$ ./supysonic-cli folder add Test /tmp/Test
Folder 'Test' added
spl0k@ubu-vbox:~/supysonic$ cp -R /media/sf_projects/supysonic/ABBA-m4a /tmp/Test/ABBA
spl0k@ubu-vbox:~/supysonic$ ./supysonic-cli folder scan Test

Scanning done
Added: 0 artists, 0 albums, 0 tracks
Deleted: 0 artists, 0 albums, 0 tracks
spl0k@ubu-vbox:~/supysonic$ rm -R /tmp/Test/ABBA
spl0k@ubu-vbox:~/supysonic$ cp -R /media/sf_projects/supysonic/ABBA-flac/ /tmp/Test/ABBA
spl0k@ubu-vbox:~/supysonic$ ./supysonic-cli folder scan Test
Scanning 'Test': 100% (59/59)
Scanning done
Added: 1 artists, 1 albums, 59 tracks
Deleted: 0 artists, 0 albums, 0 tracks
spl0k@ubu-vbox:~/supysonic$ 

... I'm starting with an empty database. Which DBMS are you using?

Would you happen to have a supysonic-watcher running and listening for changes in the folder you are scanning? That shouldn't be the case though if this is a newly created folder as show above (the watcher isn't aware of folder addition/deletion).

[baldurmen]

I'm not running supysonic-watcher.

I'm not starting from an empty DB either (although I was able to reproduce the bug with one), and I'm using MySQL (mariadb).

[spl0k]

Now that storm has been replaced by PonyORM, could you please tell me if you're still able to reproduce this error?

[baldurmen]

I'd like that very much, but since PonyORM is not packaged in Debian (yet), I can't upgrade to the latest commit :(

I did solve my problem by replacing all the m4a files I had in my library by FLACs though...

I guess this issue can be closed :D

[spl0k]

You can still install it through pip.

$ sudo apt-get install python-pip
$ sudo pip install pony

But that would mean you would use python libraries from different sources. If that bothers you, I suggest you install supysonic in a virtual environment and only use libraries installed from pip in this env.

$ sudo apt-get install python-virtualenv python-pip
$ virtualenv env
$ . env/bin/activate
$ pip install -r requirements.txt