Closed Bug 421610 Opened 16 years ago Closed 16 years ago

Weave users seeing 500 errors

Categories

(mozilla.org Graveyard :: Server Operations, task)

Product:
mozilla.org Graveyard
Component:
Server Operations
Platform:
All
Other
Type:
task
Priority:
Not set
Severity:
major

Tracking

(Not tracked)

Status:
RESOLVED WONTFIX

People

(Reporter: hello, Assigned: oremj)

References

(
URL
)

Details

(Whiteboard: Waiting on apache bug)

Attachments

(1 file)

weave logilfe
613 bytes, application/octet-stream
Details 
See the forum thread here:

https://labs.mozilla.com/forum/index.php/topic,579.0.html

Could you check server logs and see what the problem is?
Assignee: server-ops → oremj
This is no longer a corrupt database.  I think what is happening is:

* Client calls LOCK
* Client fails

* Client tries to LOCK again at another time, but there is already a LOCK in place
* Client fails continuously

Any ideas on how to fix this problem?

Could be, however, shouldn't the server be returning 423 (locked)?  500 is "internal server error".
Okay, nevermind it is corrupt:

[Wed Mar 05 18:04:17 2008] [error] [client 10.2.80.101] Could not LOCK /user/a49cda78d60a2c4b760e62df7c7748c9046e5c6b/ due to a failed precondition (e.g. other locks).  [500, #0]
[Wed Mar 05 18:04:17 2008] [error] [client 10.2.80.101] The locks could not be queried for verification against a possible "If:" header.  [500, #0]
[Wed Mar 05 18:04:17 2008] [error] [client 10.2.80.101] The lock database was found to be corrupt. An indirect lock's direct lock could not be found.  [500, #402]

Looks like this is a rare error: Googling for it only gives me http://catacomb.tigris.org/oldarchive/msg00327.html


Hmm, I wonder if there's something about the pattern of weave requests that is exposing a bug on the server.

Is there a way for us to automatically detect this before we get user complaints about it?
Something can look at the error logs to see if it is happenings, but that still leaves the problems of the error happening before we can catch it.
People are still seeing 500 errors.  Did it go bad again, or what?
Did it ever stop? I've gotten them every time since 0.1.20 came out. Technically, I'm not signed in because of it but weave still synchs anyway.

From the log for a couple of minutes ago (unprompted by me):

2008-03-12 00:33:24	Chrome.Window	INFO	Sync window opened
2008-03-12 00:33:24	Service.Main	INFO	Hashing username albill@arcanology.com
2008-03-12 00:33:24	Service.Main	INFO	Using server URL: https://services.mozilla.com/user/dfba9baf82ab25da08625aa27370c44fb46cdf5a/
2008-03-12 00:33:24	Service.DAV	WARN	_makeRequest: got status 500
2008-03-12 00:33:24	Service.Util	ERROR	Could not get private key from server Error code: 500
2008-03-12 00:33:24	Service.Main	WARN	Exception caught in WeaveSync__login: checkStatus failed
2008-03-12 00:33:27	Chrome.Window	INFO	Sync window closed

Deleted the lock databases are you still seeing a 500?
It seems to have worked once and now I get a locked file when I try to synch. Here is brief log from the one session and the following attempts today:

2008-03-12 10:55:02	Service.Main	INFO	Weave Sync Service Initializing
2008-03-12 10:55:02	Service.Main	INFO	Weave scheduler enabled
2008-03-12 10:55:03	Chrome.Window	INFO	Sync window opened
2008-03-12 10:55:03	Service.Main	INFO	Hashing username albill@arcanology.com
2008-03-12 10:55:03	Service.Main	INFO	Using server URL: https://services.mozilla.com/user/dfba9baf82ab25da08625aa27370c44fb46cdf5a/
2008-03-12 10:55:03	Service.DAV	INFO	Logging in
2008-03-12 10:55:09	Service.DAV	WARN	_makeRequest: got status 500
2008-03-12 10:55:09	Service.Util	ERROR	Could not get private key from server Error code: 500
2008-03-12 10:55:09	Service.Main	WARN	Exception caught in WeaveSync__login: checkStatus failed
2008-03-12 10:56:12	Service.SnapStore	INFO	Read saved snapshot from disk
2008-03-12 10:56:12	Service.BmkEngine	INFO	Beginning sync
2008-03-12 10:56:12	Service.DAV	INFO	Acquiring lock
2008-03-12 10:56:12	Service.BmkEngine	INFO	Lock acquired
2008-03-12 10:56:12	Service.BmkEngine	INFO	Got status file from server
2008-03-12 10:56:12	Service.BmkEngine	INFO	Downloading server deltas
2008-03-12 10:56:14	Service.BmkEngine	INFO	Local snapshot version: 3
2008-03-12 10:56:14	Service.BmkEngine	INFO	Server status: 0
2008-03-12 10:56:14	Service.BmkEngine	INFO	Server maxVersion: 25
2008-03-12 10:56:14	Service.BmkEngine	INFO	Server snapVersion: 0
2008-03-12 10:56:14	Service.BmkEngine	INFO	Reconciling client/server updates
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}8","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":112}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}9","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":115}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}2","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":94}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{5272b39e-26d2-2e4d-8643-ad25447cadd4}2","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":94}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{89e3f696-fff6-2647-bfec-85be29daa9a1}0","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":98}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{89e3f696-fff6-2647-bfec-85be29daa9a1}0","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":98}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{76bd73a7-93e8-b341-a051-66ab4bb3c016}3","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":99}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{76bd73a7-93e8-b341-a051-66ab4bb3c016}3","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":99}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{76bd73a7-93e8-b341-a051-66ab4bb3c016}4","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":100}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{76bd73a7-93e8-b341-a051-66ab4bb3c016}4","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":100}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{76bd73a7-93e8-b341-a051-66ab4bb3c016}5","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":101}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{76bd73a7-93e8-b341-a051-66ab4bb3c016}5","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":101}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{76bd73a7-93e8-b341-a051-66ab4bb3c016}6","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":102}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{76bd73a7-93e8-b341-a051-66ab4bb3c016}6","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":102}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{37de05fb-8507-f44f-9ead-1734179d02eb}0","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":103}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{37de05fb-8507-f44f-9ead-1734179d02eb}0","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":103}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{37de05fb-8507-f44f-9ead-1734179d02eb}1","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":104}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{37de05fb-8507-f44f-9ead-1734179d02eb}1","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":104}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{37de05fb-8507-f44f-9ead-1734179d02eb}2","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":105}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{37de05fb-8507-f44f-9ead-1734179d02eb}2","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":105}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{eab3b75d-0a4a-6e4e-9801-69f495453ab6}0","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":106}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{eab3b75d-0a4a-6e4e-9801-69f495453ab6}0","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":106}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{6bf4665f-7059-9c46-8afd-998c02c6ce33}0","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":107}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{6bf4665f-7059-9c46-8afd-998c02c6ce33}0","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":107}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{6bf4665f-7059-9c46-8afd-998c02c6ce33}1","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":108}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{6bf4665f-7059-9c46-8afd-998c02c6ce33}1","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":108}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{6bf4665f-7059-9c46-8afd-998c02c6ce33}2","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":109}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{6bf4665f-7059-9c46-8afd-998c02c6ce33}2","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":109}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{6bf4665f-7059-9c46-8afd-998c02c6ce33}3","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":110}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{6bf4665f-7059-9c46-8afd-998c02c6ce33}3","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":110}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{6bf4665f-7059-9c46-8afd-998c02c6ce33}4","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":111}}
2008-03-12 10:56:15	Service.BMSync	ERROR	commandLike: Unknown item type: {"action":"edit","GUID":"{6bf4665f-7059-9c46-8afd-998c02c6ce33}4","depth":2,"parents":["{08f5a78b-eafc-3248-842a-4cd1c5947257}434","{08f5a78b-eafc-3248-842a-4cd1c5947257}0"],"data":{"index":111}}
2008-03-12 10:56:15	Service.BmkEngine	INFO	Changes for client: 18
2008-03-12 10:56:15	Service.BmkEngine	INFO	Predicted changes for server: 1
2008-03-12 10:56:15	Service.BmkEngine	INFO	Client conflicts: 2
2008-03-12 10:56:15	Service.BmkEngine	INFO	Server conflicts: 2
2008-03-12 10:56:15	Service.BmkEngine	WARN	Conflicts found!  Discarding server changes
2008-03-12 10:56:15	Service.BmkEngine	INFO	Applying changes locally
2008-03-12 10:56:15	Service.DAV	INFO	Releasing lock
2008-03-12 10:56:15	Service.DAV	INFO	Lock released (or we didn't have one)
2008-03-12 10:56:15	Async.Generator	ERROR	Exception caught in WeaveSync__sync: URI is not defined
2008-03-12 11:25:02	Service.Main	INFO	Running scheduled sync
2008-03-12 11:25:02	Service.Main	WARN	Service lock failed: already locked
2008-03-12 11:55:02	Service.Main	INFO	Running scheduled sync
2008-03-12 11:55:02	Service.Main	WARN	Service lock failed: already locked
2008-03-12 12:25:02	Service.Main	INFO	Running scheduled sync
2008-03-12 12:25:02	Service.Main	WARN	Service lock failed: already locked
2008-03-12 12:55:02	Service.Main	INFO	Running scheduled sync
2008-03-12 12:55:02	Service.Main	WARN	Service lock failed: already locked
2008-03-12 13:06:10	Service.Main	WARN	Service lock failed: already locked
2008-03-12 13:06:25	Service.Main	WARN	Service lock failed: already locked
2008-03-12 13:06:25	Service.Main	WARN	Service lock failed: already locked
2008-03-12 13:06:25	Service.Main	WARN	Service lock failed: already locked
2008-03-12 13:06:26	Service.Main	WARN	Service lock failed: already locked
2008-03-12 13:06:30	Service.Main	WARN	Service lock failed: already locked
2008-03-12 13:06:32	Service.Main	WARN	Service lock failed: already locked
2008-03-12 13:06:32	Service.Main	WARN	Service lock failed: already locked
2008-03-12 13:06:32	Service.Main	WARN	Service lock failed: already locked
2008-03-12 13:25:02	Service.Main	INFO	Running scheduled sync
2008-03-12 13:25:02	Service.Main	WARN	Service lock failed: already locked

Okay, it seems you're hitting a *different* 500 error (I see this too).  The add-on attempts to get the private key if it exists, it's hosted at:

<user store>/private/privkey

For example:

https://services.mozilla.com/user/79020a8b2ddd5633801b242ea3df3056c8dfcc37/private/privkey

When the 'private' folder does not exist, attempting to access these two URLs will result in a 500 error insteaad of a 404:

<user store>/private/privkey
<user store>/private/

But this one gives me a 404 (no trailing slash):

<user store>/private

This doesn't happen with my personal testing server, which delayed my debugging :-/

I will modify the add-on to consider 500 a 404 in this case.
Missing files will now return 404 instead of 500, like they should.
excellent!
should we leave this bug open to investigate the locking-related 500 errors?
We could leave it open a couple more days.  Maybe this will fix the issue.
Is this still happening?
No, it is not.
Closing, please reopen if this starts to happen again.
Status: NEW → RESOLVED
Closed: 16 years ago
Resolution: --- → FIXED
Hmm, looks like one user hit a 500 error here:

https://labs.mozilla.com/forum/index.php/topic,619.msg2293.html#msg2293
Reopening.
Can we get the 'infrastructure-related bugs' group flag cleared?  I left that checked by accident when I submitted the bug.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Group: infra
Here's another:

https://labs.mozilla.com/forum/index.php/topic,632.msg2355.html#msg2355

Are these all for different reasons?  I'd really like to find out if there's something I'm doing in the add-on that puts the server in a bad state.  I could attempt to work around it if I knew what the problem was.
Are you running apache on your personal testing server and have you been able to reproduce the problem at all?
Yes, I'm running this version:

i  apache2              2.2.4-3ubuntu0.1
ii  apache2-mpm-prefork  2.2.4-3ubuntu0.1

I *have* gotten this problem on my server, but I have not been able to come up with a reproducible test case, and come to think of it, I upgraded apache and can't remember if I saw it before or after the upgrade (I haven't seen the problem in a while).

