Home of the Squeezebox™ & Transporter® network music players.
Page 4 of 6 FirstFirst ... 23456 LastLast
Results 31 to 40 of 54
  1. #31
    Senior Member
    Join Date
    Jun 2009
    Posts
    497
    Quote Originally Posted by mherger View Post
    I even don't understand in German :-D. I didn't understand _what_
    explained the behaviour.


    Ah, OK! I just wanted to express, till then we concentrated on trying to see why scanner does "wrong changes" or doesn't remove artists and in which order scans happen.
    But if server doesn't detect the files as changed (eg for "windows reasons") and they aren't even handled by scanner, the problem maybe is "outside scanner" and in server structure or in windows...?

    I'll check the scanned files too and report (will take a little for I now saved db and log after EVERY scan and I did a lot of scans ;-))

  2. #32
    Babelfish's Best Boy mherger's Avatar
    Join Date
    Apr 2005
    Location
    Switzerland
    Posts
    20,734

    How does new&changed scanner detect whatfiles to scan?

    > Ah, OK! I just wanted to express, till then we concentrated on trying to
    > see why scanner does "wrong changes" or doesn't remove artists and in
    > which order scans happen.
    > But if server doesn't detect the files as changed (eg for "windows
    > reasons") and they aren't even handled by scanner, the problem maybe is
    > "outside scanner" and in server structure or in windows...?


    Ok, that makes sense. Thanks for clarifying.

  3. #33
    Senior Member
    Join Date
    Jun 2009
    Posts
    497
    So, I finally collected all the data - I watched the "0 scan" (the last scan before the change), 1st scan (after the change) and 2nd scan (after the change)

    "0 scan":
    (Last scan BEFORE changes =
    = BEFORE "1st scan" (after changes))

    tracks.timestamp
    1624895572 - Montag, 28. Juni 2021 17:52:52 GMT+02:00 DST (ctime?)

    tracks.filesize
    5898100

    tracks.added_time
    1643710345 - Dienstag, 1. Februar 2022 11:12:25 GMT+01:00

    tracks.updates_time
    1643710345 - Dienstag, 1. Februar 2022 11:12:25 GMT+01:00

    scanned_files.timestamp
    1624895572 - Montag, 28. Juni 2021 17:52:52 GMT+02:00 DST (ctime = mtime at that point)

    scanned_files.filesize
    5898100


    AFTER 1st scan (after changes):

    tracks.timestamp
    1624895572 - Montag, 28. Juni 2021 17:52:52 GMT+02:00 DST (ctime?)

    tracks.filesize
    5898100

    tracks.added_time
    1643710345 - Dienstag, 1. Februar 2022 11:12:25 GMT+01:00

    tracks.updates_time
    1643710345 - Dienstag, 1. Februar 2022 11:12:25 GMT+01:00

    scanned_files.timestamp
    1644444840 - Mittwoch, 9. Februar 2022 23:14:00 GMT+01:00 (mtime)

    scanned_files.filesize
    5890048

    After this (1st) scan, the track and album had been (on contributor_track.contributor and contributor_track.album) still be linked to the OLD contributor ("Nalin & Kane")



    AFTER 2nd scan (after changes):

    tracks.timestamp
    1644444840 - Mittwoch, 9. Februar 2022 23:14:00 GMT+01:00 (mtime)

    tracks.filesize
    5890048

    tracks.added_time
    1643710345 - Dienstag, 1. Februar 2022 11:12:25 GMT+01:00

    tracks.updates_time
    1644484141 - Donnerstag, 10. Februar 2022 10:09:01 GMT+01:00

    scanned_files.timestamp
    1644444840 - Mittwoch, 9. Februar 2022 23:14:00 GMT+01:00 (mtime)

    scanned_files.filesize
    5890048

    After this (2nd) scan, the track and album finally had been (on contributor_track.contributor and contributor_track.album) changed and now linked to the NEW contributor ("Nalin + Kane")


    As far as I can see, with 1st scan, scanned_files.timestamp and scanned_files.filesize have been changed, so they were different now from tracks.timestamp and tracks.filesize.
    But this lead to no changes on any "contributor-files".

    Only on 2nd scan the comparison scanned_files.timestamp != tracks.timestamp (or scanned_files.filesize != tracks.filesize) lead to changes within the contributor-fields in library.db ...

    So it looks to me as it "always needs 2 scans" - one to change the scanned_files.timestamp / scanned_file.filesize and a 2nd one to make those changes take effect on other fields in the db?
    Last edited by frank1969; 2022-02-11 at 11:34.

  4. #34
    Babelfish's Best Boy mherger's Avatar
    Join Date
    Apr 2005
    Location
    Switzerland
    Posts
    20,734
    The full query to get the changed tracks is:

    Code:
    SELECT DISTINCT (scanned_files.url) 
      FROM scanned_files
           JOIN
           tracks ON (scanned_files.url = tracks.url AND 
                      (scanned_files.timestamp != tracks.timestamp OR 
                       scanned_files.filesize != tracks.filesize) AND 
                      tracks.content_type != 'dir') 
     WHERE scanned_files.url LIKE 'file:///path/to/your/music%';
    Where the last condition would be the URLified music folder. You can probably even leave it out. Next time you have a first scan after changes, which missed some items, could you please run the above to see what you get?

    And one more thing: would there be more than 50 _changed_ tracks overall when this happens? (Of which some would be picked up, and some not?)

    I think you've identified a long standing bug...
    Last edited by mherger; 2022-02-11 at 19:56.
    Michael

    "It doesn't work - what shall I do?" - "Please check your server.log and/or scanner.log file!"
    (LMS: Settings/Information)

  5. #35
    Babelfish's Best Boy mherger's Avatar
    Join Date
    Apr 2005
    Location
    Switzerland
    Posts
    20,734

    How does new&changed scanner detect whatfiles to scan?

    Ok, time for another batch of updates :-).

    I believe there was a bug in the scanner introduced more than a decade
    ago... the processing of changed files happens in batches of 50 tracks.
    After closer inspection I figured out that only ever _one_ such batch
    would have been processed. Which means that as soon as you had more than
    50 changed tracks, you'd get partial results. I was able to easily
    reproduce the issue by lowering the batch size to 1 track.

    So please give the latest build another try. Thank you very much for
    your testing and reporting! I believe we've identified quite a few
    issues in the past two weeks :-).

  6. #36
    Senior Member
    Join Date
    Jun 2009
    Posts
    497
    OK, MANY MANY thanks, I've just installed, made sure I changed more than 50 files and started a "new&changed" (which takes a little longer due to the changes, I guess - till now it was about 45 min. for a new & changed, now it is after 45 min. halfways through the database so I guess it will be "times 3" - but that's worth it, if You found and fixed the bug.

    And it's a little "fun" or thrill to find it - what makes me crazy is (or was) that I didn't find what caused the behavior. I did the same things to my files and "sometimes it worked" (= the scanner found the files and corrected the db-entries) and "sometimes it didn't" (= the scanner didn't change entries in the db) - and I didn't came to the idea it depends on the number of changes I do (as Your remember, if I especially tested a new beta, I just did 1-3 files so I could see the effect easily - and mostly it worked. But in "normal work" (when I change a lot of entries) the bug appeared again. So the "> 50" thing sound reasonable...

  7. #37
    Babelfish's Best Boy mherger's Avatar
    Join Date
    Apr 2005
    Location
    Switzerland
    Posts
    20,734

    How does new&changed scanner detect whatfiles to scan?

    > OK, MANY MANY thanks, I've just installed, made sure I changed more than
    > 50 files and started a "new&changed" (which takes a little longer due to
    > the changes, I guess - till now it was about 45 min. for a new &
    > changed, now it is after 45 min. halfways through the database so I
    > guess it will be "times 3" - but that's worth it, if You found and fixed
    > the bug.


    It should certainly not take that much longer. The only step which might
    take longer is the "Rescanning changed audio files (x)" - which
    shouldn't be where the scanner is spending a lot of time. In the log
    snippet you posted a few days ago (70 tracks), finding all tracks took
    almost 10 minutes, whereas the actual update only took a few seconds. So
    even if that latter took 3x as long as before, it would only be seconds.

    > And it's a little "fun" or thrill to find it - what makes me crazy is
    > (or was) that I didn't find what caused the behavior. I did the same
    > things to my files and "sometimes it worked" (= the scanner found the
    > files and corrected the db-entries) and "sometimes it didn't" (= the


    Yep, I hate that kind of behaviour (and like the challenge, as you do :-)).

  8. #38
    Senior Member
    Join Date
    Jun 2009
    Posts
    497
    Ok, one quick feedback cause scanner "hangs".

    Logfile says:
    [22-02-12 11:26:38.0681] Slim::Utils::Scanner::Local::updateTracks (531) Rescanning changed audio files (298)

    298 tracks sounds reasonable.
    Then it starts scanning the changed files (I looked into scanner.log and recognized those are the files I changed today, files I changed yesterday or eben the day(s) before and it does some more updates on files, I changed a few days before and today again (for example:
    On the following tracked I changed the year from "0" to "1967" some days ago - today I changed the artists name (from "The Temptations" to "Temptations") now it sees the files as new and updates the year-change from some days ago.
    [22-02-12 11:26:41.7569] Slim::Utils::Scanner::Local::changed (967) Handling changed audio track file:///M:/_Various/M/Motown%20Unreleased%201967/21%20%20-%20The%20Temptations%20-%20Since%20I%20Don%27t%20Have%20You.mp3
    [22-02-12 11:26:41.7844] Slim::Utils::Scanner::Local::__ANON__ (1077) Rescanning changed year 0 -> 1967

    That all looks good.

    But now for more than 20 minutes - nothing happens.

    Web-interface says
    "Help Rescanning Media Library... Geńnderte Dateien werden durchsucht (1487 of 298)" (and the number increases, now it is (a few seconds later) "(1515 of 298)")

    Last log-entry ist:
    [22-02-12 11:27:15.0623] Slim::Utils::Scanner::Local::changed (967) Handling changed audio track file:///M:/S/Sonny%20+%20Cher/1965%20-%20Baby%20Don%27t%20Go/12%20-%20Caesar%20+%20Cleo%3B%20Sonny%20+%20Cher%20-%20Let%20The%20Good%20Times%20Roll.mp3
    [22-02-12 11:27:15.0675] Slim::Schema::Contributor::rescan (244) Removing unused contributor: 127316

    which is 20 minutes ago now.

    I exported log file to excel and scanner already did "Handling changed audio track" on all 298 tracks (ok, to be honest, excel says 294 but this might be an error in exporting or "counting" - as far as I can see, this "Sonny + Cher" track is the last (in alphabetical order) I changed".

    Server.log is unchanged since 11:11 - scanner.log since 11:27 ... - scanner seemingly doesn't know what to do after handling changed tracks and "goes on counting" ...

    I will now abort and set db back to "yesterday evening" and start to scan anew...

  9. #39
    Senior Member
    Join Date
    Jun 2009
    Posts
    497
    Quote Originally Posted by mherger View Post
    It should certainly not take that much longer.
    Yes!
    It became quicker till the end and now I started the "2nd try" and it's "as quick as it always was".
    Guess there were some windows update in the background this morning, didn't check task manager, sry!
    I will report if it "runs through" this time...

  10. #40
    Senior Member
    Join Date
    Jun 2009
    Posts
    497
    *** Tested with r1644665330 ***

    Ok, 2nd try, same result:
    "Rescanning Media Library... Geńnderte Dateien werden durchsucht (511 of 298)"

    "Information" tab on options says:

    Discovering files/directories: M: (1260039 of 1260039) Complete 00:22:32
    Removing deleted files: M: (714 of 714) Complete 00:06:37
    Scanning changed files: M: (527) Running 00:05:13
    M:\_Various\M\Motown Collection\1998 - Motown Collection - Motown Hits Of Gold - CD 3\04 - The Supremes; The Temptations - I'm Gonna Make You Love Me.mp3

    Note:
    The File mentioned there (M:\_Various\M\...) is actually NOT the last file scanned according to scanner.log

    scanner.log says:


    [22-02-12 12:51:35.2076] Slim::Utils::Scanner::Local::deleted (636) Handling deleted audio file [...]
    [22-02-12 12:51:35.2107] Slim::Schema::Album::rescan (273) Removing unused album: 26137
    [22-02-12 12:51:41.9899] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
    "progress:1644666304||importer||M:|directory_delet ed||714||714||1644666701.98934",
    ]
    [22-02-12 12:51:41.9929] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK
    [22-02-12 12:51:41.9935] Slim::Utils::Scanner::Local::updateTracks (531) Rescanning changed audio files (298)
    [22-02-12 12:51:42.0129] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
    "progress:1644666701.99379||importer||M:|directory _changed||1||298||",
    ]
    [22-02-12 12:51:42.0160] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK
    [22-02-12 12:51:42.0165] Slim::Utils::Scanner::Local::changed (967) Handling changed audio track file:///M:/[...]

    [...]
    * Here are about 295 changed tracks handled *

    [22-02-12 12:52:17.9092] Slim::Utils::Scanner::Local::changed (967) Handling changed audio track file:///M:/S/Sonny%20+%20Cher/1965%20-%20Baby%20Don%27t%20Go/07%20-%20Caesar%20+%20Cleo%3B%20Sonny%20+%20Cher%20-%20Do%20You%20Want%20to%20Dance.mp3
    [22-02-12 12:52:18.2522] Slim::Utils::Scanner::Local::changed (967) Handling changed audio track file:///M:/S/Sonny%20+%20Cher/1965%20-%20Baby%20Don%27t%20Go/12%20-%20Caesar%20+%20Cleo%3B%20Sonny%20+%20Cher%20-%20Let%20The%20Good%20Times%20Roll.mp3
    [22-02-12 12:52:18.2574] Slim::Schema::Contributor::rescan (244) Removing unused contributor: 127316

    [22-02-12 12:52:23.4628] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
    "progress:1644666701.99379||importer||M:|directory _changed||318||298||",
    ]
    [22-02-12 12:52:23.4658] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK
    [22-02-12 12:52:28.6004] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
    "progress:1644666701.99379||importer||M:|directory _changed||322||298||",
    ]
    [22-02-12 12:52:28.6032] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK
    [22-02-12 12:52:33.7420] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
    "progress:1644666701.99379||importer||M:|directory _changed||326||298||",
    ]
    [22-02-12 12:52:33.7451] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK
    [22-02-12 12:52:38.9079] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
    "progress:1644666701.99379||importer||M:|directory _changed||330||298||",
    ]

    [...]

    ]
    [22-02-12 12:59:08.6201] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK
    [22-02-12 12:59:14.0922] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
    "progress:1644666701.99379||importer||M:|directory _changed||639||298||",
    ]
    [22-02-12 12:59:14.0950] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK
    [22-02-12 12:59:19.3689] Slim::Utils::SQLiteHelper::updateProgress (442) Notify to server: [
    "progress:1644666701.99379||importer||M:|directory _changed||643||298||",
    ]
    [22-02-12 12:59:19.3718] Slim::Utils::SQLiteHelper::updateProgress (466) Notify to server OK

    * [...] and so on *

    server.log says:

    [22-02-12 12:51:32.5101] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666304.99661||importer||M:|directory_ deleted||712||714||
    [22-02-12 12:51:41.9925] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666304||importer||M:|directory_delete d||714||714||1644666701.98934
    [22-02-12 12:51:42.0154] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||1||298||
    [22-02-12 12:51:47.1941] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||12||298||
    [22-02-12 12:51:52.5882] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||30||298||
    [22-02-12 12:51:57.5921] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||80||298||
    [22-02-12 12:52:02.6086] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||157||298||
    [22-02-12 12:52:07.6585] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||247||298||
    [22-02-12 12:52:12.6596] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||293||298||
    [22-02-12 12:52:17.8212] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||304||298||
    [22-02-12 12:52:23.4643] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||318||298||
    [22-02-12 12:52:28.6027] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||322||298||
    [...]
    [22-02-12 13:04:24.7709] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||879||298||
    [22-02-12 13:04:29.9774] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||883||298||
    [22-02-12 13:04:35.2212] Slim::Utils::SQLiteHelper::_notifyFromScanner (581) Notify from scanner: progress:1644666701.99379||importer||M:|directory_ changed||887||298||

    ... and so on for once again 15 minutes now...
    Last edited by frank1969; 2022-02-12 at 05:54.

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •