"Modify Time" on share not getting updated


Recommended Posts

I got hit with this bug (again) with the first new folder/file I put on my server after upgrading from 5.0.2 to 5.0.3

Please explain the bug here outside context of xmbc.  Maybe list the steps to duplicate.  Thanks.

 

Not really sure I can explain it outside the context of XBMC, as it's the only program I use that I have constantly scanning my server comparing dates. XBMC keeps a hash of what the directory looked like during the previous scan, and then when you run the next scan, it compares those two to find any new files/directories. More info: http://wiki.xbmc.org/?title=New_Video_Scanner_Ideas#Checking_whether_a_path_needs_scanning

 

It seems to be random when it happens, I've only experienced it about 3 times (twice in the last week). The last time, these were the steps, and I had just updated to 5.0.3 and the array had been running fine (outside of this issue):

 

1.) Copy new folder with a movie file in it from my Desktop to my unRAID server into a share

2.) Run "Update library" on XBMC, which scans unRAID share from step above for new files, but finds nothing

3.) Stop array, start array (no reboot)

4.) Run "Update library" again, and it finds folder/file that was added in step 1

 

So after stopping the array and starting it again, it seems to go back to normal. I even added a couple more things a few minutes ago, and it picked those up no problem. Not sure what could be the root cause

Link to comment

Not really sure I can explain it outside the context of XBMC, as it's the only program I use that I have constantly scanning my server comparing dates. XBMC keeps a hash of what the directory looked like during the previous scan, and then when you run the next scan, it compares those two to find any new files/directories. More info: http://wiki.xbmc.org/?title=New_Video_Scanner_Ideas#Checking_whether_a_path_needs_scanning

In that write-up, there's this sentence: "Hopefully all filesystems (on all OSes) will update the modified time of a folder if any of it's contents change (file rename, file addition, file modification, file removal etc.). "

 

The modified time of a directory is never changed by a simple file modification, e.g., see:

http://stackoverflow.com/questions/3620684/directory-last-modified-date

 

This is probably just an error in the write-up since what you are doing would create a new object in a folder (object being the movie directory).

 

I have tested this and don't see an issue.  Something I've never noticed before though was there doesn't seem to be a way in windows to display the share modification time, that is the mtime of the share itself.

 

My testing has been to mount a test share within linux like this:

 

mkdir /test

mount //tower/Movies /test -o user=nobody

 

Now create/rename/delete files and directories within /test and notice that 'stat /test' returns correct mtime.

Also go to the Tower server and create/rename/delete files and directories on individual disks that have a Movies share and also observe that 'stat /test' returns correct mtime.

 

Is your server time and xmbc time synchronized, or are they off from each other?

Link to comment
Is your server time and xmbc time synchronized, or are they off from each other?

 

They're both linked up to a time server, so if they're off, it's only by seconds. Same with the machine I'm transferring files from

 

Since stopping the array and starting it again fixes it, something in whatever those scripts run could be the cause (or solution). Does starting or stopping the array change the mtime of the share directory?

Link to comment

Since stopping the array and starting it again fixes it, something in whatever those scripts run could be the cause (or solution). Does starting or stopping the array change the mtime of the share directory?

No, at least as it appears on the linux-side.  Are you running any add-ons?

Link to comment
Are you running any add-ons?

 

Just the new WebGUI, if that counts as an add on. Nothing else. I did run unMENU a few releases ago, but have since been running without

 

Let me guess...

 

You are using NFS?

 

But it works fine via Samba?

 

You are running one of the recent XBMC 13.0 Alphas?

 

Not using NFS, only have Samba and FTP enabled (but I never use FTP, I just enabled it for quick direct disk access briefly, just forgot to turn off), and I'm using the current version of OpenELEC 3.2.3 (which is based on XBMC 12.2)

 

Just for a note, the issue exists beyond the one system (but same OS). I have a few OpenELEC machines in my home, and the first time I encountered it  (a few months ago), I couldn't figure out why the one in my room wasn't seeing my new content, so I tried the one in the living room. Same issue. So I rolled one back to an XBMC 12.0 based build and still saw the same issue. That's when I rebooted everything and it all worked,so I just let it go (until it happened again)

 

I'm still assuming it's unRAID, based on what the guy in the other thread said:

However looking at the mapped drive on a separate windows machine (so also connecting via samba) revealed that it too thought the last modified time of the directory was the end of July. Which was incorrect but consistent with xbmc. It also disagreed with unraid's filesystem.

 

I guess I'll have to verify that part for myself the next time I run into the issue. I'll see if I can replicate it by trying some random things on my unRAID box. Does anyone know how I would go about checking the last modified time of a directory of a mapped share in Windows? eg \\filer\movies mapped to the M drive in Windows. I PMed boof to find out how he figured out his Windows machine was seeing the same error, maybe he can help shed some light

Link to comment

I guess I'll have to verify that part for myself the next time I run into the issue. I'll see if I can replicate it by trying some random things on my unRAID box. Does anyone know how I would go about checking the last modified time of a directory of a mapped share in Windows? eg \\filer\movies mapped to the M drive in Windows. I PMed boof to find out how he figured out his Windows machine was seeing the same error, maybe he can help shed some light

If you can figure out a way to replicate that would be great.  If I can reproduce, then usually I can fix in a matter of minutes.  Figuring out how to replicated and setting it up is what takes all the time.

Link to comment
If you can figure out a way to replicate that would be great.  If I can reproduce, then usually I can fix in a matter of minutes.  Figuring out how to replicated and setting it up is what takes all the time.

 

I haven't quite figured out how to replicate it (if I even can), but it did happen again in my attempts to trigger it. I've just been slowly loading it with new content (Don't judge my collection, I'm just throwing anything I can on there!), just trying to trigger it. Not certain what set it off yet. This time, I didn't stop and start the array so I could have some time to test, and take instruction from you if you wanted me to try anything

 

I also got ahold of boof, and he gave me some the command to check the timestamps within unRAID and Windows (to verify that it isn't just XBMC with the issue). Here are some screenshots:

 

unRAID's last timestamp:

jlZETS6.jpg

 

What Windows sees as the last time stamp (the "." line):

O5CyIFW.jpg

 

Clearly there's a discrepancy in the two. Also, as you can see folders with a later timestamp than unRAID is advertising. Those folders are the ones XBMC is not seeing (when it hash checks the directory). It seems it doesn't like anything after 7:47AM. I wonder if it doesn't like folders with the same timestamp, as there were two folders created at 7:47AM?

Link to comment

This time, I didn't stop and start the array so I could have some time to test, and take instruction from you if you wanted me to try anything

 

I don't know where windows is getting that time stamp for ".".  I don't think this is an issue because I've seen similar behavior with other types of drive letter mapping.  Speaking of drive letter mapping... I never use it, but does this issue only show up using this method to access shares?

 

Anyway, what is interesting is the time stamp shown for "HD Movies" on the linux side appears to be earlier than a couple directories on the windows side: "Street Kings", "People Like Us".  But this could be normal.  For example, suppose you create a file in "Street Kings" - the time stamp of the "Street Kings" directory will be updated but the time stamp of the share directory on the linux side will not.

 

What you might try is this: stop whatever transfers you are doing.  Then repeat those screen shots.  Then Stop/Start array and repeat those screen shots again and let's see if there are any differences.

Link to comment
I don't know where windows is getting that time stamp for ".".

 

That's what it's picking up as the last modified time of the directory/share. Perhaps samba is the problem (which I suspected) and is advertising a different time than what unRAID reports when run directly on the system?

 

but does this issue only show up using this method to access shares?

 

You mean outside of in Windows and XBMC? No. I only noticed it in XBMC, but used Windows to verify that it was a problem at the unRAID end

 

What you might try is this: stop whatever transfers you are doing.  Then repeat those screen shots.  Then Stop/Start array and repeat those screen shots again and let's see if there are any differences.

 

Here's where the fun begins

 

Here's the before shots.

 

unRAID "before" timestamp:

unvzKYN.jpg

 

Windows "before" timestamp:

uIu1k6c.jpg

Note: Timestamp is stuck on the same it was last night

 

Now at this point, I thought rather than starting and stopping the array, I'd try to pinpoint it to Samba. So I stopped and started just the samba service (as you can see in the screenshot), and then took the screenshots

 

unRAID "after" timestamp:

nhqxYvX.jpg

Note: Same timestamp as the "before" shot. No concern there

 

Windows "after" timestamp:

I5vZiR4.jpg

Note: "." timestamp now matches unRAID system timestamp

 

After stopping/starting samba, I also ran an "Update library" on my XBMC system, and it caught all of the folders

Link to comment

instead of playing with it on the unraid side, try disconnecting the windows mapped drive, then reconnecting and compare the time stamps.

 

 

i'd presume stopping/starting samba might have the same effect.

 

or, you can type this into the win7 cmd prompt

 

dir /p "\\egoserve\hd movies" and compare that to the timestamp of "H:"

 

my hypothesis here is that the "." timestamp is created when "H:" is connected.

Link to comment
my hypothesis here is that the "." timestamp is created when "H:" is connected.

 

It is not. That same timestamp persists across multiple Windows machines that I mapped it to, and even if I disconnect and reconnect, it stays the same.

 

i'd presume stopping/starting samba might have the same effect.

 

Samba is the one broadcasting the modified times, and the client is receiving it. Disconnecting and reconnecting a share at the client side wouldn't change what it receives, nor can it control what Samba is broadcasting on the server side, especially considering that the machine I first had issues with only had read/guest access

 

The problem end is not Windows, it is unRAID. I'm not troubleshooting Windows either, I'm only using it to verify issues that I'm getting on an XBMC machine. I wanted to verify the same symptoms on a completely different machine.

Link to comment
are you using a cache drive? just going through the possible variables here.

 

Yes I am, but my understanding of the cache drive is that it should appear as seamless to samba as any other drive in the array. This issue also started well after the last mover script, and well before the next mover script had a chance to run (3AM). The modified time of the share also stays the same from before it runs as it does after, as you can see in the screenshots

Link to comment

are you using a cache drive? just going through the possible variables here.

 

Yes I am, but my understanding of the cache drive is that it should appear as seamless to samba as any other drive in the array. This issue also started well after the last mover script, and well before the next mover script had a chance to run (3AM). The modified time of the share also stays the same from before it runs as it does after, as you can see in the screenshots

 

This appears to be a bug in Samba's SMB2 implementation.  I will post the symptoms to the samba newsgroup.

 

It happens whether you map a share (either disk share or user share, doesn't matter) to a driver letter, or access via UNC.  If you restart samba on the unRaid side, the time stamp gets updated.  If you type "net use * /delete" on the windows side, when it reconnects it also updates the time stamp.

 

If you edit /etc/samba/smb.conf and delete or comment out this line:

 

max protocol = SMB2

or change to

 

max protocol = NT1

 

The problem does not happen, but then you're using older SMB protocol.

 

I'll be moving this thread of the "Issues List".

Link to comment

I also got ahold of boof, and he gave me some the command to check the timestamps within unRAID and Windows (to verify that it isn't just XBMC with the issue). Here are some screenshots:

 

Well done for pushing this forward, I've read this thread with interest.

 

I hope my witterings were useful, it sounds like I was seeing the issue still after all - just not noticeable as xbmc was behaving as I would have expected still.

Link to comment

I've been corresponding with a samba developer on this, and release 5.0.4 will have a patch that might fix it - I say "might" because I can't reproduce the original issue for some reason.  This has been a very strange problem.  When first trying to reproduce, couldn't do it... then later the problem started happening.  I don't know what triggered the problem.  Then I wanted to put together a simple definitive test case to post to samba mailing list, so rebooted everything: server, windows client, linux client.  Simplified the share structure, and haven't been able to reproduce the issue again  ::)

 

A similar bug is reported here:

https://bugzilla.samba.org/show_bug.cgi?id=9870

 

I added the patch created by Jeremy at the end of that report.  So when 5.0.4 gets posted, you guys who can make this happen: please try and see if problem is fixed  ;)

Link to comment