Bug 349795

Comment 1 Tomasz Zarna 2011-06-20 06:11:32 EDT

Quick check: passes locally on Windows and Linux.

Comment 2 Szymon Brandys 2011-06-21 04:10:06 EDT

Orion Build : I20110621-0200

This time a similar problem happened in GitStatusTest.testConfilct (btw there is a typo in the test name)

Unexpected task format: {"Severity":"Error","Message":"Task not found: EFx4Y9CbABAQZoNypGrDoA","HttpCode":404,"Code":0}

junit.framework.AssertionFailedError: Unexpected task format: {"Severity":"Error","Message":"Task not found: EFx4Y9CbABAQZoNypGrDoA","HttpCode":404,"Code":0}
at org.eclipse.orion.server.tests.servlets.git.GitTest.waitForTaskCompletion(GitTest.java:232)
at org.eclipse.orion.server.tests.servlets.git.GitTest.push(GitTest.java:477)
at org.eclipse.orion.server.tests.servlets.git.GitTest.push(GitTest.java:456)
at org.eclipse.orion.server.tests.servlets.git.GitStatusTest.testConfilct(GitStatusTest.java:952)
at org.eclipse.test.EclipseTestRunner.run(EclipseTestRunner.java:416)
at org.eclipse.test.EclipseTestRunner.run(EclipseTestRunner.java:249)
at org.eclipse.test.CoreTestApplication.runTests(CoreTestApplication.java:36)
at org.eclipse.test.CoreTestApplication.run(CoreTestApplication.java:32)
at org.eclipse.equinox.internal.app.EclipseAppContainer.callMethodWithException(EclipseAppContainer.java:587)
at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:198)
at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110)
at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79)
at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:344)
at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:179)
at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:622)
at org.eclipse.equinox.launcher.Main.basicRun(Main.java:577)
at org.eclipse.equinox.launcher.Main.run(Main.java:1410)
at org.eclipse.equinox.launcher.Main.main(Main.java:1386)
at org.eclipse.core.launcher.Main.main(Main.java:34)

Comment 3 Szymon Brandys 2011-06-22 03:49:58 EDT

Orion Build : I20110621-1638
GitUriTest.testGitUrisForRepositoryClonedIntoSubfolder

Unexpected task format: {"Severity":"Error","Message":"Task not found: oOl2kEqcABATbf8e2zQaZw","HttpCode":404,"Code":0}

junit.framework.AssertionFailedError: Unexpected task format: {"Severity":"Error","Message":"Task not found: oOl2kEqcABATbf8e2zQaZw","HttpCode":404,"Code":0}
at org.eclipse.orion.server.tests.servlets.git.GitTest.waitForTaskCompletion(GitTest.java:232)
at org.eclipse.orion.server.tests.servlets.git.GitTest.clone(GitTest.java:319)
at org.eclipse.orion.server.tests.servlets.git.GitTest.clone(GitTest.java:379)
at org.eclipse.orion.server.tests.servlets.git.GitUriTest.testGitUrisForRepositoryClonedIntoSubfolder(GitUriTest.java:168)
at org.eclipse.test.EclipseTestRunner.run(EclipseTestRunner.java:416)
at org.eclipse.test.EclipseTestRunner.run(EclipseTestRunner.java:249)
at org.eclipse.test.CoreTestApplication.runTests(CoreTestApplication.java:36)
at org.eclipse.test.CoreTestApplication.run(CoreTestApplication.java:32)
at org.eclipse.equinox.internal.app.EclipseAppContainer.callMethodWithException(EclipseAppContainer.java:587)
at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:198)
at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110)
at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79)
at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:344)
at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:179)
at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:622)
at org.eclipse.equinox.launcher.Main.basicRun(Main.java:577)
at org.eclipse.equinox.launcher.Main.run(Main.java:1410)
at org.eclipse.equinox.launcher.Main.main(Main.java:1386)
at org.eclipse.core.launcher.Main.main(Main.java:34)

Comment 4 Tomasz Zarna 2011-06-24 04:45:07 EDT

I20110624020
testCheckoutAborted

Unexpected task format: {"Severity":"Error","Message":"Task not found: sC4nWSqeABAf-bF05yIr0g","HttpCode":404,"Code":0} 

