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

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?
  • If you send the debug output to support@zot....org, with a link to this thread, we'll take a look.
  • 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?
  • 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).
  • 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
  • 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.
  • 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.
  • 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.
  • bash:

    firefox 2> foo

    (t)csh:

    firefox >& foo
  • edited August 3, 2009
    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.
  • edited August 2, 2009
    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.
  • 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.
  • edited August 3, 2009
    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
  • 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.
  • edited August 3, 2009
    >>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)
  • edited August 3, 2009
    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).
  • 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.
  • edited August 3, 2009
    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.
  • chrome://zotero/content/test/modtime.xul is available in 2.0b6.4 for others to try.
  • 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
Sign In or Register to comment.