View Issue Details

Jump to Notes
IDProjectCategoryView StatusDate SubmittedLast Update
0008487MMW v4Properties/Auto-Toolspublic2011-10-07 16:312012-12-19 23:55
Reporterrusty Assigned To 
PriorityurgentSeveritymajorReproducibilityalways
Status closedResolutionfixed 
Product Version4.0 
Target Version4.1Fixed in Version4.1 
Summary0008487: Last Modified timestamp fails to update on some NAS devices
DescriptionUser reports that on the ReadyNAS DUO device, timestamps fail to update when tags are modified, resulting in incomplete backups (backups being based on last-modified timestamp). This problem doesn't occur for locally tagged files or for files updated on e.g. QNAP device.

It may be a Netgear issue, however MP3Tag fixed this issue in 2009: http://forums.mp3tag.de/lofiversion/index.php/t8649.html

The following log is for adding rows "D" to the comment tag of bAAb - 06 Money Money Monkey. The file is stored on the NAS mapped as X:\. The timestamp did not change.

Thanks
Gingernut63

LOG
00000001 0.00000000 [5116] Forms: Accepted WM_ACTIVATEAPP +
00000002 0.00008663 [5116] Forms: RestoreTopMost: Starting
00000003 0.00046425 [5116] Winamp simulation window received messsage 28
00000004 0.00112742 [5116] MainForm: NC Activate +
00000005 0.01108676 [5116] TAlbumArtViewController.SelectSongs - Begin
00000006 0.01517173 [5116] TAlbumArtViewController.SelectSongs - End
00000007 0.12563001 [5116] MainForm: NC Activate -
00000008 0.69324523 [5116] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 0, All: 37
00000009 0.69877547 [5116] Thread 'UpdateDriveLetters_Var' has started 8476
00000010 0.69888383 [5116] Thread initialized 8476
00000011 0.71270204 [5116] CDPlayer.ini location: C:\Users\stuart\AppData\Roaming\MediaMonkey\CDPlayer.ini
00000012 0.74234581 [5116] Going 'UpdateDriveLetters_Var'to make final callback 8476
00000013 17.31020546 [5116] MainForm: NC Activate +
00000014 17.36803818 [5116] 3192 DB open SQL: SELECT PreviewStartTime, PreviewLength, CacheName, PreviewName, Copyright, Encoder, ISRC, InitialKey, Language, OrigLyricist, ParentalRating,PreGap, PostGap, TotalSamples, GaplessBytes, SignType, SignPart1, SignPart2, SignPart3, SignPart4, ContainerType, StreamCount, StreamInfo FROM Songs WHERE ID=?
00000015 17.37612915 [5116] TGenThread.Create: ThreadName: OnReadArtists , Running Threads: Internal: 0, All: 35
00000016 17.37879372 [5116] Thread 'OnReadArtists' has started 8532
00000017 17.37887001 [5116] Thread initialized 8532
00000018 17.38617134 [5116] TGenThread.Create: ThreadName: OnReadAlbums , Running Threads: Internal: 0, All: 36
00000019 17.38888741 [5116] Thread 'OnReadAlbums' has started 9172
00000020 17.38904381 [5116] Thread initialized 9172
00000021 17.45537758 [5116] 8532 DB lock finished, took 253051.
00000022 17.45547676 [5116] 3192 DB open SQL: SELECT Lyrics, Comment FROM Songs WHERE Songs.ID=?
00000023 17.45565414 [5116] 9172 DB lock finished, took 668.
00000024 17.45578957 [5116] 8532 DB lock finished, took 748.
00000025 17.45680237 [5116] 3192 DB lock finished, took 987.
00000026 17.45849609 [5116] Forms: NormalizeTopMosts: Level: 0
00000027 17.46029663 [5116] 8532 DB open SQL: SELECT DISTINCT ParentalRating FROM Songs
00000028 17.48274231 [5116] MainForm: NC Activate -
00000029 17.60230255 [5116] 8532 DB lock finished, took 470148.
00000030 17.60309601 [5116] Thread 'OnReadAlbums' is going to callback
00000031 17.60346031 [5116] Thread 'OnReadArtists' is going to callback
00000032 17.61343956 [5116] Thread 'OnReadArtists'has finished 8532
00000033 17.61390686 [5116] 9172 DB query prepare finished, took 103.
00000034 17.61400604 [5116] 9172 DB query prepare finished, took 111.
00000035 17.61417007 [5116] 9172 DB lock finished, took 347.
00000036 17.61429596 [5116] 9172 DB query prepare finished, took 67.
00000037 17.61440659 [5116] 9172 DB lock finished, took 178.
00000038 17.71478844 [5116] 9172 DB lock finished, took 330641.
00000039 17.71825027 [5116] Thread 'OnReadAlbums' is going to callback
00000040 17.71839523 [5116] Thread 'OnReadAlbums' is going to callback
00000041 17.72227097 [5116] DB: Deleting prepared query: SELECT IDGenre, GenreName FROM Genres
00000042 17.72232437 [5116] DB: Deleting prepared query: SELECT ID, Name, View FROM Views WHERE ID = ?
00000043 30.70731163 [5116] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 0, All: 35
00000044 30.71150970 [5116] Thread 'UpdateDriveLetters_Var' has started 488
00000045 30.71158600 [5116] Thread initialized 488
00000046 30.72592926 [5116] CDPlayer.ini location: C:\Users\stuart\AppData\Roaming\MediaMonkey\CDPlayer.ini
00000047 30.78068352 [5116] Going 'UpdateDriveLetters_Var'to make final callback 488
00000048 38.50011063 [5116] Forms: RestoreTopMost: Level: 1
00000049 38.50368881 [5116] MainForm: NC Activate +
00000050 38.50454330 [5116] TBackgroundTagger.UpdateTags: Got BTLockCS
00000051 38.52068710 [5116] TGenThread.Create: ThreadName: _DoTag , Running Threads: Internal: 0, All: 35
00000052 38.52529907 [5116] Tagging: Queuing finished
00000053 38.52629471 [5116] 3192 DB open SQL: SELECT ID,Album FROM Albums WHERE Album=? AND Artist=?
00000054 38.52646637 [5116] Thread registered, going to initialize 7720
00000055 38.52656174 [5116] Thread initialized 7720
00000056 38.52680206 [5116] Tagging: Track will be tagged now: X:\00 BAAB - Arrival (Deluxe Edition)\bAAb - 06 Money Money Money.mp3
00000057 38.52969742 [5116] 3192 DB lock finished, took 9010.
00000058 38.52980042 [5116] 3192 DB lock successful.
00000059 38.53036499 [5116] 3192 DB exec SQL: DELETE FROM GenresSongs WHERE IDSong=?
00000060 38.53065491 [5116] 3192 DB lock finished, took 649.
00000061 38.53080750 [5116] 3192 DB lock finished, took 149.
00000062 38.53091431 [5116] 3192 DB lock successful.
00000063 38.53111649 [5116] 3192 DB open SQL: SELECT ID,Artist FROM Artists WHERE Artist=?
00000064 38.53127289 [5116] 3192 DB exec SQL: INSERT INTO ArtistsSongs (PersonType,IDArtist,IDSong) VALUES (?,?,?)
00000065 38.53145599 [5116] 3192 DB lock finished, took 331.
00000066 38.53165054 [5116] 3192 DB lock finished, took 260.
00000067 38.53174973 [5116] 3192 DB lock successful.
00000068 38.53190231 [5116] 3192 DB open SQL: SELECT Count(*) FROM PathProcessing
00000069 38.53203964 [5116] 3192 DB open SQL: SELECT * FROM Artists WHERE Artist=?
00000070 38.53240967 [5116] Refreshing active cover called
00000071 38.53383255 [5116] TAlbumArtViewController::PrepareAlbumArtList - begin
00000072 38.53393936 [5116] TAlbumArtViewsManager::PrepareAlbumArtList - before sort
00000073 38.53421783 [5116] TAlbumArtViewsManager::PrepareAlbumArtList - before fill
00000074 38.53432846 [5116] 3192 DB lock finished, took 75.
00000075 38.53452682 [5116] 3192 DB lock finished, took 63.
00000076 38.53570557 [5116] TAlbumArtViewController::PrepareAlbumArtList - Albums generated
00000077 38.53585434 [5116] 3192 DB open SQL: SELECT * FROM Filters WHERE ID=?
00000078 38.53606033 [5116] 3192 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ?
00000079 38.53710938 [5116] 3192 DB open SQL: SELECT * FROM Filters WHERE ID=?
00000080 38.53731918 [5116] 3192 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ?
00000081 38.53807831 [5116] TAlbumArtViewController::PrepareAlbumArtList - Albums groups generated
00000082 38.53876877 [5116] TAlbumArtViewController.SelectSongs - Begin
00000083 38.54042435 [5116] TAlbumArtViewController.PreserveTrackSelectionToAlbumArt - begin
00000084 38.54047394 [5116] TAlbumArtViewController.LocateAlbumInAAView - begin
00000085 38.54051590 [5116] TAlbumArtViewController.PreserveTrackSelectionToAlbumArt - end
00000086 38.54068756 [5116] TAlbumArtViewController::PrepareAlbumArtList - end
00000087 38.55813599 [5116] TryLoadDirectlyFromDBAndCache called for track X:\00 BAAB - Arrival (Deluxe Edition)\bAAb - 01 When I Kissed The Teacher.mp3
00000088 38.56607056 [5116] TGenThread.Create: ThreadName: ImageReader_Var , Running Threads: Internal: 1, All: 36
00000089 38.56881714 [5116] Thread 'ImageReader_Var' has started 7632
00000090 38.56885529 [5116] Thread initialized 7632
00000091 38.56898499 [5116] 7632 DB prepare SQL: SELECT Covers.* FROM Covers, Songs WHERE songs.idalbum=? AND covers.idsong=songs.id ORDER BY Covers.idsong
00000092 38.56911087 [5116] 7632 DB open SQL: SELECT Covers.* FROM Covers, Songs WHERE songs.idalbum=? AND covers.idsong=songs.id ORDER BY Covers.idsong
00000093 38.56939697 [5116] Added Covers: 26
00000094 38.56945038 [5116] Added Covers: 28
00000095 38.58133698 [5116] Locking file: X:\00 BAAB - Arrival (Deluxe Edition)\bAAb - 06 Money Money Money.mp3
00000096 38.58144379 [5116] MP3: Going to write tag to X:\00 BAAB - Arrival (Deluxe Edition)\bAAb - 06 Money Money Money.mp3
00000097 38.82210159 [5116] MP3: Updated ID3v2
00000098 38.83655548 [5116] 3192 DB open SQL: SELECT ID, Name, View FROM Views ORDER BY ID
00000099 38.84205246 [5116] 3192 DB open SQL: SELECT * FROM Filters ORDER BY Pos
00000100 38.84254074 [5116] 3192 DB lock finished, took 1163.
00000101 38.85397720 [5116] TryLoadDirectlyFromDBAndCache called for track X:\00 BAAB - Arrival (Deluxe Edition)\bAAb - 01 When I Kissed The Teacher.mp3
00000102 38.86245728 [5116] MP3.ReadHeader CheckMoreHeaders Endtest: 262144
00000103 38.90150833 [5116] MP3.ReadHeader CheckMoreHeaders finished
00000104 38.90419769 [5116] MP3: Going to read tag from X:\00 BAAB - Arrival (Deluxe Edition)\bAAb - 01 When I Kissed The Teacher.mp3
00000105 38.90885162 [5116] MP3: Updated ID3v1
00000106 38.92808914 [5116] 7720 DB exec SQL: UPDATE Songs SET FileLength=4605063, TrackModified=40822.969303345,FileModified=40822.956527778 WHERE ID=50893
00000107 38.92837524 [5116] 7720 DB lock finished, took 752.
00000108 38.92842484 [5116] Unlocked file: X:\00 BAAB - Arrival (Deluxe Edition)\bAAb - 06 Money Money Money.mp3
00000109 38.92851639 [5116] Tagging: Thread finished
00000110 38.92858124 [5116] Thread '_DoTag'has finished 7720
00000111 38.94461060 [5116] Added Covers: 29
00000112 38.94481659 [5116] 7632 DB prepare SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=?
00000113 38.94525146 [5116] 7632 DB open SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=?
00000114 38.94564056 [5116] GetFileInfo: Found in DB
00000115 38.94573593 [5116] 7632 DB open SQL: SELECT * FROM Covers WHERE IDSong=50895 ORDER BY CoverOrder
00000116 38.94594955 [5116] Added Covers: 30
00000117 38.94605637 [5116] Added Covers: 30
00000118 38.94619751 [5116] Remaining Covers: 30
00000119 38.94628525 [5116] Remaining Cover Lists: 10
00000120 38.94636917 [5116] Added Covers: 30
00000121 38.94647598 [5116] Added Covers: 32
00000122 38.94656372 [5116] Added Covers: 33
00000123 38.94668198 [5116] Added Covers: 35
00000124 38.94676590 [5116] Track comparison failed: "01"<>"08"
00000125 38.94697571 [5116] 7632 DB query prepare finished, took 340.
00000126 38.94708633 [5116] 7632 DB lock finished, took 60.
00000127 38.94720078 [5116] Remaining Covers: 33
00000128 38.94728470 [5116] Remaining Cover Lists: 11
00000129 38.94736862 [5116] Remaining Covers: 30
00000130 38.94745636 [5116] Remaining Cover Lists: 10
00000131 38.94764709 [5116] Remaining Covers: 28
00000132 38.94774628 [5116] DB: Deleting prepared query: SELECT Covers.* FROM Covers, Songs WHERE songs.idalbum=? AND covers.idsong=songs.id ORDER BY Covers.idsong
00000133 38.94788742 [5116] DB: Deleting prepared query: SELECT PreviewStartTime, PreviewLength, CacheName, PreviewName, Copyright, Encoder, ISRC, InitialKey, Language, OrigLyricist, ParentalRating,PreGap, PostGap, TotalSamples, GaplessBytes, SignType, SignPart1, SignPart2, SignPart3, SignPart4, ContainerType, StreamCount, StreamInfo FROM Songs WHERE ID=?
00000134 39.20610046 [5116] StretchStart
00000135 39.20697784 [5116] BQ: Starting a new thread.
00000136 39.21463013 [5116] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 0, All: 35
00000137 39.21686935 [5116] BQ: Starting a new task.
00000138 39.21737671 [5116] Thread 'BackgroundQueue' has started 3584
00000139 39.21743393 [5116] Thread initialized 3584
00000140 39.24716949 [5116] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 2, All: 38
00000141 39.24993515 [5116] Thread 'BackgroundQueue' has started 7404
00000142 39.25002670 [5116] Thread initialized 7404
00000143 39.25318146 [5116] StretchStart
00000144 39.25328064 [5116] BQ: Starting a new thread.
00000145 39.26176071 [5116] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 4, All: 39
00000146 39.26412582 [5116] BQ: Starting a new task.
00000147 39.26459122 [5116] Thread 'BackgroundQueue' has started 5472
00000148 39.26464462 [5116] Thread initialized 5472
00000149 39.27190018 [5116] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 4, All: 40
00000150 39.27408218 [5116] BQ: Starting a new task.
00000151 39.27454758 [5116] Thread 'BackgroundQueue' has started 4040
00000152 39.27460098 [5116] Thread initialized 4040
00000153 39.28398132 [5116] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 5, All: 41
00000154 39.28692627 [5116] StretchEnd
00000155 39.28741837 [5116] Thread registered, going to initialize 4080
00000156 39.41155243 [5116] BQ: Starting a new task.
00000157 39.41174698 [5116] 3584 DB open SQL: SELECT Songs.ID FROM Songs WHERE ( Songs.TrackType in (1,7) ) LIMIT 1
00000158 39.43186188 [5116] New thread starting 1
00000159 39.44374847 [5116] TGenThread.Create: ThreadName: , Running Threads: Internal: 7, All: 42
00000160 39.44642258 [5116] Thread '' has started 6980
00000161 39.44647980 [5116] Thread initialized 6980
00000162 39.44652557 [5116] Thread '' is going to callback
00000163 39.50261688 [5116] 3584 DB lock finished, took 300698.
00000164 39.50269318 [5116] 3584 DB open SQL: SELECT Songs.ID FROM Songs WHERE ( Songs.TrackType in (2) ) LIMIT 1
00000165 39.50278854 [5116] 3584 DB open SQL: SELECT Songs.ID FROM Songs WHERE ( Songs.TrackType in (4) ) LIMIT 1
00000166 39.50292969 [5116] 3584 DB open SQL: SELECT Songs.ID FROM Songs WHERE ( Songs.TrackType in (5) ) LIMIT 1
00000167 39.50304031 [5116] 3584 DB lock finished, took 69.
00000168 39.63462830 [5116] 3192 DB open SQL: SELECT * FROM Filters WHERE ID=?
00000169 39.63489914 [5116] 3192 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ?
00000170 39.63619614 [5116] 3192 DB open SQL: SELECT * FROM Filters WHERE ID=?
00000171 39.63646698 [5116] 3192 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ?
00000172 39.63724136 [5116] 3192 DB open SQL: SELECT * FROM Filters WHERE ID=?
00000173 39.63747787 [5116] 3192 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ?
00000174 39.63829803 [5116] 3192 DB open SQL: SELECT * FROM Filters WHERE ID=?
00000175 39.63854218 [5116] 3192 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ?
00000176 39.63948822 [5116] 3192 DB open SQL: SELECT * FROM Filters WHERE ID=?
00000177 39.63967514 [5116] 3192 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ?
00000178 39.64072418 [5116] 3192 DB open SQL: SELECT * FROM Filters WHERE ID=?
00000179 39.64094162 [5116] 3192 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ?
00000180 39.64202499 [5116] 3192 DB open SQL: SELECT * FROM Filters WHERE ID=?
00000181 39.64224243 [5116] 3192 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ?
00000182 39.64331818 [5116] 3192 DB open SQL: SELECT * FROM Filters WHERE ID=?
00000183 39.64352417 [5116] 3192 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ?
00000184 40.44152069 [5116] TGenThread.Create: ThreadName: _ManageTransactions , Running Threads: Internal: 7, All: 42
00000185 40.44697571 [5116] Thread '_ManageTransactions' has started 7608
00000186 40.44708633 [5116] Thread initialized 7608
00000187 40.44719696 [5116] Thread '_ManageTransactions'has finished 7608
00000188 42.25139618 [5116] Going 'BackgroundQueue'to make final callback 9148
00000189 42.25149155 [5116] Going 'BackgroundQueue'to make final callback 7404
00000190 42.25156784 [5116] Thread 'BackgroundQueue'has finished 1156
00000191 42.28641891 [5116] Going 'BackgroundQueue'to make final callback 5472
00000192 42.28653336 [5116] Thread 'BackgroundQueue'has finished 5472
00000193 42.28741074 [5116] Going 'BackgroundQueue'to make final callback 4080
00000194 42.46967316 [5116] TGenThread.Create: ThreadName: _ManageTransactions , Running Threads: Internal: 1, All: 36
00000195 42.47237015 [5116] Thread '_ManageTransactions' has started 4316
00000196 42.47242355 [5116] Thread initialized 4316
00000197 42.47247696 [5116] Thread '_ManageTransactions'has finished 4316
00000198 42.50243759 [5116] Going 'BackgroundQueue'to make final callback 3584
00000199 44.49774551 [5116] TGenThread.Create: ThreadName: _ManageTransactions , Running Threads: Internal: 0, All: 35
00000200 44.50329590 [5116] Thread '_ManageTransactions' has started 576
00000201 44.50340271 [5116] Thread initialized 576
00000202 44.50351715 [5116] Thread '_ManageTransactions'has finished 576
00000203 48.56032944 [5116] Thread '_ManageTransactions' has started 8512
00000204 48.56039047 [5116] Thread initialized 8512
00000205 48.58999634 [5116] Going '_ManageTransactions'to make final callback 8512
00000206 60.72108078 [5116] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 0, All: 35
00000207 60.72678757 [5116] Thread 'UpdateDriveLetters_Var' has started 8780
00000208 60.72687149 [5116] Thread initialized 8780
00000209 60.72897720 [5116] CDPlayer.ini location: C:\Users\stuart\AppData\Roaming\MediaMonkey\CDPlayer.ini
00000210 60.74106979 [5116] CDPlayer.ini location: C:\Users\stuart\AppData\Roaming\MediaMonkey\CDPlayer.ini
00000211 60.76385117 [5116] Going 'UpdateDriveLetters_Var'to make final callback 8780
Additional Informationhttp://www.mediamonkey.com/forum/viewtopic.php?f=6&t=60827
TagsNo tags attached.
Fixed in build1601

Relationships

related to 0010283 closedLudek AV while ripping CD 

Activities

jiri

2012-02-03 08:56

administrator   ~0030240

No reply from Florian yet, even though I asked again.

jiri

2012-05-08 08:05

administrator   ~0031047

I got this from Florian:


I'm using something like this as workaround:

HANDLE hFile = ::CreateFile(filePathWrite, GENERIC_READ|GENERIC_WRITE,
FILE_SHARE_READ, NULL, OPEN_EXISTING, FILE_ATTRIBUTE_NORMAL, NULL);

if (hFile != INVALID_HANDLE_VALUE) {

 FILETIME ftCreate, ftModify, ftAccessed;
 const BOOL bHasTimestamps = ::GetFileTime(hFile, &ftCreate,
&ftAccessed, &ftModify);

 // additional code goes here

 if (bHasTimeStamps) {
   SYSTEMTIME st;
   ::GetSystemTime(&st);
   ::SystemTimeToFileTime(&st, &ftModify);
   ::SetFileTime(hFile, &ftCreate, NULL, &ftModify);
 }

 ::CloseHandle(hFile);
}

michal

2012-05-09 11:24

developer   ~0031071

Fixed in build 1601. But I cannot test it, have no relevant NAS device.

peke

2012-12-19 23:55

developer   ~0034035

Verified No regressions and additional reports using 1615 and Qnap