Each syncing all attachments are processed even if there are no changes

polar

Hi,
I have to zotero installations (both 2.06b3 on debian machines). Some times I sync the repositories directly through ssh some times via the zotero sync Option. Both procedures work fine.

But on on computer during syncing all attachments are processed each syncing again. Even if there are no changes. The debug output tells me they are packed and during upload I get the message: "Stored file mod time matches remote file" So the upload is cancelled. But in the zotero window I can see the progress bar. Two times! Then the syncing is finished with no errors.

On the other computer (where the storage, zotero.sqlite and journal are identical) the attachments aren't processed during syncing if there are no changes.

Any idea?

dstillman

If you send the debug output to support@zot....org, with a link to this thread, we'll take a look.

polar

Hi Dan,

I found the error: my direct syncing via ssh (with unison) didn't synchronize the right modification time of files but the mtime seems to be the criteria which zotero uses to decide whether a file is modified or not. So all files on both machines were the same but with different timestamps.

Wouldn't it better to take a more robust one like md5sum?

dstillman

Yes, your debug output showed that your file mtimes were off by a consistent margin. You should be able to tweak Unison to sync the correct times (if you haven't yet).

Using MD5 alone would be much slower, of course, but we could probably use a combination of mtime and MD5 hash—if the mtime differed, check the contents. For most people the mtime should be sufficient, but the hash would help in cases where the mtimes were being altered (including by bugs on Windows and Linux that we haven't yet tracked down that cause mtimes retrieved from files to differ from the mtimes that were just set on those files).

lboloni

Dan,

I am having similar problems - admittedly I am syncing from 5-6 different machines (with jungledisk as the WebDAV). My guess is that this problem is due to the interaction between the bugs and features of various WebDAV implementations, and whatever the computer chooses to do with its own time...

Did you consider instead a simple version number based scheme? Keep a version number per entry, and just increment it when you change an entry, and label it locally modified. If it is not locally modified, and the version number is identical, no further checks are needed. This would avoid the need for computing hashes, etc.

thanks for your great work
Lotzi

polar

Hi Dan,
thanks for your answer. I fixed the problem by telling unison syncing the mtime as well (times = true). But there is another point: It wasn't only that zotero checked all the files once during syncing - but all the times - even if there was no changing at all.
So the sqlite database doesn't seem to be informed if the comparison between local and remote files results in no differences. If the mtime once doesn't match it's a problem all the time.

dstillman

lboloni: The point of checking mtimes (or content hashes) is to allow files edited outside of Zotero to be synced. A version number wouldn't help with that. We also store the mtimes of files in separate property files on the server rather than relying on server mtimes—we don't use the WebDAV server's clock for anything other than a single global check to skip syncing if another client hasn't synced. The problems people have run into so far have resulted from either Firefox or the OS not returning the same mtimes that Zotero previously assigned to files, but we haven't be able to reproduce any such problems ourselves.

polar: I was wondering about that, and I was going to ask for debug output for a second sync run to see what was going on. Based on your initial output, the next sync should've been fine as long as Firefox was returning the correct mtime and you didn't modify the mtimes with unison in between. I'll see if I can reproduce anything like this, but let me know if you see it again.

polar

dan, the debugging mode produces much output on the terminal. too much to find the relevant parts. Is there any possibility direct it to a file? I dind't find out how.

dstillman

bash:

firefox 2> foo

(t)csh:

firefox >& foo

Rintze

I still got the same problem. Reading this thread, I'm beginning to wonder if it has something to do with the fact that at work, my Firefox profile is set up as a roaming profile. As I use the standard data directory (inside the profile), this might mess up the mtimes. I'll try using a custom data directory on Monday.

edit: whoops, forgot I'm running a portable Firefox installation at work, so that's not it.

pesho

Edited: Ignore all this, it seems to be the way time stamps are calculated. Completely irrelevant to the problem.


I have been having this problem for quite a while. It is affecting only certain files. When I checked the modification times of a couple of files they were all -2 hours compared to the time stamp stored in the prop files.

This is on windows Vista with Firefox 3.5 and the latest dev. build of zotero. The WebDav server is running on a ReadyNas NV+ NAS appliance.

All the machines are on pacific time and update their clocks automatically from NTP servers. The clocks are synced within few seconds.

dstillman

pesho: Are you seeing the underlying problem of repeated uploads, though? If so, and you're running the dev build already, upgrade to r4830, load chrome://zotero/content/test/modtime.xul in Firefox, and let me know whether the test passes or fails. If it fails, paste in the output here.

pesho

Dan,

the test passes.

There is a change in the behavior. It tries to upload 98 files, but apparently skips the upload after checking the mtime. It tries the upload twice every time I restart firefox.

I am pasting a snippet of the console log below. Is there a way to redirect the console log to a file in windows? The log is too long and even with console buffer set to 9999 lines, I am loosing large chunk of it.


zotero(5): Binding parameter 1 of type string: "7IWGCT5F"

zotero(3): HTTP GET

zotero(3): 1225826724

zotero(5): SELECT syncState FROM itemAttachments WHERE itemID=?

zotero(5): Binding parameter 1 of type int: 546

zotero(5): SELECT storageModTime FROM itemAttachments WHERE itemID=?

zotero(5): Binding parameter 1 of type int: 546

zotero(3): Stored file mod time matches remote file -- skipping upload

zotero(5): Beginning DB transaction

zotero(3): Beginning Notifier event queue

zotero(5): SELECT syncState FROM itemAttachments WHERE itemID=?

zotero(5): Binding parameter 1 of type int: 546

zotero(5): Transaction in progress -- increasing level to 1

zotero(5): UPDATE itemAttachments SET storageModTime=? WHERE itemID=?

zotero(5): Binding parameter 1 of type int: 1225826724

zotero(5): Binding parameter 2 of type int: 546

zotero(4): Field 'dateModified' has changed from '2009-08-03 06:11:02' to '2009-
08-03 06:24:37'

[snip]

Zotero(4): Updating database with new item data

zotero(5): UPDATE items SET dateModified=?, clientDateModified=? WHERE itemID=?

zotero(5): Binding parameter 1 of type string: "2009-08-03 06:24:37"

zotero(5): Binding parameter 2 of type string: "2009-08-03 06:24:37"

zotero(5): Binding parameter 3 of type int: 546

zotero(5): Decreasing transaction level to 1

zotero(3): Reloading items 546

[snip]

zotero(3): Notifier.trigger('modify', 'item', [546]) queued

zotero(5): Decreasing transaction level to 0

zotero(5): UPDATE itemAttachments SET syncState=? WHERE itemID=?

zotero(5): Binding parameter 1 of type int: 2

zotero(5): Binding parameter 2 of type int: 546

zotero(5): Committing transaction

[snip]

zotero(3): Finishing upload request '7IWGCT5F'

zotero(3): Finished requests: 28

zotero(3): Total requests: 98

dstillman

It tries to upload 98 files, but apparently skips the upload after checking the mtime. It tries the upload twice every time I restart firefox.

But on the next sync, it doesn't run through the files again?

Is there a way to redirect the console log to a file in windows?

No. The console on Windows is more or less unusable, but if you can catch the bit at the beginning of the storage sync, when it first checks for files to upload, that might be more enlightening. You can e-mail the output to support@zot....org with a link to this thread.

Rintze

>>Is there a way to redirect the console log to a file in windows?
No.

I haven't used it, but PowerShell seems to support saving output to (text) files:
http://powershell.com/cs/blogs/ebook/archive/2008/10/20/chapter-1-the-powershell-console.aspx#piping-and-routing

--- (from the page) ---

Redirecting: Storing Information in Files

If you'd like to redirect the result of a command to a file, you can use the redirection symbol ">":
Help > help.txt (Enter)

dstillman

Good idea, but Firefox's console output on Windows opens in a separate standard console window even if Firefox is started from PowerShell. I don't know of any way to have Firefox use a PowerShell window (let alone log that window, though just using it might be a marginal improvement, even if it appears to have the same pathetic 9999-line scrollback limit).

Rintze

Maybe this works:

http://books.google.com/books?id=PNEYS39cvRQC&pg=PA348&lpg=PA348&dq=windows+log+firefox+output+console&source=bl&ots=MK67sGcOjg&sig=PJRdUG0IOR_RDlyRpk3w2PbunPc&hl=en&ei=_d52SsraOIaNjAfYyN2nBg&sa=X&oi=book_result&ct=result&resnum=6#v=onepage&q=windows log firefox output console&f=false

dstillman

I can only get Firefox's internal logging (which uses a different mechanism) using those methods, not Zotero's debug output. Maybe someone else will have better luck.

An alternative would be to have Zotero itself look for a command-line flag that would cause it to log debug output to a file in the data directory.

pesho

Dan,

You can get the debug log from:

http://stoilov.bol.ucla.edu/zotero_log_080409-1.txt

The log partial, I interrupted it once the sync started.

But on the next sync, it doesn't run through the files again?


It actually does. I can't get the part of the log that cover this. I'll see if I can reproduce the problem on a linux machine and post the entire log.

It does.

dstillman

chrome://zotero/content/test/modtime.xul is available in 2.0b6.4 for others to try.

dstillman

There might be a few different issues here, but for at least some people this is likely the same as http://forums.zotero.org/discussion/8155/sync-each-15-seconds/#Item_8