junit.framework.AssertionFailedError: Unexpected task format: {"Severity":"Error","Message":"Task not found: sC4nWSqeABAf-bF05yIr0g","HttpCode":404,"Code":0}
at org.eclipse.orion.server.tests.servlets.git.GitTest.waitForTaskCompletion(GitTest.java:232)
at org.eclipse.orion.server.tests.servlets.git.GitTest.clone(GitTest.java:319)
at org.eclipse.orion.server.tests.servlets.git.GitTest.clone(GitTest.java:379)
at org.eclipse.orion.server.tests.servlets.git.GitCheckoutTest.testCheckoutAborted(GitCheckoutTest.java:504)
at org.eclipse.test.EclipseTestRunner.run(EclipseTestRunner.java:416)
at org.eclipse.test.EclipseTestRunner.run(EclipseTestRunner.java:249)
at org.eclipse.test.CoreTestApplication.runTests(CoreTestApplication.java:36)
at org.eclipse.test.CoreTestApplication.run(CoreTestApplication.java:32)
at org.eclipse.equinox.internal.app.EclipseAppContainer.callMethodWithException(EclipseAppContainer.java:587)
at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:198)
at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110)
at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79)
at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:344)
at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:179)
at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:622)
at org.eclipse.equinox.launcher.Main.basicRun(Main.java:577)
at org.eclipse.equinox.launcher.Main.run(Main.java:1410)
at org.eclipse.equinox.launcher.Main.main(Main.java:1386)
at org.eclipse.core.launcher.Main.main(Main.java:34)

Comment 5 Tomasz Zarna 2011-06-24 05:35:26 EDT

One possible reason for those to happen is an IO exception while creating a task[1]. Is there a way to view logs generated when running tests? I took a quick look at buildLog-*.txt, but couldn't find anything.

[1] 
	TaskStore.writeTask(String, String) line: 51	
	TaskService.createTask() line: 30	
	CloneJob.createTask() line: 56	
	CloneJob.<init>(WebClone, CredentialsProvider, String, String, WebProject) line: 51	
	GitCloneHandlerV1.handlePost(HttpServletRequest, HttpServletResponse) line: 211	
	GitCloneHandlerV1.handleRequest(HttpServletRequest, HttpServletResponse, String) line: 67	
	GitCloneHandlerV1.handleRequest(HttpServletRequest, HttpServletResponse, Object) line: 1
	...

Comment 6 John Arthorne 2011-06-24 09:08:38 EDT

Created attachment 198526 [details]
Log file

This is the entire log file from running last night's server tests. There is no error writing tasks, but this one looks potentially suspicious:

java.io.IOException: Destination folder already exists and contains a repository
        at org.eclipse.orion.server.git.servlets.CloneJob.doClone(CloneJob.java:71)

Comment 7 Tomasz Zarna 2011-06-24 09:56:22 EDT

(In reply to comment #6)
> java.io.IOException: Destination folder already exists and contains a repository
> at
> org.eclipse.orion.server.git.servlets.CloneJob.doClone(CloneJob.java:71)

Thanks, but that's not it. It's a side effect of running GitCloneTest#testCloneAlreadyExists. Filed bug 350260 for it. The other one is bug 345898.

Comment 8 Tomasz Zarna 2011-06-27 05:29:26 EDT

I've just bumped into that when trying to clone a repo from github[1]. First I saw the exception in the Firebug console, when retried all went fine but the Repositories page showed two identical repos. It's a real issue.

[1] git://github.com/mamacdon/mamacdon.github.com.git

Comment 9 John Arthorne 2011-06-30 13:57:27 EDT

I had this test failure today on Windows 7, so it is not specific to Linux. Unfortunately I deleted the workspace by immediately re-running the test before I thought about it carefully. If anyone gets this failure when running the tests locally, they should look in the folder .metadata/.plugins/org.eclipse.orion.server.core/tasks to see if there is a file matching the task id. Or, a file with different case but otherwise the same name. If there is, please attach here or paste the contents. One possibility is a parse error when converting the task from String->JSON. I have added additional error logging in this case so there should hopefully be more details in the error log if this occurs.

Comment 10 John Arthorne 2011-07-05 15:15:22 EDT

From today's test failure I got more details from my additional logging:

org.json.JSONException: A JSONObject text must begin with '{' at character 0
        at org.json.JSONTokener.syntaxError(JSONTokener.java:412)
        at org.json.JSONObject.<init>(JSONObject.java:179)
        at org.json.JSONObject.<init>(JSONObject.java:419)
        at org.eclipse.orion.server.core.tasks.TaskInfo.fromJSON(TaskInfo.java:43)
        at org.eclipse.orion.internal.server.core.tasks.TaskService.getTask(TaskService.java:38)
        at org.eclipse.orion.internal.server.servlets.task.TaskServlet.doGet(TaskServlet.java:60)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)

However looking at the task file in disk it looks correct:

{"Result":{"Severity":"Ok","Message":"Clone complete.","HttpCode":200,"Code":0},"PercentComplete":100,"Message":"Clone complete.","Running":false,"Location":"http://localhost:8080/gitapi/clone/file/Bl/folder","Id":"UBLZdCCnABAQXe--D7CqaQ"}

Comment 11 John Arthorne 2011-07-05 15:17:25 EDT

My theory is that this is caused by concurrent reads and writes of the same file by the task store.

Comment 12 John Arthorne 2011-07-05 15:56:02 EDT

Fix released.

http://git.eclipse.org/c/e4/org.eclipse.orion.server.git/commit/?id=c16460ee5316ca6786f05069e033da9f811bff6f