The internets have not been super helpful, either.  Most people getting 500 errors from mod_dav just seem to have incorrect permissions to the lock db.
Looking at apache's svn it looks like they haven't patched dav in >20 months, but maybe there was a fix in there somewhere that redhat hasn't picked up.  Would you post a tarball of the modules/dav/ directory of the apache you are using?
er, /usr/lib/apache2/modules? (no dav/ there)
I can also make you an account if you want to poke around.  Ping me on irc.
I've got version 01.28, but I still get this:

2008-04-02 10:43:04	Chrome.Window	INFO	Login successful
2008-04-02 10:43:23	Service.DAV	WARN	_makeRequest: got status 500
2008-04-02 10:43:23	Async.Generator	ERROR	Exception caught in  WeaveLockWrapper: Could not acquire lock

I am receiving this as well. Install on Vista machine worked fine. Installed on XP machine and attempted a synch. I can successfully log in but then will not sunch even after resetting server login and resetting server lock. Log follows:
2008-04-02 16:30:52	Service.DAV	WARN	_makeRequest: got status 500
2008-04-02 16:30:52	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-02 16:30:53	Service.DAV	WARN	_makeRequest: got status 500
2008-04-02 16:30:53	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-02 16:30:56	Service.DAV	WARN	_makeRequest: got status 500
2008-04-02 16:30:56	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-02 16:30:57	Service.DAV	WARN	_makeRequest: got status 500
2008-04-02 16:30:57	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-02 16:30:58	Service.DAV	WARN	_makeRequest: got status 500
2008-04-02 16:30:58	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-02 16:30:59	Service.DAV	WARN	_makeRequest: got status 500
2008-04-02 16:30:59	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-02 16:31:00	Service.DAV	WARN	_makeRequest: got status 500
2008-04-02 16:31:00	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-02 16:32:42	Service.Main	INFO	Logging out
2008-04-02 16:33:15	Chrome.Window	INFO	Login successful
2008-04-02 16:33:24	Service.DAV	WARN	_makeRequest: got status 500
2008-04-02 16:33:24	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock


I am also seeing this with version 0.1.29 on Ubuntu Hardy 8.04
Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9b4) Gecko/2008031317 Firefox/3.0b4


mod_dav hasn't been modified for about 20 months, so it looks like we are running the most current version.  Dan, is there anything I can do on my end that would help you resolve this, get you logs etc?
Is apache logging any errors?  500 is an "internal server error", so it should be logging something.  Perhaps we need to run it with some verbosity knob turned up?
Running into this on my Vista machine as well; Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US; rv:1.9b5) Gecko/2008032620 Firefox/3.0b5. Verbose log:

2008-04-02 23:59:45	Service.DAV	DEBUG	LOCK request for 
2008-04-02 23:59:51	Service.DAV	WARN	_makeRequest: got status 500
2008-04-02 23:59:51	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-02 23:59:51	Async.Generator	DEBUG	Stack trace:
JS frame :: chrome://browser/content/browser.xul :: oncommand :: line 1
JS frame :: chrome://weave/content/sync.js :: Sync_doSync :: line 260
JS frame :: file:///C:/Users/johnarush/AppData/Roaming/Mozilla/Firefox/Profiles/g435q67b.default/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/service.js :: WeaveSync_sync :: line 498
JS frame :: unknown (async) :: WeaveLockWrapper
2008-04-03 00:00:09	Service.DAV	DEBUG	LOCK request for 
2008-04-03 00:00:12	Service.DAV	WARN	_makeRequest: got status 500
2008-04-03 00:00:12	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-03 00:00:12	Async.Generator	DEBUG	Stack trace:
JS frame :: chrome://browser/content/preferences/preferences.xul :: oncommand :: line 1
JS frame :: file:///C:/Users/johnarush/AppData/Roaming/Mozilla/Firefox/Profiles/g435q67b.default/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/service.js :: WeaveSync_sync :: line 498
JS frame :: unknown (async) :: WeaveLockWrapper

Same here! Vista 32 bits Home, Firefox 3.0b5, 01.28 Weave
Firefox 3.0b5, Mac OS X 10.5.2

2008-04-02 09:43:20	Chrome.Window	INFO	Login successful
2008-04-02 09:43:24	Service.DAV	WARN	_makeRequest: got status 500
2008-04-02 09:43:24	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-02 09:43:28	Service.DAV	WARN	_makeRequest: got status 500
2008-04-02 09:43:28	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-02 09:44:02	Service.DAV	WARN	_makeRequest: got status 500
2008-04-02 09:44:02	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock

And detailed log is: 
2008-04-02 09:56:08	Chrome.Login	TRACE	Sync login window opened
2008-04-02 09:56:10	Service.Main	DEBUG	Logging in
2008-04-02 09:56:10	Service.DAV	DEBUG	Logging in
2008-04-02 09:56:10	Service.DAV	DEBUG	GET request for 
2008-04-02 09:56:10	Service.DAV	DEBUG	GET request for meta/version
2008-04-02 09:56:10	Service.DAV	DEBUG	GET request for private/privkey
2008-04-02 09:56:11	Service.Util	DEBUG	Running command: /Users/vasechka/Library/Application Support/Firefox/Profiles/bce3kk0i.default/extensions/{340c2bbc-ce74-4362-90b5-7c26312808ef}/openssl/unix/exec.sh /Users/vasechka/Library/Application Support/Firefox/Profiles/bce3kk0i.default/weave/tmp openssl rsa -in key -pubout -out output -passin file:pass
2008-04-02 09:56:11	Chrome.Window	INFO	Login successful
2008-04-02 09:56:11	Chrome.Login	TRACE	Sync login window closed
2008-04-02 09:56:51	Service.DAV	DEBUG	LOCK request for 
2008-04-02 09:56:52	Service.DAV	WARN	_makeRequest: got status 500
2008-04-02 09:56:52	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-02 09:56:52	Async.Generator	DEBUG	Stack trace:
JS frame :: chrome://browser/content/browser.xul :: oncommand :: line 1
JS frame :: chrome://weave/content/sync.js :: Sync_doSync :: line 260
JS frame :: file:///Users/vasechka/Library/Application%20Support/Firefox/Profiles/bce3kk0i.default/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/service.js :: WeaveSync_sync :: line 498
JS frame :: unknown (async) :: WeaveLockWrapper
I have this same "Exception caught in WeaveLockWrapper: Could not acquire lock" error when doing manual sync. My services.mozilla.com user name is stephen@ju-ju.com.

I noticed Weave is connecting via WebDAV so I connected to my user directory and tried to delete all files and directories there. Everything could be deleted but one: "user-data" and "bookmarks" directory in it. "bookmarks" directory is reported "No such file or directory" but it's still in the list.

Some file system problem?
(In reply to comment #29)
> Is apache logging any errors?  500 is an "internal server error", so it should
> be logging something.  Perhaps we need to run it with some verbosity knob
> turned up?
> 

Apache is logging the same errors I posted in comment 3.  The LogLevel is set to debug.
Hrm, so, "The lock database was found to be corrupt" is worrisome.  Why is it not trying to at least reset the db, if it knows it's corrupt?

Searching for that phrase, I've only found some reports that it is "fixed" (in 2003), and only one other question about it, in 2001.

Not really sure how to proceed here...
Yeah, I ran in to the same problem googling for the problem and asking in #apache.  No one seemed to know what could be wrong.  Since you have seen these errors before on your server it seems like we must be doing something wrong on the client side.  On the other hand it seems like dav wouldn't allow a client to corrupt its lock database...
Given the nature of error 500, it is by definition a server problem.  However, it may be there is some particular workaround we could do client-side, if we knew what causes the mod_dav bug.

Obviously things would be much easier if we had a reproducible test case, rather than random sightings.

One point of note: dholbert just started seeing this yesterday, he says it started happening after he attempted a 'server reset' (which does a PROPFIND on the server and then a DELETE for all the files).  I've done that dozens of times, though, so I'm not sure what was special about the time he did it.  Perhaps it's a red herring.

Can we extract any information from the lock db?  It seems to be a proprietary binary format, but I didn't look into it a lot.  Maybe if we knew exactly which "indirect" locks are being left behind, we could guess what the problem might be.
I ve got 500:
2008-04-05 23:01:44	Service.DAV	DEBUG	LOCK request for 
2008-04-05 23:01:46	Service.DAV	WARN	_makeRequest: got status 500
2008-04-05 23:01:46	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-05 23:01:46	Async.Generator	DEBUG	Stack trace:
JS frame :: chrome://browser/content/preferences/preferences.xul :: oncommand :: line 1
JS frame :: file:///C:/Documents%20and%20Settings/Administrator/Application%20Data/Mozilla/Firefox/Profiles/wygkk12w.default/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/service.js :: WeaveSync_sync :: line 498
JS frame :: unknown (async) :: WeaveLockWrapper

FFb5, Weave 0.1.29

My username is kukachik@gmail.com

Since 0.1.29 (I think I had 0.1.28 working) I consistently get the 500 error and can't sync from any system. Last sync was March 31.
FF 3.0b5, Fedora 9b and OS X, 10.5.1

Below is a bookmark sync attempt after resetting login data:
------------------------------------
2008-04-05 09:49:48	Chrome.Wizard	INFO	Initializing setup wizard
2008-04-05 09:49:48	Chrome.Wizard	INFO	Showing welcome page
2008-04-05 09:49:50	Chrome.Wizard	INFO	Showing backup page
2008-04-05 09:49:51	Chrome.Wizard	INFO	Showing account page
2008-04-05 09:50:14	Chrome.Wizard	INFO	Verifying login
2008-04-05 09:50:14	Chrome.Wizard	INFO	Adding user login/password to password manager
2008-04-05 09:50:15	Service.Main	INFO	Logging out
2008-04-05 09:50:15	Chrome.Wizard	INFO	Logged out
2008-04-05 09:50:15	Service.Main	DEBUG	Logging in
2008-04-05 09:50:15	Service.DAV	DEBUG	Logging in
2008-04-05 09:50:15	Service.DAV	DEBUG	GET request for 
2008-04-05 09:50:15	Service.DAV	DEBUG	GET request for meta/version
2008-04-05 09:50:15	Service.DAV	DEBUG	GET request for private/privkey
2008-04-05 09:50:15	Service.Util	DEBUG	Running command: /home/kevin/.mozilla/firefox/9go46667.kevin/extensions/{340c2bbc-ce74-4362-90b5-7c26312808ef}/openssl/unix/exec.sh /home/kevin/.mozilla/firefox/9go46667.kevin/weave/tmp openssl rsa -in key -pubout -out output -passin file:pass
2008-04-05 09:50:15	Chrome.Wizard	INFO	Login verified
2008-04-05 09:50:15	Chrome.Window	INFO	Login successful
2008-04-05 09:50:17	Chrome.Wizard	INFO	Showing initialization page
2008-04-05 09:50:20	Service.DAV	DEBUG	LOCK request for 
2008-04-05 09:50:20	Service.DAV	WARN	_makeRequest: got status 500
2008-04-05 09:50:20	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-05 09:50:20	Async.Generator	DEBUG	Stack trace:
JS frame :: chrome://weave/content/wizard.xul :: oncommand :: line 1
JS frame :: chrome://weave/content/wizard.js :: SyncWizard_onSync :: line 187
JS frame :: file:///home/kevin/.mozilla/firefox/9go46667.kevin/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/service.js :: WeaveSync_sync :: line 498
JS frame :: unknown (async) :: WeaveLockWrapper
2008-04-05 09:50:26	Chrome.Wizard	INFO	Shutting down setup wizard

Experiencing the same issue with new install of Vista x64

2008-04-07 01:55:06	Chrome.Wizard	INFO	Initializing setup wizard
2008-04-07 01:55:06	Chrome.Wizard	INFO	Showing welcome page
2008-04-07 01:55:07	Chrome.Wizard	INFO	Showing backup page
2008-04-07 01:55:08	Chrome.Wizard	INFO	Showing account page
2008-04-07 01:55:18	Chrome.Wizard	INFO	Verifying login
2008-04-07 01:55:18	Chrome.Wizard	INFO	Adding user login/password to password manager
2008-04-07 01:55:18	Service.Main	INFO	Logging out
2008-04-07 01:55:18	Chrome.Wizard	INFO	Logged out
2008-04-07 01:55:21	Chrome.Wizard	INFO	Login verified
2008-04-07 01:55:21	Chrome.Window	INFO	Login successful
2008-04-07 01:55:22	Chrome.Wizard	INFO	Showing initialization page
2008-04-07 01:55:24	Service.DAV	WARN	_makeRequest: got status 500
2008-04-07 01:55:24	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock

If I connect to the service via OSX's "Connect to server" I can read and upload files with no problem, even if apache is reporting a corrupt lock database for other requests.
(In reply to comment #41)
but you can't delete some folders - it is reported as being in use.  
I don't think OSX grabs a lock before doing other things, so that would explain why you can still use it sometimes.  The Weave add-on grabs a lock before doing anything at all on the server.

We could investigate locking in some other fashion, perhaps by putting a file on the server and using etags, but I'm not sure how feasible that will be.  I remember considering it long ago and rejecting the idea, but I don't recall why exactly.

As an aside, I'm not super surprised there is a mod_dav bug around locking.  The WebDAV spec is almost hilariously complicated when it comes to locks.
Did some more testing with OSX's client.  I created 500 files and 500 directories.  I then wrote to all 500 files and deleted some of the directories.  I still haven't been able to corrupt the database.  Looks like OSX's client is doing locking for writes.

10.2.80.101 -  [06/Apr/2008:21:38:00 -0700] "UNLOCK /user/7243876d83a1be87be825998e10e2a1ffef7512e/test/file224 HTTP/1.1" 204 - "-" "WebDAVFS/1.5 (01508000) Darwin/9.2.0 (i386)"
10.2.80.101 - [06/Apr/2008:21:38:00 -0700] "UNLOCK /user/7243876d83a1be87be825998e10e2a1ffef7512e/test/file226 HTTP/1.1" 204 - "-" "WebDAVFS/1.5 (01508000) Darwin/9.2.0 (i386)"
10.2.80.101 - [06/Apr/2008:21:38:00 -0700] "LOCK /user/7243876d83a1be87be825998e10e2a1ffef7512e/test/file218 HTTP/1.1" 200 467 "-" "WebDAVFS/1.5 (01508000) Darwin/9.2.0 (i386)"
10.2.80.101 -  [06/Apr/2008:21:38:00 -0700] "LOCK /user/7243876d83a1be87be825998e10e2a1ffef7512e/test/file219 HTTP/1.1" 200 467 "-" "WebDAVFS/1.5 (01508000) Darwin/9.2.0 (i386)"

Running 0.1.29 on FF3b5 (Ubuntu AMD64) and get the same since 02 April.

Also, I can verify my account, but when I try and do the first time transfer, it seems to get the same block.

==============================================================================

2008-04-02 20:49:09	Service.Main	INFO	Weave Sync Service Initializing
2008-04-02 20:49:09	Service.Main	INFO	Weave scheduler enabled
2008-04-02 20:49:16	Chrome.Window	INFO	Login successful
2008-04-02 21:19:09	Service.Main	INFO	Running scheduled sync
2008-04-02 21:19:10	Service.DAV	WARN	_makeRequest: got status 423
2008-04-02 21:19:10	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-02 21:49:08	Service.Main	INFO	Running scheduled sync
2008-04-02 21:49:10	Service.DAV	WARN	_makeRequest: got status 500
2008-04-02 21:49:10	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-03 08:58:01	Service.Main	INFO	Running scheduled sync
2008-04-03 08:58:01	Service.DAV	WARN	_makeRequest: got status 2147746065
2008-04-03 08:58:01	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-03 09:28:01	Service.Main	INFO	Running scheduled sync
2008-04-03 09:28:01	Service.DAV	WARN	_makeRequest: got status 2147746065
2008-04-03 09:28:01	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-03 09:58:00	Service.Main	INFO	Running scheduled sync
2008-04-03 09:58:03	Service.DAV	WARN	_makeRequest: got status 500
2008-04-03 09:58:03	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock

/user/foo/user-data/history seems to disappear.  I am seeing:

[02/Apr/2008:14:35:54 -0700] "GET /user/foo/user-data/history/ HTTP/1.1" 200 1426 "-" "Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9b4) Gecko/2008031317 Firefox/3.0b4"

...

[02/Apr/2008:15:05:51 -0700] "GET /user/foo/user-data/history/ HTTP/1.1" 200 1426 "-" "Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9b4) Gecko/2008031317 Firefox/3.0b4"
[03/Apr/2008:06:44:34 -0700] "GET /user/foo/user-data/history/ HTTP/1.1" 404 340 "-" "Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9b4) Gecko/2008031317 Firefox/3.0b4"

Randomly apache will respond with a 404 for that file.  The client will then try a MKCOL to create that directory.  After the LOCK, random 404, MKCOL, UNLOCK any LOCK after will return at 500.



Gets 404 because user-data is deleted, so that isn't so random after all.  Anyways, this always seems to occur on the "LOCK,mkcols,UNLOCK,LOCK" after DELETE /user/foo/user-data/
2008-04-08 09:03:15	Service.Main	INFO	Weave Sync Service Initializing
2008-04-08 09:03:15	Service.Main	INFO	Weave scheduler enabled
2008-04-08 09:03:35	Chrome.Window	INFO	Login successful
2008-04-08 09:33:15	Service.Main	INFO	Running scheduled sync
2008-04-08 09:33:16	Service.DAV	WARN	_makeRequest: got status 500
2008-04-08 09:33:16	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-08 10:03:15	Service.Main	INFO	Running scheduled sync
2008-04-08 10:03:17	Service.DAV	WARN	_makeRequest: got status 500
2008-04-08 10:03:17	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock

I just installed httpd 2.2.8.  Let's see if it solves the problem.
Jeremy:  Is that updated httpd already running?  'cause it's still broken for me:
-----------
2008-04-08 11:28:51	Service.DAV	WARN	_makeRequest: got status 500
2008-04-08 11:28:51	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock

(In reply to comment #50)
> Jeremy:  Is that updated httpd already running?  'cause it's still broken for
> me:

I only upgraded one of the fs servers.  I think you may be on the one I haven't upgraded.
(In reply to comment #47)
> Gets 404 because user-data is deleted, so that isn't so random after all. 
> Anyways, this always seems to occur on the "LOCK,mkcols,UNLOCK,LOCK" after
> DELETE /user/foo/user-data/

At least that narrows it down.  DELETE /user/foo/user-data comes from a 'server wipe' routine I have, which does a PROPFIND in the user directory and removes anything it finds.

(In reply to comment #49)
> I just installed httpd 2.2.8.  Let's see if it solves the problem.

Cool.  I hope so!
STill getting an error on: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9b5) Gecko/2008032620 Firefox/3.0b5

08 16:44:40	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-08 16:44:42	Service.DAV	WARN	_makeRequest: got status 500
2008-04-08 16:44:42	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock

Weave synced for the 1st time in many weeks. I guess I am on the updated server?
Same for me, I was getting the exact same errors as above before.  The apache update seems to have done the trick.  Thank you very much.
Extremely cool.
Jeremy, have you upgraded all the fs nodes?
Syncing again now.

Thanks.
Still not syncing from any client system using weave 0.1.29:

2008-04-09 06:25:17	Chrome.Window	INFO	Login successful
2008-04-09 06:26:37	Service.DAV	DEBUG	LOCK request for 
2008-04-09 06:26:37	Service.DAV	WARN	_makeRequest: got status 500
2008-04-09 06:26:37	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-09 06:26:37	Async.Generator	DEBUG	Stack trace:
JS frame :: chrome://browser/content/browser.xul :: oncommand :: line 1
JS frame :: chrome://weave/content/sync.js :: Sync_doSync :: line 260
JS frame :: file:///Users/kevin/Library/Application%20Support/Firefox/Profiles/mecd3m7p.kevin/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/service.js :: WeaveSync_sync :: line 498
JS frame :: unknown (async) :: WeaveLockWrapper

--
Kevin
Still seeing:

[Wed Apr 09 15:22:04 2008] [error] [client 10.2.80.101] Could not LOCK /user/d73bdc0f79ad2e09750e1f446ce2ed303badf44b/ due to a failed precondition (e.g. other locks).  [500, #0]
[Wed Apr 09 15:22:04 2008] [error] [client 10.2.80.101] The locks could not be queried for verification against a possible "If:" header.  [500, #0]
[Wed Apr 09 15:22:04 2008] [error] [client 10.2.80.101] (2)No such file or directory: The lock database was found to be corrupt. An indirect lock's direct lock could not be found.  [500, #402]

I have not been able to sync since 31-March from any system (Linux or Mac) using various versions of weave. I am stuck with:
Service.DAV     WARN    _makeRequest: got status 500
Async.Generator ERROR   Exception caught in WeaveLockWrapper: Could not acquire lock

...on all weave clients. Can someone either delete my account (so I can recreate it) or delete the contents of my user directory?

/user/85a6f16349585aa02522eaf1f2c87b44b62396e3

Username: kps@sent.com

I can't do this from the weave client, all I get is the above errors.

Thanks,
Kevin
Can't sync for this reason (Verbose Log) for a long time:

:02	Service.DAV	DEBUG	LOCK request for 
2008-04-11 15:49:02	Service.DAV	DEBUG	GET request for meta/version
2008-04-11 15:49:03	Service.DAV	DEBUG	GET request for private/privkey
2008-04-11 15:49:04	Service.Util	DEBUG	Running command: C:\PortableApps\FirefoxPortable\Data\profile\extensions\{340c2bbc-ce74-4362-90b5-7c26312808ef}\openssl\win32\exec.bat C:\PortableApps\FirefoxPortable\Data\profile\weave\tmp C:\PortableApps\FirefoxPortable\Data\profile\extensions\{340c2bbc-ce74-4362-90b5-7c26312808ef}\openssl\win32\openssl.exe rsa -in key -pubout -out output -passin file:pass
2008-04-11 15:49:04	Service.BmkEngine	INFO	Beginning sync
2008-04-11 15:49:04	Service.DAV	DEBUG	GET request for user-data/
2008-04-11 15:49:05	Service.DAV	DEBUG	GET request for user-data/bookmarks/
2008-04-11 15:49:05	Service.BmkEngine	DEBUG	Getting status file from server
2008-04-11 15:49:05	Service.DAV	DEBUG	GET request for user-data/bookmarks/status.json
2008-04-11 15:49:06	Service.BmkEngine	INFO	Got status file from server
2008-04-11 15:49:06	Service.DAV	DEBUG	UNLOCK request for 
2008-04-11 15:49:07	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIJSON.decode]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: file:///C:/PortableApps/FirefoxPortable/Data/profile/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/engines.js :: BmkEngine__getServerData :: line 476"  data: no]
2008-04-11 15:49:07	Async.Generator	DEBUG	Stack trace:
JS frame :: chrome://browser/content/browser.xul :: oncommand :: line 1
JS frame :: chrome://weave/content/sync.js :: Sync_doSync :: line 260
JS frame :: file:///C:/PortableApps/FirefoxPortable/Data/profile/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/service.js :: WeaveSync_sync :: line 498
JS frame :: unknown (async) :: WeaveLockWrapper





JS frame :: file:///C:/PortableApps/FirefoxPortable/Data/profile/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/util.js :: EL_notify :: line 354
JS frame :: file:///C:/PortableApps/FirefoxPortable/Data/profile/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/async.js :: anonymous :: line 214
JS frame :: file:///C:/PortableApps/FirefoxPortable/Data/profile/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/async.js :: AsyncGen__done :: line 237
JS frame :: file:///C:/PortableApps/FirefoxPortable/Data/profile/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/async.js :: anonymous :: line 103
JS frame :: file:///C:/PortableApps/FirefoxPortable/Data/profile/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/async.js :: AsyncGen_cont :: line 188
JS frame :: file:///C:/PortableApps/FirefoxPortable/Data/profile/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/engines.js :: BmkEngine__sync :: line 264
JS frame :: unknown (async) :: BmkEngine__getServerData

Any suggestions?
Thanks.
(In reply to comment #51)
> (In reply to comment #50)
> > Jeremy:  Is that updated httpd already running?  'cause it's still broken for
> > me:
> 
> I only upgraded one of the fs servers.  I think you may be on the one I haven't
> upgraded.
> 

Cool -- this bug is WORKSFORME now!  I'm guessing IT / WebDev must have now updated the fs server that I'm on now.  Yay!

I'm still seeing corrupt database errors in the database.  If there was a way to reproduce the error I could file a bug with apache, but it seems to be pretty random.  As a work around we could

* Stop locking the top level directory on the client.
* Cron job delete the lock database every minute ( this would pretty much defeat the purpose of locking )

Thoughts?
Works for me as well!
(In reply to comment #63)
> I'm still seeing corrupt database errors in the database.  If there was a way
> to reproduce the error I could file a bug with apache, but it seems to be
> pretty random.  As a work around we could
> 
> * Stop locking the top level directory on the client.
> * Cron job delete the lock database every minute ( this would pretty much
> defeat the purpose of locking )
> 
> Thoughts?

Indeed, I've had more reports of it.  Just now in fact a friend pinged me, he's seeing them.

I'm not sure how else to do locks.  Would it work if I lock only a file?  I could lock a specific file, I guess.  It would not be correct, but it would work as long as you only use the weave add-on (or whatever you use knows of our specific convention).

I was seeing error 500 - it stopped, but a new error started almost immediately:

-----

2008-04-11 02:55:13	Service.Main	INFO	Running scheduled sync
2008-04-11 02:55:14	Service.DAV	WARN	_makeRequest: got status 500
2008-04-11 02:55:14	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-04-11 03:25:13	Service.Main	INFO	Running scheduled sync
2008-04-11 03:25:15	Service.SnapStore	WARN	Could not parse saved snapshot; reverting to initial-sync state
2008-04-11 03:25:15	Service.BmkEngine	INFO	Beginning sync
2008-04-11 03:25:16	Service.BmkEngine	INFO	Got status file from server
2008-04-11 03:25:16	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIJSON.decode]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: file:///C:/Documents%20and%20Settings/rpassava/Application%20Data/Mozilla/Firefox/Profiles/ox1wmu26.default/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/engines.js :: BmkEngine__getServerData :: line 476"  data: no]

-----

Since then I have been getting the "exception" error in WeaveLockWrapper whenever I try and sync.
Attached file weave logilfe — 
I get this lock problems too.
Just filed https://issues.apache.org/bugzilla/show_bug.cgi?id=44865.  I'm not sure anything will come from it since we can't find a way to reliably reproduce with one client, but it's worth a shot.
Thanks.  Maybe something will come out of that.

I've changed the client to lock only one file, the change will go out in the next update (possibly tomorrow).
Whiteboard: Waiting on apache bug
Weave: v0.1.29
User: kps AT sent DOT com
2008-05-08 21:07:44	Chrome.Window	INFO	Login successful
2008-05-08 21:07:55	Service.DAV	WARN	_makeRequest: got status 500
2008-05-08 21:07:55	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock

Constant failure with this account from multiple clients. Other user accounts work OK from same Weave clients.
Been failing for about a month from each of my machines: linux, win xp, win 2k3.

2008-05-08 21:49:35	Service.Util	DEBUG	Running command: /home/ubuntu/.mozilla/firefox/profile/extensions/{340c2bbc-ce74-4362-90b5-7c26312808ef}/openssl/unix/exec.sh /home/ubuntu/.mozilla/firefox/profile/weave/tmp openssl rsautl -decrypt -inkey tmp-key -in tmp-output -out output
2008-05-08 21:49:35	Service.HistEngine	INFO	Downloading server deltas
2008-05-08 21:49:35	Service.DAV	DEBUG	GET request for user-data/history/deltas.json
2008-05-08 21:49:35	Service.DAV	WARN	_makeRequest: got status 404
2008-05-08 21:49:35	Service.Util	ERROR	Could not download deltas. Error code: 404
2008-05-08 21:49:35	Service.DAV	DEBUG	UNLOCK request for 
2008-05-08 21:49:35	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: checkStatus failed
2008-05-08 21:49:35	Async.Generator	DEBUG	Stack trace:
JS frame :: chrome://browser/content/browser.xul :: oncommand :: line 1
JS frame :: chrome://weave/content/sync.js :: Sync_doSync :: line 260
JS frame :: file:///home/ubuntu/.mozilla/firefox/profile/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/service.js :: WeaveSync_sync :: line 498
JS frame :: unknown (async) :: WeaveLockWrapper





JS frame :: file:///home/ubuntu/.mozilla/firefox/profile/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/util.js :: EL_notify :: line 354
JS frame :: file:///home/ubuntu/.mozilla/firefox/profile/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/async.js :: anonymous :: line 214
JS frame :: file:///home/ubuntu/.mozilla/firefox/profile/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/async.js :: AsyncGen__done :: line 237
JS frame :: file:///home/ubuntu/.mozilla/firefox/profile/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/async.js :: anonymous :: line 103
JS frame :: file:///home/ubuntu/.mozilla/firefox/profile/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/async.js :: AsyncGen_cont :: line 188
JS frame :: file:///home/ubuntu/.mozilla/firefox/profile/extensions/%7B340c2bbc-ce74-4362-90b5-7c26312808ef%7D/modules/engines.js :: BmkEngine__sync :: line 264
JS frame :: unknown (async) :: BmkEngine__getServerData

Weave has been running smoothly until a few days ago, then I started getting these error messages:

2008-05-08 08:36:47	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: openssl did not run successfully, error code 1

2008-05-09 18:21:45	Service.DAV	WARN	_makeRequest: got status 500
2008-05-09 18:21:45	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-05-09 18:22:06	Service.Main	INFO	Logging out
2008-05-09 18:22:14	Chrome.Window	INFO	Login successful
2008-05-09 18:22:21	Service.DAV	WARN	_makeRequest: got status 500
2008-05-09 18:22:21	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock

never be able to use it.
Yeah i'm also getting these kind of errors:
2008-05-16 15:37:52	Chrome.Window	INFO	Login successful
2008-05-16 15:44:02	Chrome.Window	INFO	Sync window closed
2008-05-16 15:44:59	Service.Main	INFO	Running scheduled sync
2008-05-16 15:45:01	Service.DAV	WARN	_makeRequest: got status 500
2008-05-16 15:45:01	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock
2008-05-16 16:14:59	Service.Main	INFO	Running scheduled sync
2008-05-16 16:15:01	Service.DAV	WARN	_makeRequest: got status 500
2008-05-16 16:15:01	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: Could not acquire lock

I am having the same issue.
I've also the Async.Generator Error.
Here some of the logfile:

2008-05-20 12:35:49	Service.Main	INFO	Running scheduled sync
2008-05-20 12:35:52	Service.BmkEngine	INFO	Beginning sync
2008-05-20 12:35:53	Service.BmkEngine	INFO	Got status file from server
2008-05-20 12:35:54	Service.BmkEngine	INFO	Downloading server deltas
2008-05-20 12:35:56	Service.BmkEngine	INFO	Local snapshot version: 18
2008-05-20 12:35:56	Service.BmkEngine	INFO	Server status: 0
2008-05-20 12:35:56	Service.BmkEngine	INFO	Server maxVersion: 18
2008-05-20 12:35:56	Service.BmkEngine	INFO	Server snapVersion: 0
2008-05-20 12:35:57	Service.BStore	WARN	Warning: unknown item type, cannot serialize: 9
2008-05-20 12:35:57	Service.BStore	WARN	Warning: unknown item type, cannot serialize: 9
2008-05-20 12:35:59	Service.BmkEngine	INFO	Sync complete: no changes needed on client or server
2008-05-20 12:35:59	Service.HistEngine	INFO	Beginning sync
2008-05-20 12:36:01	Service.HistEngine	INFO	Got status file from server
2008-05-20 12:36:01	Service.HistEngine	INFO	Downloading server snapshot
2008-05-20 12:36:02	Service.HistEngine	INFO	Downloading server deltas
2008-05-20 12:36:03	Async.Generator	ERROR	Exception caught in WeaveLockWrapper: openssl did not run successfully, error code 1

Comment #76 is a completely unrelated error.  It's "openssl did not run successfully", and it'll be made invalid after bug 433949 is fixed.

FWIW, the workaround in comment #69 hasn't been released yet.  It should make this issue go away I believe.
I've pushed an update to Weave which will only lock a single file, rather than the entire collection.  This should work around the problem (I hope).

Jeremy, I think we'll want to wipe the lock db once more, to fix any broken accounts that might have come up since the last wipe.
Is this still an issue with the single file locking method?
Did you clear the DB after comment #78?  If so, it should be better now, and you can WONTFIX this bug.
Yep, cleared.
Status: REOPENED → RESOLVED
Closed: 16 years ago → 16 years ago
Resolution: --- → WONTFIX
Product: mozilla.org → mozilla.org Graveyard
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: