2014년 12월 10일 수요일

response too long errors from java driver

We are getting several of these in production, Does this literally mean that the query is trying to return back 1.3GB of data?


response too long: 1397246281 - java.lang.IllegalArgumentException: response too long: 1397246281
 at com.mongodb.Response.<init>(Response.java:49) ~[mongo-java-driver-2.12.3.jar:na]
 at com.mongodb.DBPort$1.execute(DBPort.java:141) ~[mongo-java-driver-2.12.3.jar:na]
 at com.mongodb.DBPort$1.execute(DBPort.java:135) ~[mongo-java-driver-2.12.3.jar:na]
 at com.mongodb.DBPort.doOperation(DBPort.java:164) ~[mongo-java-driver-2.12.3.jar:na]


I did go through this post  we arent using any library around mongo java driver which might be causing thread safety issues. 



Can you include the full stack trace, please?  Also check the server logs to see if there is anything being logged there, and if so post the logs somewhere where we can see them.



2014-12-04 10:32:56.765 ERROR [GlobalExceptionMapper    ] null - java.lang.IllegalArgumentException: response too long: 889192448
 at com.mongodb.Response.<init>(Response.java:49) ~[mongo-java-driver-2.12.3.jar:na]
 at com.mongodb.DBPort$1.execute(DBPort.java:141) ~[mongo-java-driver-2.12.3.jar:na]
 at com.mongodb.DBPort$1.execute(DBPort.java:135) ~[mongo-java-driver-2.12.3.jar:na]
 at com.mongodb.DBPort.doOperation(DBPort.java:164) ~[mongo-java-driver-2.12.3.jar:na]
Wrapped by: java.lang.reflect.InvocationTargetException: null
 at sun.reflect.GeneratedMethodAccessor845.invoke(Unknown Source) ~[na:na]
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_72]
 at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_72]
 at com.edmunds.vehicle.repository.aspect.RepositoryAspect.interceptRepositoryCall(RepositoryAspect.java:105) ~[vehicle-repository-1.25.17.jar:na]
Wrapped by: java.lang.reflect.UndeclaredThrowableException: null
 at com.edmunds.vehicle.repository.coherence.StyleRepositoryImpl$$EnhancerByCGLIB$$f7645cc.findLiteStyles(<generated>) ~[spring-core-3.2.5.RELEASE.jar:na]
 at com.edmunds.vehicledirectory.service.VehicleDirectoryService.findShortStylesByModelYearAndCategoryFilter(VehicleDirectoryService.java:306) ~[vehicle-directory-service-5.8.13.jar:na]
 at com.edmunds.vehicledirectory.service.VehicleDirectoryService.findTrimsByModelYearAndCategoryWithShortStyles(VehicleDirectoryService.java:300) ~[vehicle-directory-service-5.8.13.jar:na]
 at com.edmunds.vehicledirectory.service.VehicleDirectoryService.getIndividualSubModelTrimList(VehicleDirectoryService.java:409) ~[vehicle-directory-service-5.8.13.jar:na]
2014-12-04 10:32:56.765 ERROR [GlobalExceptionMapper    ] null - java.lang.IllegalArgumentException: response too long: 889192448
 at com.mongodb.Response.<init>(Response.java:49) ~[mongo-java-driver-2.12.3.jar:na]
 at com.mongodb.DBPort$1.execute(DBPort.java:141) ~[mongo-java-driver-2.12.3.jar:na]
 at com.mongodb.DBPort$1.execute(DBPort.java:135) ~[mongo-java-driver-2.12.3.jar:na]
 at com.mongodb.DBPort.doOperation(DBPort.java:164) ~[mongo-java-driver-2.12.3.jar:na]
Wrapped by: java.lang.reflect.InvocationTargetException: null
 at sun.reflect.GeneratedMethodAccessor845.invoke(Unknown Source) ~[na:na]
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_72]
 at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_72]
 at com.edmunds.vehicle.repository.aspect.RepositoryAspect.interceptRepositoryCall(RepositoryAspect.java:105) ~[vehicle-repository-1.25.17.jar:na]
Wrapped by: java.lang.reflect.UndeclaredThrowableException: null
 at com.edmunds.vehicle.repository.coherence.StyleRepositoryImpl$$EnhancerByCGLIB$$f7645cc.findLiteStyles(<generated>) ~[spring-core-3.2.5.RELEASE.jar:na]
 at com.edmunds.vehicledirectory.service.VehicleDirectoryService.findShortStylesByModelYearAndCategoryFilter(VehicleDirectoryService.java:306) ~[vehicle-directory-service-5.8.13.jar:na]
 at com.edmunds.vehicledirectory.service.VehicleDirectoryService.findTrimsByModelYearAndCategoryWithShortStyles(VehicleDirectoryService.java:300) ~[vehicle-directory-service-5.8.13.jar:na]
 at com.edmunds.vehicledirectory.service.VehicleDirectoryService.getIndividualSubModelTrimList(VehicleDirectoryService.java:409) ~[vehicle-directory-service-5.8.13.jar:na]
2014-12-04 10:32:56.765 ERROR [GlobalExceptionMapper    ] null - java.lang.IllegalArgumentException: response too long: 889192448
 at com.mongodb.Response.<init>(Response.java:49) ~[mongo-java-driver-2.12.3.jar:na]
 at com.mongodb.DBPort$1.execute(DBPort.java:141) ~[mongo-java-driver-2.12.3.jar:na]
 at com.mongodb.DBPort$1.execute(DBPort.java:135) ~[mongo-java-driver-2.12.3.jar:na]
 at com.mongodb.DBPort.doOperation(DBPort.java:164) ~[mongo-java-driver-2.12.3.jar:na]
Wrapped by: java.lang.reflect.InvocationTargetException: null
 at sun.reflect.GeneratedMethodAccessor845.invoke(Unknown Source) ~[na:na]
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_72]
 at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_72]
 at com.edmunds.vehicle.repository.aspect.RepositoryAspect.interceptRepositoryCall(RepositoryAspect.java:105) ~[vehicle-repository-1.25.17.jar:na]
Wrapped by: java.lang.reflect.UndeclaredThrowableException: null
 at com.edmunds.vehicle.repository.coherence.StyleRepositoryImpl$$EnhancerByCGLIB$$f7645cc.findLiteStyles(<generated>) ~[spring-core-3.2.5.RELEASE.jar:na]
 at com.edmunds.vehicledirectory.service.VehicleDirectoryService.findShortStylesByModelYearAndCategoryFilter(VehicleDirectoryService.java:306) ~[vehicle-directory-service-5.8.13.jar:na]
 at com.edmunds.vehicledirectory.service.VehicleDirectoryService.findTrimsByModelYearAndCategoryWithShortStyles(VehicleDirectoryService.java:300) ~[vehicle-directory-service-5.8.13.jar:na]
 at com.edmunds.vehicledirectory.service.VehicleDirectoryService.getIndividualSubModelTrimList(VehicleDirectoryService.java:409) ~[vehicle-directory-service-5.8.13.jar:na]




>  we arent using any library around mongo java driver which might be causing thread safety issues. Just to double-check something - your own code that uses the mongo java driver directly is not accessing the same DBCursor instances from multiple threads, right?



I am double checking this to make sure.

AFAIK we dont do this



Looks like we might have been using it with multiple threads

We were using hystrix annotations (netflix) on some of our methods dealing with DbCursor, hystrix might internally spin up threads , so we are getting rid of this to see if this works

will update this thread with my findings


Removing hystrix did not solve the issue

AN OOM error led to a premature release of DBPort objects containing BufferedInputStream objects that hadn’t been read fully, which lead to the "repsonse too long" error we fixed the OOM error and that fixed the response too long error 


analysis is in this document

https://docs.google.com/document/d/1uP7WzPw6dW7AGUbd1BJyyTv_4dX_PshrijKt-Fn8TCc/edit?usp=sharing

seems like a mongo bug when on exceptional cases?

CM-1063: Response too long exception investigation



Thanks for the detailed analysis.  This looks like a real bug.  Would you be willing to report an issue in Jira: https://jira.mongodb.org/browse/JAVA

댓글 없음:

댓글 쓰기