Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Remove closeQuietly as close flushes the buffer and throws errors #20

Closed
wants to merge 1 commit into from
Closed

Conversation

muuki88
Copy link

@muuki88 muuki88 commented Apr 29, 2016

The exception

fm.last.moji.tracker.TrackerException: size_verify_error 
  Expected: 2744; actual: 0 (missing); 
  path: http://127.00.01:7500/dev102/0/000/000/0000000142.fid;
  error: Job queryworker has only 0, wants 150, making 150

gets swallowed by the IOUtils, which hides upload failures.

@muuki88
Copy link
Author

muuki88 commented Apr 29, 2016

I'll try to provide tests if this pr has a chance to get merged.

@@ -72,7 +72,7 @@ public void copyToMogile(File source, MojiFile destination) throws IOException {
outputStream.flush();
} finally {
IOUtils.closeQuietly(inputStream);
IOUtils.closeQuietly(outputStream);
outputStream.close();;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I find this surprising behaviour as line 72 clearly flushes the buffer. Are you certain this is where the problem lies? How did you find it?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We have an old version of ngnix, which doesn't support chunked requests and response with a 411 Content length required, when I call moji.copyToMogile(file, destination).

The problem was that neither the exception was thrown nor a useful error log was printed. The issue is related to #21 , which prints

411 Content length required

where as the current behavior ( including this fix ) is throwing an exception that contains

ERR size_verify_error

Copy link
Member

@massdosage massdosage Apr 29, 2016

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can you please paste in the full stack trace thrown with the above code in place? If I understand correctly (it's been a while since I looked at this code) you're saying that the exception you mention in the other PR is being swallowed here. So if we rethrow it instead of swallowing then you should have enough information wherever it ends up and then there won't be a need to log the output which is in the other PR?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I will post the full stacktrace on monday, when I'm at work again.

you're saying that the exception you mention in the other PR is being swallowed here
So if we rethrow it instead of swallowing then you should have enough information

Actually I thought so as well. However at somepoint the message changes from Content length required to size_verifiy_error, which is still puzzling me.

@muuki88
Copy link
Author

muuki88 commented May 2, 2016

This is the stacktrace, when adding this PR:

fm.last.moji.tracker.TrackerException: size_verify_error Expected:+720%3B+actual:+0+%28missing%29%3B+path:+http://127.0.0.1:7500/dev102/0/000/000/0000000193.fid%3B+error:+Job+queryworker+has+only+0,+wants+150,+making+150.
    at fm.last.moji.tracker.impl.TrackerImpl.handleGeneralResponseError(TrackerImpl.java:195)
    at fm.last.moji.tracker.impl.TrackerImpl.createClose(TrackerImpl.java:95)
    at fm.last.moji.tracker.pool.BorrowedTracker.createClose(BorrowedTracker.java:88)
    at fm.last.moji.impl.FileUploadOutputStream.close(FileUploadOutputStream.java:109)
    at fm.last.moji.impl.MojiImpl.copyToMogile(MojiImpl.java:75)
    at fm.last.moji.spring.SpringMojiBean.copyToMogile(SpringMojiBean.java:109)
    at fm.last.moji.integration.ExpermondoIT.copyToMogile(ExpermondoIT.java:47)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
    at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
    at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
    at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:43)
    at org.junit.runners.BlockJUnit4ClassRunner.runNotIgnored(BlockJUnit4ClassRunner.java:79)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:71)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:49)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
    at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)
    at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:459)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:675)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:382)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:192)

@hrchu
Copy link
Member

hrchu commented May 2, 2016

The root cause is, when file upload to store node is failed, we should not send create_close to tracker node. (Which cause size_verify_error, seems the file is not in the store node)

I have some fix about this issue, but still verify it in my production environment.

@hrchu
Copy link
Member

hrchu commented May 2, 2016

@muuki88 the close() method in outputStream is override. size_verify_error is occurred there.

@muuki88
Copy link
Author

muuki88 commented May 2, 2016

Cool @hrchu Then we can close this PR and take your fix instead, which bubbles the actual root cause.

@muuki88 muuki88 closed this Aug 10, 2016
@muuki88 muuki88 deleted the fix/copyToMogile branch August 10, 2016 19:07
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants