TrackStat + apostrophes in song titles

[gbreit]

The punchline first: Suddenly, all of my tracks whose song titles contain an apostrophe have lost their TrackStat rating.

The details:

Sometime after upgrading to SC 7.0 or 7.1 (sorry, not sure which), I noticed that a large number of my tracks lost their TrackStat rating. I have been accumulating ratings for a couple of years now. Not an extreme sized database: 925 albums with 16602 songs by 2656 artists.

For the past few weeks, I have been trying to find some pattern to the disappearing ratings. Some albums lost ratings for just one track. Others lost several tracks, others were not affected at all.

I checked the TrackStat backup xml file, and the tracks are there, with the rating.

I tried restoring from backup. Tried removing all TrackStat data and restoring from backup. Upgraded all of Erland's plugins to the latest.

Finally found the pattern in the song titles -- only those with apostrophes lost their rating.

A couple of examples:

On Tom Wait's Swordfishtrombones, only these songs lost their ratings:

Soldier's Things
Frank's Wild Year
Trouble's Braids

Los Angeles by X, only these lost their ratings:

Your Phone's Off The Hook, But You're Not
The World's A Mess, It's In My Kiss

In both cases, I can verify that the stats are present in the TrackStat backup xml file.

I've seen mention in the forums that some handling of special characters in the SC database has changed in either SCv7.0 or 7.1, but I have not heard of anyone having trouble with apostrophes.

Anyone else seeing this? Any suggestions on how to fix this?

Currently running SC7.1 on WinXP, TrackStat 2.3. Most CD ripping done with iTunes under XP or OS X. Some AAC, some mp3. Same thing happens with downloaded flacs tagged by other people.

Any ideas would be greatly appreciated.

Thx.

Greg

[erland]

Could you post or mail me the backup file, or at least the XML section of the backup file that represents one of those tracks.

I've tried backup/restores from 7.0 to 7.2 with apostrophes and they seem to work in my setup. I currently don't have a 6.5 setup, so I can't see how the backup looks in that.

It would also be interesting if you rated one of the apostrophe tracks and perform a backup in 7.1 and compared the backup section with the backup from 6.5 (or whatever release you were on before).

Enabling trackstat debug logging in "SqueezeCenter Settings/Logging" might also show some more details, but the log file could get huge if you have a large library.

[gbreit]

Erland:

Thanks for your reply. I pm'd you a (gzipped) backup performed today after manually rating the two songs by X I mentioned in my post. Very strange behavior -- I had an old scheduled backup from March (not sure what SC version that was, but everything was working fine back then) and another from August 30. For one of the problem tracks, here's the entry (same for the March and Aug backups):

<track>
<url>file%3A%2F%2F%2FC%3A%2FMusic_Library%2FX%2FLo s%2520Angeles%2F09%2520The%2520World's%2520A%2520M ess%2C%2520It's%2520In%2520My%2520Ki.m4a</url>
<playCount>2</playCount>
<lastPlayed>1171913925</lastPlayed>
<added>1152992482</added>
<rating>100</rating>
</track>


After manually rating the track and performing another backup today (attached), now I see two entries for that track, each containing a subset of the total data:

<track>
<url>file%3A%2F%2F%2FC%3A%2FMusic_Library%2FX%2FLo s%2520Angeles%2F09%2520The%2520World's%2520A%2520M ess%2C%2520It's%2520In%2520My%2520Ki.m4a</url>
<playCount>2</playCount>
<lastPlayed>1171913925</lastPlayed>
<added>1152992482</added>
</track>
<track>
<url>file%3A%2F%2F%2FC%3A%2FMusic_Library%2FX%2FLo s%2520Angeles%2F09%2520The%2520World's%2520A%2520M ess%2C%2520It's%2520In%2520My%2520Ki.m4a</url>
<added>1152992482</added>
<rating>100</rating>
</track>


Here's the really weird thing:

It appears that *every* song title containing an apostrophe now has two "track" entries in the xml file. This was not the case in the automatic backup performed on August 30. Between the August 30 scheduled backup and today's "forced" backup, I only manually rated the two songs by X. Nothing else.

I re-scanned my library with TrackStat debugging enabled. Nothing unusual in the log file (see below).

Thanks a lot for your help on this. I owe you a PayPal contribution.

Greg
-----------------------------------
Debug lines from log file during rescan:

[08-09-01 14:17:25.1253] Plugins::TrackStat::Plugin::commandCallback65 (3451) Entering commandCallback65
[08-09-01 14:17:25.1484] Plugins::TrackStat::Storage::refreshTracks (1089) Checking if additional indexes are needed for tracks
[08-09-01 14:17:26.0007] Plugins::TrackStat::Storage::refreshTracks (1113) Starting to analyze indexes
[08-09-01 14:17:26.9226] Plugins::TrackStat::Storage::refreshTracks (1126) Finished analyzing indexes : It took 1.774172 seconds
[08-09-01 14:17:26.9235] Plugins::TrackStat::Storage::refreshTracks (1131) Starting to update urls in statistic data based on musicbrainz ids
[08-09-01 14:17:27.0018] Plugins::TrackStat::Storage::refreshTracks (1150) Finished updating urls in statistic data based on musicbrainz ids, updated 0 items : It took 0.078182 seconds
[08-09-01 14:17:27.0027] Plugins::TrackStat::Storage::refreshTracks (1155) Starting to update musicbrainz id's in statistic data based on urls
[08-09-01 14:17:27.2241] Plugins::TrackStat::Storage::refreshTracks (1175) Finished updating musicbrainz id's in statistic data based on urls, updated 0 items : It took 0.22118 seconds
[08-09-01 14:17:27.2515] Plugins::TrackStat::Storage::refreshTracks (1180) Starting to update ratings in standard slimserver database based on urls
[08-09-01 14:17:29.9538] Plugins::TrackStat::Storage::refreshTracks (1200) Finished updating ratings in standard slimserver database based on urls, updated 0 items : It took 2.702226 seconds
[08-09-01 14:17:29.9547] Plugins::TrackStat::Storage::refreshTracks (1205) Starting to update added times in statistic data based on urls
[08-09-01 14:17:32.0316] Plugins::TrackStat::Storage::refreshTracks (1225) Finished updating added times in statistic data based on urls, updated 0 items : It took 2.077108 seconds
[08-09-01 14:17:32.0325] Plugins::TrackStat::Storage::refreshTracks (1230) Starting to update play counts in statistic data based on urls
[08-09-01 14:17:34.8131] Plugins::TrackStat::Storage::refreshTracks (1254) Finished updating play counts in statistic data based on urls, updated 0 items : It took 2.780485 seconds
[08-09-01 14:17:34.8478] Plugins::TrackStat::Storage::refreshTracks (1259) Starting to update last played times in statistic data based on urls
[08-09-01 14:17:37.9381] Plugins::TrackStat::Storage::refreshTracks (1283) Finished updating last played times in statistic data based on urls, updated 0 items : It took 3.090358 seconds
[08-09-01 14:17:37.9390] Plugins::TrackStat::Storage::refreshTracks (1288) Starting to add tracks without added times in statistic data based on urls
[08-09-01 14:17:41.2506] Plugins::TrackStat::Storage::refreshTracks (1312) Finished adding tracks without added times in statistic data based on urls, added 0 items : It took 3.311504 seconds
[08-09-01 14:17:41.2515] Plugins::TrackStat::Storage::refreshTracks (1317) Starting to update ratings in statistic data based on urls
[08-09-01 14:17:46.4382] Plugins::TrackStat::Storage::refreshTracks (1341) Finished updating ratings in statistic data based on urls, updated 0 items : It took 5.186494 seconds
[08-09-01 14:17:46.4391] Plugins::TrackStat::Storage::refreshTracks (1346) Starting to update unrated ratings in statistic data based on null
[08-09-01 14:17:47.3287] Plugins::TrackStat::Storage::refreshTracks (1366) Finished updating unrated ratings in statistic data based on null, updated 0 items : It took 0.889578 seconds
[08-09-01 14:17:47.3502] Plugins::TrackStat::Storage::refreshTracks (1372) Starting to update urls in track_history based on musicbrainz ids
[08-09-01 14:17:47.5231] Plugins::TrackStat::Storage::refreshTracks (1392) Finished updating urls in track_history based on musicbrainz ids, updated 0 items : It took 0.172842 seconds
[08-09-01 14:17:47.5242] Plugins::TrackStat::Storage::refreshTracks (1397) Starting to update musicbrainz id's in track_history based on urls
[08-09-01 14:17:47.8444] Plugins::TrackStat::Storage::refreshTracks (1417) Finished updating musicbrainz id's in statistic data based on urls, updated 0 items : It took 0.320089 seconds
[08-09-01 14:17:47.8453] Plugins::TrackStat::Storage::refreshTracks (1422) Starting to add missing entries to history table
[08-09-01 14:17:53.2662] Plugins::TrackStat::Storage::refreshTracks (1442) Finished adding missing entries to history table, adding 0 items : It took 5.420891 seconds
[08-09-01 14:17:53.2671] Plugins::TrackStat::Storage::refreshTracks (1447) Starting to update unrated ratings in history table based on null
[08-09-01 14:17:53.3742] Plugins::TrackStat::Storage::refreshTracks (1467) Finished updating unrated ratings in history table based on null, updated 0 items : It took 0.10695 seconds
[08-09-01 14:17:53.3752] Plugins::TrackStat::Plugin::commandCallback65 (3467) Exiting commandCallback65

[erland]

One thing that is a bit strange is that the url in your backup file contains a ' character while my ' characters is encoded as %2527 in the backup file.

I'm not sure if this is the reason, but it might be the reason why I can't reproduce this in my own setup.

What does the SqueezeCenter version information in SqueezeCenter Settings/Status say in your setup ?

It should be something like:
==============
SqueezeCenter Version: 7.2 - TRUNK @ UNKNOWN - Windows XP - EN - cp1252
Server IP address: 172.16.0.121
Perl Version: 5.8.8 MSWin32-x86-multi-thread
MySQL Version: 5.0.22-community-nt
Platform Architecture: 586
Hostname: e6750win
Server Port Number: 9000
Total Players Recognized: 1
=============

The problem in your setup is that you for some reason has duplicate rows in the database. Until I've successfully been able to reproduce it I have no idea how this could happen.

I've seen other users having duplicate rows but it has neven been related to ' characters as far as I can remember. The solution to the other users has always been to shutdown SqueezeCenter, completely delete the database by deleting the "Cache/MySQL" directory, startup SqueezeCenter, perform a rescan and finally restore the TrackStat backup file. If you choose to try this, I would recommend that you don't actually delete the "Cache/MySQL" directory, instead just move it somewhere else so you can restore the original contents if it doesn't work.

Also, I would recommend that you don't delete any TrackStat backup files in case you will need one of them to restore all data when we have found the problem.

If I understood you correctly the backup from August 30 didn't have duplicate entries in the backup file ?
Which version of SqueezeCenter and TrackStat were you using on August 30 ?

Do you have a standard SqueezeCenter installation installed with the .exe download or is there something special with your setup which could cause the behavior ?

[gbreit]

Stopped SC, cleared the cache, rescanned (SC started a rescan as soon as I restarted it), and restored the Aug 30 TrackStat backup (which doesn't have the duplicate entries). Same problem.

Just FYI, I noticed in my backup files (the one I sent as well as Aug30 and March29) the apostrophes are sometimes encoded as %2527 as you described. In other cases, the actual apostrophe character is there. I couldn't see any pattern as to why it was one vs. the other. Regardless, the ratings are missing in the TrackStat GUI regardless of how that character is represented in the backup file.

The August 30 backup used SC7.1 and TrackStat 2.2.1. I believe I upgraded to 2.3 the day after that.

Here's my version info. Looks pretty similar to yours:

SqueezeCenter Version: 7.1 - 22170 @ Mon Jul 28 13:36:57 PDT 2008 - Windows XP - EN - cp1252
Server IP address: 192.168.1.96
Perl Version: 5.8.8 MSWin32-x86-multi-thread
MySQL Version: 5.0.22-community-nt
Platform Architecture: 586
Hostname: banzai
Server Port Number: 9000
Total Players Recognized: 1

I am now almost certain that this problem started sometime after I upgraded to SC7.1, and probably after upgrading TrackStat to 2.2 or 2.2.1 since then. I wish I could be more precise about when I first noticed this issue. Pretty sure I went straight from one of the 2.0 betas to 2.2. I think I skipped 2.1.

Mine is a totally standard setup. I always install from the .exe file. I use iTunes for most of the CD ripping and library management. Sometimes we rip CDs on other computers (PC and Mac) and transfer the mp3 or aac files to the machine running SC -- I have a network shared folder on the SC PC called "music to add" where I copy music files from other PCs. Periodically, I run iTunes on the SC PC, point to that directory and "Add To Library" to file them away in my music library directory. SC then finds them in the next scan. Not sure if that's clear, but the system works for me.

Some of my TrackStat ratings were originally imported from iTunes, but that was a very long time ago.

I'm really stumped here. Your plugins are extremely useful and have worked great for me for a couple of years. I'll keep thinking about what could have brought this on. Any more thoughts you have would be appreciated.

Thanks.

Greg

[erland]

I am now almost certain that this problem started sometime after I upgraded to SC7.1, and probably after upgrading TrackStat to 2.2 or 2.2.1 since then. I wish I could be more precise about when I first noticed this issue. Pretty sure I went straight from one of the 2.0 betas to 2.2. I think I skipped 2.1.

Do you know what version of SqueezeCenter you run before 7.1 ? Was it a 7.0.x release or a SlimServer 6.5 release ?

Periodically, I run iTunes on the SC PC, point to that directory and "Add To Library" to file them away in my music library directory. SC then finds them in the next scan.

Do you use the iTunes integration enabled in "SqueezeCenter Settings/iTunes" ?
Do you have a Music Folder configured in SqueezeCenter ?

Any more thoughts you have would be appreciated.

I'm sorry if it feels like you are doing basic tests of the plugin, but I'm not able to reproduce this in my own setup so information about the behavior of the following sequence would help.

Could you try to:
1. Rate a track with apostrophe which was rated before
2. Do a TrackStat backup

How does the entry/entries in the new backup for this file look in comparison to the corresponding old backup file ?

3. Change the rating again to something else
4. Restore the TrackStat backup you took in step 2
5. Wait until the restore finish, you will see an entry in the SqueezeCenter log regarding this

Did the rating get get restored to the value you set in step 2 or does it still have the value you set in step 3 ?

6. If the rating wasn't restored and there was duplicate entries for the track in the backup file, manually edit the backup file so it only contains the section for the track which have the correct rating value.
7. Restore the TrackStat backup file modified in step 6
8. Wait until the restore finish, you will see an entry in the SqueezeCenter log regarding this

Did the rating get get restored to the value you set in step 2 or does it still have the value you set in step 3 ?

[gbreit]

Hi Erland:

I am happy to perform the test you described, but it may take me a day or two. To answer your other questions: I was definitely running 7.0.1 prior to upgrading to 7.1. Yes, I have iTunes integration enabled. And Yes, I have a Music Folder configured in SqueezeCenter (C:\Music_Library\).

In the meantime, here is an interesting item. I fortunately have held on to most of my scheduled backup files, and rescued a bunch that had not yet been deleted from the XP trash.

Over time, the file sizes grow gradually, as expected, as more ratings are added, more songs are added to the library, and more history entries are generated. However, between Aug 02 and Aug 03, I noticed an unusually large jump in size:

-rwx------ 1 gbreit gbreit 7353795 Jul 31 03:08 trackstat_scheduled_backup_20080731.xml
-rwx------ 1 gbreit gbreit 7358800 Aug 1 03:08 trackstat_scheduled_backup_20080801.xml
-rwx------ 1 gbreit gbreit 7367833 Aug 2 03:08 trackstat_scheduled_backup_20080802.xml
-rwx------ 1 gbreit gbreit 8177327 Aug 3 09:52 trackstat_scheduled_backup_20080803.xml
-rwx------ 1 gbreit gbreit 8181521 Aug 8 18:05 trackstat_scheduled_backup_20080808.xml
-rwx------ 1 gbreit gbreit 8181521 Aug 9 03:05 trackstat_scheduled_backup_20080809.xml

I upgraded SC from 7.01 to 7.1 on Aug 2 in the afternoon (around 13:00). So the jump in size occurred during the first backup after the 7.1 upgrade.

(XP directories are samba mounted on my mac, where I can work from the Unix shell)

I performed a diff between the 0802 and 0803 backups which I have pm'd you. At the beginning, you will see a bunch of new tracks that I added that day, no problem. But following that is a large number of new <track> fields that all look like this:

> <track>
> <url>file%3A%2F%2F%2FC%3A%2FMusic_Library%2FBadfin ger%2FBadfinger_The%2520Very%2520Best%2520Of%2F10% 2520We%2527re%2520For%2520The%2520Dark.m4a</url>
> <added>1158814205</added>
> </track>

What do these all have in common? Every one appears to have an apostrophe in either the song title, or the album title (corresponding to the directory in which it is stored). Furthermore, the apostrophe is encoded as %2527 in the url. I have not verified, but I suspect that on that day, there has been a new duplicate entry added for every single url that contains an apostrophe...

Again, I am not 100% certain when I started to experience the issue with the missing ratings, but it very possible it started after the 7.1 upgrade.

Will execute your suggested test asap.

Thx.

Greg

[gbreit]

Erland:

Just to clarify. You asked:

>Do you use the iTunes integration enabled in "SqueezeCenter Settings/iTunes" ?

Yes. "Use iTunes" is checked.

>Do you have a Music Folder configured in SqueezeCenter ?

If you mean an iTunes Music Folder, then No, since I run iTunes on the same PC. Only the iTunes xml file location is specified. If you mean a Music Folder for SqueezeCenter (under "Basic Settings"), then Yes, that is specified.

Greg

[gbreit]

I'm sorry if it feels like you are doing basic tests of the plugin, but I'm not able to reproduce this in my own setup so information about the behavior of the following sequence would help.

Could you try to:
1. Rate a track with apostrophe which was rated before
2. Do a TrackStat backup

Unfortunately, I wasn't able to do this test. I didn't realize it at the time, but after clearing the cache, rescanning, and restoring the TrackStat backup a couple of days ago, the content of the xml file changed.

First off, it appears the duplicate records disappeared -- the xml file is much smaller than before the clear/rescan/restore I did on Sep 2:

-rwx------ 1 gbreit gbreit 9370010 Sep 1 10:45 trackstat_scheduled_backup_20080901.xml
-rwx------ 1 gbreit gbreit 9389310 Sep 2 03:11 trackstat_scheduled_backup_20080902.xml
-rwx------ 1 gbreit gbreit 7594308 Sep 3 03:03 trackstat_scheduled_backup_20080903.xml
-rwx------ 1 gbreit gbreit 7594308 Sep 4 03:03 trackstat_scheduled_backup_20080904.xml


Furthermore, now I have several tracks containing apostrophes which show ratings in the SC GUI -- that was not the case before. However, there is still a large number of tracks that do not show ratings in the SC GUI, and what's worse, their ratings have disappeared from the latest TrackStat backup files. So there are no longer any tracks that show ratings in the TrackStat backup file, but not the SC GUI. In other words, no tracks that match the description in your first instruction above.

Furthermore, after the rescan, all instances of the apostrophe character in the URLs of the <track> records have been replaced by '%2527'. The <historyentry> records still have apostrophes.

I am really beginning to suspect that this is related to how the apostrophe is encoded. I don't know why there are two different representations of that character...

Here's what I decided to do: Went back to the last TrackStat backup prior to the SC7.1 upgrade, which was when all the duplicate entries appeared. Did a global search and replace to substitute %2527 for the apostrophe character. Cleared the cache, rescanned, and restored from this altered backup. The idea here is that the altered backup should be similar format to the current backup, except without the missing ratings.

This worked. All my old ratings are restored, as well as the play counts. The downside is that I have to re-rate all tracks I added since the 7.1 update a month ago -- not a big deal, only 17 albums. Much better than 100s otherwise.

Thanks again for your help debugging this. You pointed me in the right direction to solve this myself. Unfortunately, we never got to the bottom of *why* this happened, and why it has evidently only happened to me.

Greg

[erland]

Thanks again for your help debugging this. You pointed me in the right direction to solve this myself. Unfortunately, we never got to the bottom of *why* this happened, and why it has evidently only happened to me.

Great that you got it to work.

I suspect the behavior was caused by a number of SqueezeCenter and plugin upgrades in a specific order. All the information you have collected in the process will be useful if any other user gets the same problem in the future, thanks for your help debugging this.