JSON publisher gives 500 and hangs, retrying forever despite success and a 202 response from destination application

[taylordowns2000]

Hey team, has anyone noticed a change in the JSON publisher recently? I was
receiving submissions as JSON (Z-Alpha JSON Server) up until December 14th,
responding with a 202. Recently, the publisher pauses and retries the same
submission over and over, despite the submissions being received in our
destination system and us responding with a 202. I've pasted the logs
below. Apologies for bad formatting.

This is a 500 that appears in Aggregate after the publisher is started:
E 2015-12-19 08:03:19.436 500 358 B 2.91 s I 08:03:19.446 I 08:03:
19.455 I 08:03:19.459 I 08:03:19.459 I 08:03:19.479 I 08:03:19.497 I 08:03:
19.522 I 08:03:19.530 I 08:03:19.542 I 08:03:19.542 I 08:03:19.688 I 08:03:
19.689 I 08:03:20.414 I 08:03:20.414 I 08:03:21.113 I 08:03:21.685 E 08:03:
22.211 I 08:03:22.212 I 08:03:22.223 E 08:03:22.338 /gae/
uploadSubmissionsTask?fscUri=uuid%3Aadeaa683-4370-4e65-92e0-a112105f7d2b
0.1.0.2 - - [19/Dec/2015:05:03:19 -0800] "GET
/gae/uploadSubmissionsTask?fscUri=uuid%3Aadeaa683-4370-4e65-92e0-a112105f7d2b
HTTP/1.1" 500 358 https://abalobisa.appspot.com/aggregateui/servicesadminservice
"AppEngine-Google; (+http://code.google.com/appengine)"
"abalobisa.appspot.com" ms=2905 cpu_ms=1432 cpm_usd=0.000291801
instance=00c61b117c6941a0ec999cc353fb389b9bd566f4 app_engine_release=1.9.30
trace_id=-
I 08:03:19.446 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: Beginning servlet processing
I 08:03:19.455 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: Request is running on frontend
I 08:03:19.459 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: Beginning UPLOAD service:
uuid:1b715159-8524-45f5-91db-6267da8aa380 form DEMO_CCM_landing_site_v1_5
I 08:03:19.459 org.opendatakit.aggregate.form.FormFactory
internalGetForms: FormCache: fetching new list of Forms
I 08:03:19.479 org.opendatakit.aggregate.util.BackendActionsTable
logValues: incoming- last Fetch: -4422 [S: -2379 Eq: -4422 Fs: -4422] futureMillis:
895578
I 08:03:19.497 org.opendatakit.aggregate.util.BackendActionsTable
logValues: -fetched- last Fetch: 0 [S: -2379 Eq: -4422 Fs: -4422] futureMillis:
-1
I 08:03:19.522 org.opendatakit.aggregate.util.BackendActionsTable
logValues: Fs-update last Fetch: 0 [S: -2379 Eq: -4422 Fs: 895578] futureMillis:
895578 requested: 895578
I 08:03:19.530 org.opendatakit.aggregate.form.FormFactory
internalGetForms: FormCache: using cached list of Forms
I 08:03:19.542 [s~abalobisa/1.385572474003285366].: Trying to
get lock : 4fedc3b6-46c2-4fe2-a3e3-a4bde852aa7e uuid:adeaa683-4370-4e65-92e0
-a112105f7d2b UPLOAD_SUBMISSION
I 08:03:19.542 [s~abalobisa/1.385572474003285366].: Persisting
lock : 4fedc3b6-46c2-4fe2-a3e3-a4bde852aa7e uuid:adeaa683-4370-4e65-92e0-a112105f7d2b
UPLOAD_SUBMISSION
I 08:03:19.688 [s~abalobisa/1.385572474003285366].: Time left
on lock: 59854
I 08:03:19.689 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: Upload invoked when
operational status is ACTIVE
I 08:03:20.414 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadSubmissions: There are 10 submissions
available for upload
I 08:03:20.414 [s~abalobisa/1.385572474003285366].: Sending one
JSON Submission
I 08:03:21.113 [s~abalobisa/1.385572474003285366].: https:
//openfn-core.herokuapp.com/inbox/3afab0f1-3937-4ca8-95a3-5491f6f32a4e/?
I 08:03:21.685 org.opendatakit.http.conn.GaeManagedClientConnection
flush: URLFetch timeout (socket + connection) (ms): 120000
E 08:03:22.211 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: org.opendatakit.aggregate.
exception.ODKExternalServiceException: (202)
at org.opendatakit.aggregate.externalservice.JsonServer.sendRequest(
JsonServer.java:143)
at org.opendatakit.aggregate.externalservice.JsonServer.insertData(
JsonServer.java:197)
at org.opendatakit.aggregate.externalservice.AbstractExternalService
.sendSubmission(AbstractExternalService.java:141)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
sendSubmissions(UploadSubmissionsWorkerImpl.java:318)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
uploadSubmissions(UploadSubmissionsWorkerImpl.java:278)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
uploadAllSubmissions(UploadSubmissionsWorkerImpl.java:184)
at org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet.doGet(UploadSubmissionsTaskServlet.java:108)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java
:511)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1166)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330)
at org.springframework.security.web.access.intercept.
FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118)
at org.springframework.security.web.access.intercept.
FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.access.
ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.session.SessionManagementFilter.
doFilter(SessionManagementFilter.java:103)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.opendatakit.common.security.spring.
SecurityContextHolderAwareAuthPreservingRequestFilter.doFilter(
SecurityContextHolderAwareAuthPreservingRequestFilter.java:66)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.authentication.
AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:
113)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.savedrequest.
RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.authentication.www.
DigestAuthenticationFilter.doFilter(DigestAuthenticationFilter.java:115)
at org.opendatakit.common.security.spring.DigestAuthenticationFilter
.doFilter(DigestAuthenticationFilter.java:40)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.opendatakit.common.security.spring.OutOfBandUserFilter.
doFilter(OutOfBandUserFilter.java:105)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.opendatakit.common.security.spring.Oauth2ResourceFilter.
doFilter(Oauth2ResourceFilter.java:354)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.authentication.logout.
LogoutFilter.doFilter(LogoutFilter.java:110)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.context.
SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.
java:87)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.access.channel.
ChannelProcessingFilter.doFilter(ChannelProcessingFilter.java:144)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.FilterChainProxy.
doFilterInternal(FilterChainProxy.java:192)
at org.springframework.security.web.FilterChainProxy.doFilter(
FilterChainProxy.java:160)
at org.springframework.web.filter.DelegatingFilterProxy.
invokeDelegate(DelegatingFilterProxy.java:344)
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(
DelegatingFilterProxy.java:261)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.utils.servlet.ParseBlobUploadFilter.
doFilter(ParseBlobUploadFilter.java:125)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(
SaveSessionFilter.java:37)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.utils.servlet.
JdbcMySqlConnectionCleanupFilter.doFilter(JdbcMySqlConnectionCleanupFilter.
java:60)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.utils.servlet.TransactionCleanupFilter.
doFilter(TransactionCleanupFilter.java:43)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.
java:388)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler
.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.
java:182)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.
java:765)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:
418)
at com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(
AppVersionHandlerMap.java:260)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.
java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.
java:542)
at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(
HttpConnection.java:923)
at com.google.apphosting.runtime.jetty.RpcRequestParser.
parseAvailable(RpcRequestParser.java:78)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.
serviceRequest(JettyServletEngineAdapter.java:148)
at com.google.apphosting.runtime.JavaRuntime$RequestRunnable.run(
JavaRuntime.java:469)
at com.google.tracing.TraceContext$TraceContextRunnable.runInContext
(TraceContext.java:437)
at com.google.tracing.TraceContext$TraceContextRunnable$1.run(
TraceContext.java:444)
at com.google.tracing.CurrentContext.runInContext(CurrentContext.
java:256)
at com.google.tracing.TraceContext$AbstractTraceContextCallback.
runInInheritedContextNoUnref(TraceContext.java:308)
at com.google.tracing.TraceContext$AbstractTraceContextCallback.
runInInheritedContext(TraceContext.java:300)
at com.google.tracing.TraceContext$TraceContextRunnable.run(
TraceContext.java:441)
at com.google.apphosting.runtime.ThreadGroupPool$PoolEntry.run(
ThreadGroupPool.java:235)
at java.lang.Thread.run(Thread.java:745)
I 08:03:22.212 [s~abalobisa/1.385572474003285366].: Releasing
lock : 4fedc3b6-46c2-4fe2-a3e3-a4bde852aa7e uuid:adeaa683-4370-4e65-92e0-a112105f7d2b
UPLOAD_SUBMISSION
I 08:03:22.223 [s~abalobisa/1.385572474003285366].: Time left
on lock: 57319
E 08:03:22.338 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: org.opendatakit.aggregate.exception.
ODKExternalServiceException: (202)

*This might be the 202 we send back: *
W 2015-12-19 08:03:22.985 202 0 B 240 ms I 08:03:22.991 I 08:03:
22.998 I 08:03:22.998 I 08:03:22.998 I 08:03:23.017 I 08:03:23.036 I 08:03:
23.042 I 08:03:23.048 I 08:03:23.048 I 08:03:23.186 I 08:03:23.186 W 08:03:
23.186 I 08:03:23.196 I 08:03:23.224 /gae/uploadSubmissionsTask?fscUri=uuid%
3Aadeaa683-4370-4e65-92e0-a112105f7d2b
0.1.0.2 - - [19/Dec/2015:05:03:22 -0800] "GET
/gae/uploadSubmissionsTask?fscUri=uuid%3Aadeaa683-4370-4e65-92e0-a112105f7d2b
HTTP/1.1" 202 - https://abalobisa.appspot.com/aggregateui/servicesadminservice
"AppEngine-Google; (+http://code.google.com/appengine)"
"abalobisa.appspot.com" ms=240 cpu_ms=71 cpm_usd=0
instance=00c61b117c6941a0ec999cc353fb389b9bd566f4 app_engine_release=1.9.30
trace_id=-
I 08:03:22.991 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: Beginning servlet processing
I 08:03:22.998 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: Request is running on frontend
I 08:03:22.998 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: Beginning UPLOAD service:
uuid:1b715159-8524-45f5-91db-6267da8aa380 form DEMO_CCM_landing_site_v1_5
I 08:03:22.998 org.opendatakit.aggregate.form.FormFactory
internalGetForms: FormCache: fetching new list of Forms
I 08:03:23.017 org.opendatakit.aggregate.util.BackendActionsTable
logValues: incoming- last Fetch: -3537 [S: -5916 Eq: -7959 Fs: 892041] futureMillis:
892041
I 08:03:23.036 org.opendatakit.aggregate.util.BackendActionsTable
logValues: -fetched- last Fetch: 0 [S: -5916 Eq: -7959 Fs: 22041] futureMillis:
-1
I 08:03:23.042 org.opendatakit.aggregate.form.FormFactory
internalGetForms: FormCache: using cached list of Forms
I 08:03:23.048 [s~abalobisa/1.385572474003285366].: Trying to
get lock : 113f716b-d98f-4b92-ba9f-2629a8012354 uuid:adeaa683-4370-4e65-92e0
-a112105f7d2b UPLOAD_SUBMISSION
I 08:03:23.048 [s~abalobisa/1.385572474003285366].: Persisting
lock : 113f716b-d98f-4b92-ba9f-2629a8012354 uuid:adeaa683-4370-4e65-92e0-a112105f7d2b
UPLOAD_SUBMISSION
I 08:03:23.186 [s~abalobisa/1.385572474003285366].: Time left
on lock: 59862
I 08:03:23.186 [s~abalobisa/1.385572474003285366].: Releasing
lock : 113f716b-d98f-4b92-ba9f-2629a8012354 uuid:adeaa683-4370-4e65-92e0-a112105f7d2b
UPLOAD_SUBMISSION
W 08:03:23.186 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: Upload IGNORED when
operational status is ACTIVE_PAUSE
I 08:03:23.196 [s~abalobisa/1.385572474003285366].: Time left
on lock: 59852
I 08:03:23.224 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: ending successful servlet processing

[Mitch_S]

What version of ODK Aggregate are you running?

It may be that you have a corrupted submission and ODK Aggregate is stalled
trying to read it.
This would be farther down in the log.

Assuming you are running a newer ODK Aggregate, the error logs and
resolution steps are covered here:

Aggregate AppEngine Troubleshooting

The error messages are different prior to 1.4.5, and in some cases, you may
need the latest 1.4.7 to get enough information in the log messages.

···

On Sat, Dec 19, 2015 at 5:16 AM, Taylor Downs wrote:

Hey team, has anyone noticed a change in the JSON publisher recently? I
was receiving submissions as JSON (Z-Alpha JSON Server) up until December
14th, responding with a 202. Recently, the publisher pauses and retries the
same submission over and over, despite the submissions being received in
our destination system and us responding with a 202. I've pasted the logs
below. Apologies for bad formatting.

This is a 500 that appears in Aggregate after the publisher is started:
E 2015-12-19 08:03:19.436 500 358 B 2.91 s I 08:03:19.446 I 08:03:
19.455 I 08:03:19.459 I 08:03:19.459 I 08:03:19.479 I 08:03:19.497 I 08:03
:19.522 I 08:03:19.530 I 08:03:19.542 I 08:03:19.542 I 08:03:19.688 I 08:
03:19.689 I 08:03:20.414 I 08:03:20.414 I 08:03:21.113 I 08:03:21.685 E 08
:03:22.211 I 08:03:22.212 I 08:03:22.223 E 08:03:22.338 /gae/
uploadSubmissionsTask?fscUri=uuid%3Aadeaa683-4370-4e65-92e0-a112105f7d2b
0.1.0.2 - - [19/Dec/2015:05:03:19 -0800] "GET
/gae/uploadSubmissionsTask?fscUri=uuid%3Aadeaa683-4370-4e65-92e0-a112105f7d2b
HTTP/1.1" 500 358 https://
abalobisa.appspot.com/aggregateui/servicesadminservice "AppEngine-Google;
(+http://code.google.com/appengine)" "abalobisa.appspot.com" ms=2905
cpu_ms=1432 cpm_usd=0.000291801
instance=00c61b117c6941a0ec999cc353fb389b9bd566f4 app_engine_release=1.9.30
trace_id=-
I 08:03:19.446 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: Beginning servlet processing
I 08:03:19.455 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: Request is running on frontend
I 08:03:19.459 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: Beginning UPLOAD service
: uuid:1b715159-8524-45f5-91db-6267da8aa380 form
DEMO_CCM_landing_site_v1_5
I 08:03:19.459 org.opendatakit.aggregate.form.FormFactory
internalGetForms: FormCache: fetching new list of Forms
I 08:03:19.479 org.opendatakit.aggregate.util.BackendActionsTable
logValues: incoming- last Fetch: -4422 [S: -2379 Eq: -4422 Fs: -4422] futureMillis:
895578
I 08:03:19.497 org.opendatakit.aggregate.util.BackendActionsTable
logValues: -fetched- last Fetch: 0 [S: -2379 Eq: -4422 Fs: -4422] futureMillis:
-1
I 08:03:19.522 org.opendatakit.aggregate.util.BackendActionsTable
logValues: Fs-update last Fetch: 0 [S: -2379 Eq: -4422 Fs: 895578] futureMillis:
895578 requested: 895578
I 08:03:19.530 org.opendatakit.aggregate.form.FormFactory
internalGetForms: FormCache: using cached list of Forms
I 08:03:19.542 [s~abalobisa/1.385572474003285366].: Trying to
get lock : 4fedc3b6-46c2-4fe2-a3e3-a4bde852aa7e uuid:adeaa683-4370-4e65-
92e0-a112105f7d2b UPLOAD_SUBMISSION
I 08:03:19.542 [s~abalobisa/1.385572474003285366].: Persisting
lock : 4fedc3b6-46c2-4fe2-a3e3-a4bde852aa7e uuid:adeaa683-4370-4e65-92e0-a112105f7d2b
UPLOAD_SUBMISSION
I 08:03:19.688 [s~abalobisa/1.385572474003285366].: Time left
on lock: 59854
I 08:03:19.689 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: Upload invoked when
operational status is ACTIVE
I 08:03:20.414 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadSubmissions: There are 10 submissions
available for upload
I 08:03:20.414 [s~abalobisa/1.385572474003285366].: Sending
one JSON Submission
I 08:03:21.113 [s~abalobisa/1.385572474003285366].: https://
openfn-core.herokuapp.com/inbox/3afab0f1-3937-4ca8-95a3-5491f6f32a4e/?
I 08:03:21.685 org.opendatakit.http.conn.GaeManagedClientConnection
flush: URLFetch timeout (socket + connection) (ms): 120000
E 08:03:22.211 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: org.opendatakit.
aggregate.exception.ODKExternalServiceException: (202)
at org.opendatakit.aggregate.externalservice.JsonServer.
sendRequest(JsonServer.java:143)
at org.opendatakit.aggregate.externalservice.JsonServer.insertData
(JsonServer.java:197)
at org.opendatakit.aggregate.externalservice.
AbstractExternalService.sendSubmission(AbstractExternalService.java:141)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
sendSubmissions(UploadSubmissionsWorkerImpl.java:318)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
uploadSubmissions(UploadSubmissionsWorkerImpl.java:278)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
uploadAllSubmissions(UploadSubmissionsWorkerImpl.java:184)
at org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet.doGet(UploadSubmissionsTaskServlet.java:108)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.
java:511)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1166)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330)
at org.springframework.security.web.access.intercept.
FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118)
at org.springframework.security.web.access.intercept.
FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.access.
ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.session.
SessionManagementFilter.doFilter(SessionManagementFilter.java:103)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.opendatakit.common.security.spring.
SecurityContextHolderAwareAuthPreservingRequestFilter.doFilter(
SecurityContextHolderAwareAuthPreservingRequestFilter.java:66)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.authentication.
AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:
113)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.savedrequest.
RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.authentication.www.
DigestAuthenticationFilter.doFilter(DigestAuthenticationFilter.java:115)
at org.opendatakit.common.security.spring.
DigestAuthenticationFilter.doFilter(DigestAuthenticationFilter.java:40)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.opendatakit.common.security.spring.OutOfBandUserFilter.
doFilter(OutOfBandUserFilter.java:105)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.opendatakit.common.security.spring.Oauth2ResourceFilter.
doFilter(Oauth2ResourceFilter.java:354)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.authentication.logout.
LogoutFilter.doFilter(LogoutFilter.java:110)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.context.
SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter
.java:87)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.access.channel.
ChannelProcessingFilter.doFilter(ChannelProcessingFilter.java:144)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.FilterChainProxy.
doFilterInternal(FilterChainProxy.java:192)
at org.springframework.security.web.FilterChainProxy.doFilter(
FilterChainProxy.java:160)
at org.springframework.web.filter.DelegatingFilterProxy.
invokeDelegate(DelegatingFilterProxy.java:344)
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(
DelegatingFilterProxy.java:261)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.utils.servlet.ParseBlobUploadFilter.
doFilter(ParseBlobUploadFilter.java:125)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(
SaveSessionFilter.java:37)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.utils.servlet.
JdbcMySqlConnectionCleanupFilter.doFilter(JdbcMySqlConnectionCleanupFilter
.java:60)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.utils.servlet.TransactionCleanupFilter.
doFilter(TransactionCleanupFilter.java:43)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.
java:388)
at org.mortbay.jetty.security.SecurityHandler.handle(
SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.
java:182)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.
java:765)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.
java:418)
at com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle
(AppVersionHandlerMap.java:260)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.
java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.
java:542)
at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(
HttpConnection.java:923)
at com.google.apphosting.runtime.jetty.RpcRequestParser.
parseAvailable(RpcRequestParser.java:78)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404
)
at com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.
serviceRequest(JettyServletEngineAdapter.java:148)
at com.google.apphosting.runtime.JavaRuntime$RequestRunnable.run(
JavaRuntime.java:469)
at com.google.tracing.TraceContext$TraceContextRunnable.
runInContext(TraceContext.java:437)
at com.google.tracing.TraceContext$TraceContextRunnable$1.run(
TraceContext.java:444)
at com.google.tracing.CurrentContext.runInContext(CurrentContext.
java:256)
at com.google.tracing.TraceContext$AbstractTraceContextCallback.
runInInheritedContextNoUnref(TraceContext.java:308)
at com.google.tracing.TraceContext$AbstractTraceContextCallback.
runInInheritedContext(TraceContext.java:300)
at com.google.tracing.TraceContext$TraceContextRunnable.run(
TraceContext.java:441)
at com.google.apphosting.runtime.ThreadGroupPool$PoolEntry.run(
ThreadGroupPool.java:235)
at java.lang.Thread.run(Thread.java:745)
I 08:03:22.212 [s~abalobisa/1.385572474003285366].: Releasing
lock : 4fedc3b6-46c2-4fe2-a3e3-a4bde852aa7e uuid:adeaa683-4370-4e65-92e0-a112105f7d2b
UPLOAD_SUBMISSION
I 08:03:22.223 [s~abalobisa/1.385572474003285366].: Time left
on lock: 57319
E 08:03:22.338 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: org.opendatakit.aggregate.exception.
ODKExternalServiceException: (202)

*This might be the 202 we send back: *
W 2015-12-19 08:03:22.985 202 0 B 240 ms I 08:03:22.991 I 08:03:
22.998 I 08:03:22.998 I 08:03:22.998 I 08:03:23.017 I 08:03:23.036 I 08:03
:23.042 I 08:03:23.048 I 08:03:23.048 I 08:03:23.186 I 08:03:23.186 W 08:
03:23.186 I 08:03:23.196 I 08:03:23.224 /gae/uploadSubmissionsTask?fscUri=
uuid%3Aadeaa683-4370-4e65-92e0-a112105f7d2b
0.1.0.2 - - [19/Dec/2015:05:03:22 -0800] "GET
/gae/uploadSubmissionsTask?fscUri=uuid%3Aadeaa683-4370-4e65-92e0-a112105f7d2b
HTTP/1.1" 202 - https://
abalobisa.appspot.com/aggregateui/servicesadminservice "AppEngine-Google;
(+http://code.google.com/appengine)" "abalobisa.appspot.com" ms=240
cpu_ms=71 cpm_usd=0 instance=00c61b117c6941a0ec999cc353fb389b9bd566f4
app_engine_release=1.9.30 trace_id=-
I 08:03:22.991 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: Beginning servlet processing
I 08:03:22.998 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: Request is running on frontend
I 08:03:22.998 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: Beginning UPLOAD service
: uuid:1b715159-8524-45f5-91db-6267da8aa380 form
DEMO_CCM_landing_site_v1_5
I 08:03:22.998 org.opendatakit.aggregate.form.FormFactory
internalGetForms: FormCache: fetching new list of Forms
I 08:03:23.017 org.opendatakit.aggregate.util.BackendActionsTable
logValues: incoming- last Fetch: -3537 [S: -5916 Eq: -7959 Fs: 892041] futureMillis:
892041
I 08:03:23.036 org.opendatakit.aggregate.util.BackendActionsTable
logValues: -fetched- last Fetch: 0 [S: -5916 Eq: -7959 Fs: 22041] futureMillis:
-1
I 08:03:23.042 org.opendatakit.aggregate.form.FormFactory
internalGetForms: FormCache: using cached list of Forms
I 08:03:23.048 [s~abalobisa/1.385572474003285366].: Trying to
get lock : 113f716b-d98f-4b92-ba9f-2629a8012354 uuid:adeaa683-4370-4e65-
92e0-a112105f7d2b UPLOAD_SUBMISSION
I 08:03:23.048 [s~abalobisa/1.385572474003285366].: Persisting
lock : 113f716b-d98f-4b92-ba9f-2629a8012354 uuid:adeaa683-4370-4e65-92e0-a112105f7d2b
UPLOAD_SUBMISSION
I 08:03:23.186 [s~abalobisa/1.385572474003285366].: Time left
on lock: 59862
I 08:03:23.186 [s~abalobisa/1.385572474003285366].: Releasing
lock : 113f716b-d98f-4b92-ba9f-2629a8012354 uuid:adeaa683-4370-4e65-92e0-a112105f7d2b
UPLOAD_SUBMISSION
W 08:03:23.186 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: Upload IGNORED when
operational status is ACTIVE_PAUSE
I 08:03:23.196 [s~abalobisa/1.385572474003285366].: Time left
on lock: 59852
I 08:03:23.224 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: ending successful servlet processing

--

Post: opendatakit@googlegroups.com
Unsubscribe: opendatakit+unsubscribe@googlegroups.com
Options: http://groups.google.com/group/opendatakit?hl=en

---

You received this message because you are subscribed to the Google Groups
"ODK Community" group.
To unsubscribe from this group and stop receiving emails from it, send an
email to opendatakit+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--
Mitch Sundt
Software Engineer
University of Washington
mitchellsundt@gmail.com

[Andrew]

Hi Mitch,

This is my Aggregate install that Taylor posted about - he's handling the
JSON server side. A bit more info:

We're running v1.4.7. We're on a free AppEngine instance which hits the
quota limits occasionally so a corrupted submission is definitely possible.
However:

1. There are 2 publishers set up on each of 2 forms (4 in total) - one
   Google Spreadsheets and one JSON for each form. Only the JSON is giving
   problems - the Google Spreadsheet appears to be receiving new data without
   problems.

2. After looking at the link you supplied I searched both the "1" and
   "background" logs for Errors containing "AURI", "_PARENT_AURI" or
   "_DOM_AURI" but found no entries in either.

Does this rule out a corrupted submission?

What else could cause the errors?

The errors appear to be repeating every 45min - is this the publisher's
standard retry-time?
Here is a slightly different error-log below (from the "1" log)

Thanks and regards,
Andrew

···

-----------------

Last line of error:
E 13:45:15.706
org.opendatakit.aggregate.task.gae.servlet.UploadSubmissionsTaskServlet
doGet: org.opendatakit.aggregate.exception.ODKExternalServiceException: (
202)

From the top:
E 2015-12-19
13:45:05.062 500 358 B 10.65 s
/gae/uploadSubmissionsTask?fscUri=uuid%3A457660f6-383a-465b-b1c2-
3a6d20f46805
0.1.0.2 - - [19/Dec/2015:03:45:05 -0800] "GET
/gae/uploadSubmissionsTask?fscUri=uuid%3A457660f6-383a-465b-b1c2-3a6d20f46805
HTTP/1.1" 500 358 http://abalobisa3.appspot.com/gae/watchdog
"AppEngine-Google; (+http://code.google.com/appengine)"
"abalobisa3.appspot.com" ms=10645 cpu_ms=135 cpm_usd=0.000305324
instance=00c61b117c4dade0a89bdb87df51e586948d67 app_engine_release=1.9.30
trace_id=-

// Some lines omitted

I 13:45:05.074
org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl
uploadAllSubmissions: Beginning UPLOAD service: uuid:3f482bc6-8234-4cfa-b70e
-3aebbc0f4ac5 form Boat_Based_Fisher_Logbook_v1_6

// Some lines omitted
I 13:45:05.859
org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl streamSubmissions
: There are 10 submissions available for streaming

I 13:45:05.859
[e~abalobisa3/1.387814171653845557].: Sending one JSON Submission

I 13:45:05.864
[e~abalobisa3/1.387814171653845557].: https:
//openfn-core.herokuapp.com/inbox/3afab0f1-3937-4ca8-95a3-5491f6f32a4e/?

I 13:45:05.865
org.opendatakit.http.conn.GaeManagedClientConnection flush: URLFetch
timeout (socket + connection) (ms): 120000

E 13:45:15.641
org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl
uploadAllSubmissions: org.opendatakit.aggregate.exception.
ODKExternalServiceException: (202)
at org.opendatakit.aggregate.externalservice.JsonServer.sendRequest(
JsonServer.java:143)
at org.opendatakit.aggregate.externalservice.JsonServer.insertData(
JsonServer.java:197)
at org.opendatakit.aggregate.externalservice.AbstractExternalService.
sendSubmission(AbstractExternalService.java:141)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
sendSubmissions(UploadSubmissionsWorkerImpl.java:318)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
streamSubmissions(UploadSubmissionsWorkerImpl.java:300)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
uploadAllSubmissions(UploadSubmissionsWorkerImpl.java:194)
at org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet.doGet(UploadSubmissionsTaskServlet.java:108)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511
)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1166)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.
doFilter(FilterChainProxy.java:330)
at org.springframework.security.web.access.intercept.
FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118)
at org.springframework.security.web.access.intercept.
FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.
doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.access.ExceptionTranslationFilter.
doFilter(ExceptionTranslationFilter.java:113)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.
doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.session.SessionManagementFilter.
doFilter(SessionManagementFilter.java:103)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.
doFilter(FilterChainProxy.java:342)
at org.opendatakit.common.security.spring.
SecurityContextHolderAwareAuthPreservingRequestFilter.doFilter(
SecurityContextHolderAwareAuthPreservingRequestFilter.java:66)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.
doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.authentication.
AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:
113)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.
doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.savedrequest.RequestCacheAwareFilter
.doFilter(RequestCacheAwareFilter.java:45)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.
doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.authentication.www.
DigestAuthenticationFilter.doFilter(DigestAuthenticationFilter.java:115)
at org.opendatakit.common.security.spring.DigestAuthenticationFilter.
doFilter(DigestAuthenticationFilter.java:40)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.
doFilter(FilterChainProxy.java:342)
at org.opendatakit.common.security.spring.OutOfBandUserFilter.doFilter(
OutOfBandUserFilter.java:105)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.
doFilter(FilterChainProxy.java:342)
at org.opendatakit.common.security.spring.Oauth2ResourceFilter.doFilter(
Oauth2ResourceFilter.java:354)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.
doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.authentication.logout.LogoutFilter.
doFilter(LogoutFilter.java:110)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.
doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.context.
SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.
java:87)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.
doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.access.channel.
ChannelProcessingFilter.doFilter(ChannelProcessingFilter.java:144)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.
doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.FilterChainProxy.doFilterInternal(
FilterChainProxy.java:192)
at org.springframework.security.web.FilterChainProxy.doFilter(
FilterChainProxy.java:160)
at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(
DelegatingFilterProxy.java:344)
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(
DelegatingFilterProxy.java:261)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(
ParseBlobUploadFilter.java:125)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(
SaveSessionFilter.java:37)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.utils.servlet.JdbcMySqlConnectionCleanupFilter.
doFilter(JdbcMySqlConnectionCleanupFilter.java:60)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter
(TransactionCleanupFilter.java:43)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:
388)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.
java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:
182)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:
765)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
at com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(
AppVersionHandlerMap.java:260)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:
152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:
542)
at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(
HttpConnection.java:923)
at com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable(
RpcRequestParser.java:78)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.
serviceRequest(JettyServletEngineAdapter.java:148)
at com.google.apphosting.runtime.JavaRuntime$RequestRunnable.run(
JavaRuntime.java:469)
at com.google.tracing.TraceContext$TraceContextRunnable.runInContext(
TraceContext.java:437)
at com.google.tracing.TraceContext$TraceContextRunnable$1.run(
TraceContext.java:444)
at com.google.tracing.CurrentContext.runInContext(CurrentContext.java:
256)
at com.google.tracing.TraceContext$AbstractTraceContextCallback.
runInInheritedContextNoUnref(TraceContext.java:308)
at com.google.tracing.TraceContext$AbstractTraceContextCallback.
runInInheritedContext(TraceContext.java:300)
at com.google.tracing.TraceContext$TraceContextRunnable.run(TraceContext
.java:441)
at com.google.apphosting.runtime.ThreadGroupPool$PoolEntry.run(
ThreadGroupPool.java:235)
at java.lang.Thread.run(Thread.java:745)

I 13:45:15.642
[e~abalobisa3/1.387814171653845557].: Releasing lock : aaee3268-e6f4
-4268-84fe-5825c86c00d2 uuid:457660f6-383a-465b-b1c2-3a6d20f46805
UPLOAD_SUBMISSION

I 13:45:15.655
[e~abalobisa3/1.387814171653845557].: Time left on lock: 49722

I 13:45:15.655
[e~abalobisa3/1.387814171653845557].: Time left on lock: -10750153

I 13:45:15.655
[e~abalobisa3/1.387814171653845557].: Time left on lock: -94446872

E 13:45:15.706
org.opendatakit.aggregate.task.gae.servlet.UploadSubmissionsTaskServlet
doGet: org.opendatakit.aggregate.exception.ODKExternalServiceException: (
202)

On Monday, 21 December 2015 20:59:10 UTC+2, Mitch Sundt wrote:

What version of ODK Aggregate are you running?

It may be that you have a corrupted submission and ODK Aggregate is
stalled trying to read it.
This would be farther down in the log.

Assuming you are running a newer ODK Aggregate, the error logs and
resolution steps are covered here:

https://github.com/opendatakit/opendatakit/wiki/Aggregate-AppEngine-Troubleshooting#reparing-a-filled-in-form-submission

The error messages are different prior to 1.4.5, and in some cases, you
may need the latest 1.4.7 to get enough information in the log messages.

On Sat, Dec 19, 2015 at 5:16 AM, Taylor Downs <downs....@gmail.com <javascript:>> wrote:

Hey team, has anyone noticed a change in the JSON publisher recently? I
was receiving submissions as JSON (Z-Alpha JSON Server) up until December
14th, responding with a 202. Recently, the publisher pauses and retries the
same submission over and over, despite the submissions being received in
our destination system and us responding with a 202. I've pasted the logs
below. Apologies for bad formatting.

This is a 500 that appears in Aggregate after the publisher is started:
E 2015-12-19 08:03:19.436 500 358 B 2.91 s I 08:03:19.446 I 08:03:
19.455 I 08:03:19.459 I 08:03:19.459 I 08:03:19.479 I 08:03:19.497 I 08:03
:19.522 I 08:03:19.530 I 08:03:19.542 I 08:03:19.542 I 08:03:19.688 I 08:
03:19.689 I 08:03:20.414 I 08:03:20.414 I 08:03:21.113 I 08:03:21.685 E 08
:03:22.211 I 08:03:22.212 I 08:03:22.223 E 08:03:22.338 /gae/
uploadSubmissionsTask?fscUri=uuid%3Aadeaa683-4370-4e65-92e0-a112105f7d2b
0.1.0.2 - - [19/Dec/2015:05:03:19 -0800] "GET
/gae/uploadSubmissionsTask?fscUri=uuid%3Aadeaa683-4370-4e65-92e0-a112105f7d2b
HTTP/1.1" 500 358 https://
abalobisa.appspot.com/aggregateui/servicesadminservice "AppEngine-Google;
(+http://code.google.com/appengine)" "abalobisa.appspot.com" ms=2905
cpu_ms=1432 cpm_usd=0.000291801
instance=00c61b117c6941a0ec999cc353fb389b9bd566f4 app_engine_release=1.9.30
trace_id=-
I 08:03:19.446 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: Beginning servlet processing
I 08:03:19.455 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: Request is running on frontend
I 08:03:19.459 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: Beginning UPLOAD service
: uuid:1b715159-8524-45f5-91db-6267da8aa380 form
DEMO_CCM_landing_site_v1_5
I 08:03:19.459 org.opendatakit.aggregate.form.FormFactory
internalGetForms: FormCache: fetching new list of Forms
I 08:03:19.479 org.opendatakit.aggregate.util.BackendActionsTable
logValues: incoming- last Fetch: -4422 [S: -2379 Eq: -4422 Fs: -4422] futureMillis:
895578
I 08:03:19.497 org.opendatakit.aggregate.util.BackendActionsTable
logValues: -fetched- last Fetch: 0 [S: -2379 Eq: -4422 Fs: -4422] futureMillis:
-1
I 08:03:19.522 org.opendatakit.aggregate.util.BackendActionsTable
logValues: Fs-update last Fetch: 0 [S: -2379 Eq: -4422 Fs: 895578] futureMillis:
895578 requested: 895578
I 08:03:19.530 org.opendatakit.aggregate.form.FormFactory
internalGetForms: FormCache: using cached list of Forms
I 08:03:19.542 [s~abalobisa/1.385572474003285366].: Trying to
get lock : 4fedc3b6-46c2-4fe2-a3e3-a4bde852aa7e uuid:adeaa683-4370-4e65-
92e0-a112105f7d2b UPLOAD_SUBMISSION
I 08:03:19.542 [s~abalobisa/1.385572474003285366].: Persisting
lock : 4fedc3b6-46c2-4fe2-a3e3-a4bde852aa7e uuid:adeaa683-4370-4e65-92e0-a112105f7d2b
UPLOAD_SUBMISSION
I 08:03:19.688 [s~abalobisa/1.385572474003285366].: Time left
on lock: 59854
I 08:03:19.689 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: Upload invoked when
operational status is ACTIVE
I 08:03:20.414 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadSubmissions: There are 10 submissions
available for upload
I 08:03:20.414 [s~abalobisa/1.385572474003285366].: Sending
one JSON Submission
I 08:03:21.113 [s~abalobisa/1.385572474003285366].: https://
openfn-core.herokuapp.com/inbox/3afab0f1-3937-4ca8-95a3-5491f6f32a4e/?
I 08:03:21.685 org.opendatakit.http.conn.GaeManagedClientConnection
flush: URLFetch timeout (socket + connection) (ms): 120000
E 08:03:22.211 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: org.opendatakit.
aggregate.exception.ODKExternalServiceException: (202)
at org.opendatakit.aggregate.externalservice.JsonServer.
sendRequest(JsonServer.java:143)
at org.opendatakit.aggregate.externalservice.JsonServer.insertData
(JsonServer.java:197)
at org.opendatakit.aggregate.externalservice.
AbstractExternalService.sendSubmission(AbstractExternalService.java:141)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
sendSubmissions(UploadSubmissionsWorkerImpl.java:318)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
uploadSubmissions(UploadSubmissionsWorkerImpl.java:278)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
uploadAllSubmissions(UploadSubmissionsWorkerImpl.java:184)
at org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet.doGet(UploadSubmissionsTaskServlet.java:108)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.
java:511)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1166)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330)
at org.springframework.security.web.access.intercept.
FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118)
at org.springframework.security.web.access.intercept.
FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.

...

[Mitch_S]

From:

Aggregate Publishers Implementation Details

In particular,

Aggregate Publishers Implementation Details

• After receiving the POST request, send a 200 status code back to the
  Aggregate server, or else it will think there was an error and not send any
  further POSTs.

The problem is that your JSON server is acknowledging with a 202 (ACCEPTED)
and not a 200 (OK).

···

On Thu, Dec 31, 2015 at 12:15 AM, Andrew wrote:

Hi Mitch,

This is my Aggregate install that Taylor posted about - he's handling the
JSON server side. A bit more info:

We're running v1.4.7. We're on a free AppEngine instance which hits the
quota limits occasionally so a corrupted submission is definitely possible.
However:

1. There are 2 publishers set up on each of 2 forms (4 in total) - one
   Google Spreadsheets and one JSON for each form. Only the JSON is giving
   problems - the Google Spreadsheet appears to be receiving new data without
   problems.

2. After looking at the link you supplied I searched both the "1" and
   "background" logs for Errors containing "AURI", "_PARENT_AURI" or
   "_DOM_AURI" but found no entries in either.

Does this rule out a corrupted submission?

What else could cause the errors?

The errors appear to be repeating every 45min - is this the publisher's
standard retry-time?
Here is a slightly different error-log below (from the "1" log)

Thanks and regards,
Andrew

---

Last line of error:
E 13:45:15.706
org.opendatakit.aggregate.task.gae.servlet.UploadSubmissionsTaskServlet
doGet: org.opendatakit.aggregate.exception.ODKExternalServiceException: (
202)

From the top:
E 2015-12-19
13:45:05.062 500 358 B 10.65 s
/gae/uploadSubmissionsTask?fscUri=uuid%3A457660f6-383a-465b-b1c2-
3a6d20f46805
0.1.0.2 - - [19/Dec/2015:03:45:05 -0800] "GET
/gae/uploadSubmissionsTask?fscUri=uuid%3A457660f6-383a-465b-b1c2-3a6d20f46805
HTTP/1.1" 500 358 http://abalobisa3.appspot.com/gae/watchdog
"AppEngine-Google; (+http://code.google.com/appengine)" "
abalobisa3.appspot.com" ms=10645 cpu_ms=135 cpm_usd=0.000305324
instance=00c61b117c4dade0a89bdb87df51e586948d67 app_engine_release=1.9.30
trace_id=-

// Some lines omitted

I 13:45:05.074
org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl
uploadAllSubmissions: Beginning UPLOAD service: uuid:3f482bc6-8234-4cfa-
b70e-3aebbc0f4ac5 form Boat_Based_Fisher_Logbook_v1_6

// Some lines omitted
I 13:45:05.859
org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl
streamSubmissions: There are 10 submissions available for streaming

I 13:45:05.859
[e~abalobisa3/1.387814171653845557].: Sending one JSON Submission

I 13:45:05.864
[e~abalobisa3/1.387814171653845557].: https://
openfn-core.herokuapp.com/inbox/3afab0f1-3937-4ca8-95a3-5491f6f32a4e/?

I 13:45:05.865
org.opendatakit.http.conn.GaeManagedClientConnection flush: URLFetch
timeout (socket + connection) (ms): 120000

E 13:45:15.641
org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl
uploadAllSubmissions: org.opendatakit.aggregate.exception.
ODKExternalServiceException: (202)
at org.opendatakit.aggregate.externalservice.JsonServer.sendRequest(
JsonServer.java:143)
at org.opendatakit.aggregate.externalservice.JsonServer.insertData(
JsonServer.java:197)
at org.opendatakit.aggregate.externalservice.AbstractExternalService.
sendSubmission(AbstractExternalService.java:141)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
sendSubmissions(UploadSubmissionsWorkerImpl.java:318)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
streamSubmissions(UploadSubmissionsWorkerImpl.java:300)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
uploadAllSubmissions(UploadSubmissionsWorkerImpl.java:194)
at org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet.doGet(UploadSubmissionsTaskServlet.java:108)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:
511)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1166)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330)
at org.springframework.security.web.access.intercept.
FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118)
at org.springframework.security.web.access.intercept.
FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.access.ExceptionTranslationFilter.
doFilter(ExceptionTranslationFilter.java:113)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.session.SessionManagementFilter.
doFilter(SessionManagementFilter.java:103)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.opendatakit.common.security.spring.
SecurityContextHolderAwareAuthPreservingRequestFilter.doFilter(
SecurityContextHolderAwareAuthPreservingRequestFilter.java:66)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.authentication.
AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:
113)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.savedrequest.
RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.authentication.www.
DigestAuthenticationFilter.doFilter(DigestAuthenticationFilter.java:115)
at org.opendatakit.common.security.spring.DigestAuthenticationFilter.
doFilter(DigestAuthenticationFilter.java:40)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.opendatakit.common.security.spring.OutOfBandUserFilter.doFilter
(OutOfBandUserFilter.java:105)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.opendatakit.common.security.spring.Oauth2ResourceFilter.
doFilter(Oauth2ResourceFilter.java:354)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.authentication.logout.LogoutFilter
.doFilter(LogoutFilter.java:110)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.context.
SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter
.java:87)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.access.channel.
ChannelProcessingFilter.doFilter(ChannelProcessingFilter.java:144)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.FilterChainProxy.doFilterInternal(
FilterChainProxy.java:192)
at org.springframework.security.web.FilterChainProxy.doFilter(
FilterChainProxy.java:160)
at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate
(DelegatingFilterProxy.java:344)
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(
DelegatingFilterProxy.java:261)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(
ParseBlobUploadFilter.java:125)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(
SaveSessionFilter.java:37)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.utils.servlet.
JdbcMySqlConnectionCleanupFilter.doFilter(JdbcMySqlConnectionCleanupFilter
.java:60)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at com.google.apphosting.utils.servlet.TransactionCleanupFilter.
doFilter(TransactionCleanupFilter.java:43)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1157)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java
:388)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.
java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java
:182)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java
:765)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:
418)
at com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(
AppVersionHandlerMap.java:260)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java
:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:
542)
at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(
HttpConnection.java:923)
at com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable
(RpcRequestParser.java:78)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.
serviceRequest(JettyServletEngineAdapter.java:148)
at com.google.apphosting.runtime.JavaRuntime$RequestRunnable.run(
JavaRuntime.java:469)
at com.google.tracing.TraceContext$TraceContextRunnable.runInContext(
TraceContext.java:437)
at com.google.tracing.TraceContext$TraceContextRunnable$1.run(
TraceContext.java:444)
at com.google.tracing.CurrentContext.runInContext(CurrentContext.java:
256)
at com.google.tracing.TraceContext$AbstractTraceContextCallback.
runInInheritedContextNoUnref(TraceContext.java:308)
at com.google.tracing.TraceContext$AbstractTraceContextCallback.
runInInheritedContext(TraceContext.java:300)
at com.google.tracing.TraceContext$TraceContextRunnable.run(
TraceContext.java:441)
at com.google.apphosting.runtime.ThreadGroupPool$PoolEntry.run(
ThreadGroupPool.java:235)
at java.lang.Thread.run(Thread.java:745)

I 13:45:15.642
[e~abalobisa3/1.387814171653845557].: Releasing lock : aaee3268-
e6f4-4268-84fe-5825c86c00d2 uuid:457660f6-383a-465b-b1c2-3a6d20f46805
UPLOAD_SUBMISSION

I 13:45:15.655
[e~abalobisa3/1.387814171653845557].: Time left on lock: 49722

I 13:45:15.655
[e~abalobisa3/1.387814171653845557].: Time left on lock: -10750153

I 13:45:15.655
[e~abalobisa3/1.387814171653845557].: Time left on lock: -94446872

E 13:45:15.706
org.opendatakit.aggregate.task.gae.servlet.UploadSubmissionsTaskServlet
doGet: org.opendatakit.aggregate.exception.ODKExternalServiceException: (
202)

On Monday, 21 December 2015 20:59:10 UTC+2, Mitch Sundt wrote:

What version of ODK Aggregate are you running?

It may be that you have a corrupted submission and ODK Aggregate is
stalled trying to read it.
This would be farther down in the log.

Assuming you are running a newer ODK Aggregate, the error logs and
resolution steps are covered here:

https://github.com/opendatakit/opendatakit/wiki/Aggregate-AppEngine-Troubleshooting#reparing-a-filled-in-form-submission

The error messages are different prior to 1.4.5, and in some cases, you
may need the latest 1.4.7 to get enough information in the log messages.

On Sat, Dec 19, 2015 at 5:16 AM, Taylor Downs downs....@gmail.com wrote:

Hey team, has anyone noticed a change in the JSON publisher recently? I
was receiving submissions as JSON (Z-Alpha JSON Server) up until December
14th, responding with a 202. Recently, the publisher pauses and retries the
same submission over and over, despite the submissions being received in
our destination system and us responding with a 202. I've pasted the logs
below. Apologies for bad formatting.

This is a 500 that appears in Aggregate after the publisher is started:
E 2015-12-19 08:03:19.436 500 358 B 2.91 s I 08:03:19.446 I 08:03:
19.455 I 08:03:19.459 I 08:03:19.459 I 08:03:19.479 I 08:03:19.497 I 08:
03:19.522 I 08:03:19.530 I 08:03:19.542 I 08:03:19.542 I 08:03:19.688 I
08:03:19.689 I 08:03:20.414 I 08:03:20.414 I 08:03:21.113 I 08:03:21.685
E 08:03:22.211 I 08:03:22.212 I 08:03:22.223 E 08:03:22.338 /gae/
uploadSubmissionsTask?fscUri=uuid%3Aadeaa683-4370-4e65-92e0-a112105f7d2b
0.1.0.2 - - [19/Dec/2015:05:03:19 -0800] "GET
/gae/uploadSubmissionsTask?fscUri=uuid%3Aadeaa683-4370-4e65-92e0-a112105f7d2b
HTTP/1.1" 500 358 https://
abalobisa.appspot.com/aggregateui/servicesadminservice
"AppEngine-Google; (+http://code.google.com/appengine)" "
abalobisa.appspot.com" ms=2905 cpu_ms=1432 cpm_usd=0.000291801
instance=00c61b117c6941a0ec999cc353fb389b9bd566f4 app_engine_release=1.9.30
trace_id=-
I 08:03:19.446 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: Beginning servlet processing
I 08:03:19.455 org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet doGet: Request is running on frontend
I 08:03:19.459 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: Beginning UPLOAD
service: uuid:1b715159-8524-45f5-91db-6267da8aa380 form
DEMO_CCM_landing_site_v1_5
I 08:03:19.459 org.opendatakit.aggregate.form.FormFactory
internalGetForms: FormCache: fetching new list of Forms
I 08:03:19.479 org.opendatakit.aggregate.util.BackendActionsTable
logValues: incoming- last Fetch: -4422 [S: - 2379 Eq: -4422 Fs: -4422] futureMillis:
895578
I 08:03:19.497 org.opendatakit.aggregate.util.BackendActionsTable
logValues: -fetched- last Fetch: 0 [S: - 2379 Eq: -4422 Fs: -4422] futureMillis:
-1
I 08:03:19.522 org.opendatakit.aggregate.util.BackendActionsTable
logValues: Fs-update last Fetch: 0 [S: - 2379 Eq: -4422 Fs: 895578] futureMillis:
895578 requested: 895578
I 08:03:19.530 org.opendatakit.aggregate.form.FormFactory
internalGetForms: FormCache: using cached list of Forms
I 08:03:19.542 [s~abalobisa/1.385572474003285366].: Trying
to get lock : 4fedc3b6-46c2-4fe2-a3e3-a4bde852aa7e uuid:adeaa683-4370-
4e65-92e0-a112105f7d2b UPLOAD_SUBMISSION
I 08:03:19.542 [s~abalobisa/1.385572474003285366].:
Persisting lock : 4fedc3b6-46c2-4fe2-a3e3-a4bde852aa7e uuid:adeaa683-4370
-4e65-92e0-a112105f7d2b UPLOAD_SUBMISSION
I 08:03:19.688 [s~abalobisa/1.385572474003285366].: Time
left on lock: 59854
I 08:03:19.689 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: Upload invoked when
operational status is ACTIVE
I 08:03:20.414 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadSubmissions: There are 10 submissions
available for upload
I 08:03:20.414 [s~abalobisa/1.385572474003285366].: Sending
one JSON Submission
I 08:03:21.113 [s~abalobisa/1.385572474003285366].: https://
openfn-core.herokuapp.com/inbox/3afab0f1-3937-4ca8-95a3-5491f6f32a4e/?
I 08:03:21.685 org.opendatakit.http.conn.GaeManagedClientConnection
flush: URLFetch timeout (socket + connection) (ms): 120000
E 08:03:22.211 org.opendatakit.aggregate.task.
UploadSubmissionsWorkerImpl uploadAllSubmissions: org.opendatakit.
aggregate.exception.ODKExternalServiceException: (202)
at org.opendatakit.aggregate.externalservice.JsonServer.
sendRequest(JsonServer.java:143)
at org.opendatakit.aggregate.externalservice.JsonServer.
insertData(JsonServer.java:197)
at org.opendatakit.aggregate.externalservice.
AbstractExternalService.sendSubmission(AbstractExternalService.java:141)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
sendSubmissions(UploadSubmissionsWorkerImpl.java:318)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
uploadSubmissions(UploadSubmissionsWorkerImpl.java:278)
at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl.
uploadAllSubmissions(UploadSubmissionsWorkerImpl.java:184)
at org.opendatakit.aggregate.task.gae.servlet.
UploadSubmissionsTaskServlet.doGet(UploadSubmissionsTaskServlet.java:108)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.
java:511)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(
ServletHandler.java:1166)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330)
at org.springframework.security.web.access.intercept.
FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118)
at org.springframework.security.web.access.intercept.
FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84)
at org.springframework.security.web.
FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.

...

--

Post: opendatakit@googlegroups.com
Unsubscribe: opendatakit+unsubscribe@googlegroups.com
Options: http://groups.google.com/group/opendatakit?hl=en

---

You received this message because you are subscribed to the Google Groups
"ODK Community" group.
To unsubscribe from this group and stop receiving emails from it, send an
email to opendatakit+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--
Mitch Sundt
Software Engineer
University of Washington
mitchellsundt@gmail.com

[Andrew]

Thanks Mitch, that seems to have been our issue, all running now!

Thanks and regards,
Andrew

···

On Monday, 4 January 2016 21:00:08 UTC+2, Mitch Sundt wrote: > > From: > https://github.com/opendatakit/opendatakit/wiki/Aggregate-Publishers-Implementation-Details > > In particular, > https://github.com/opendatakit/opendatakit/wiki/Aggregate-Publishers-Implementation-Details#notes-from-a-django-integration > > > - After receiving the POST request, send a 200 status code back to the > Aggregate server, or else it will think there was an error and not send any > further POSTs. > > The problem is that your JSON server is acknowledging with a 202 > (ACCEPTED) and not a 200 (OK). > > > On Thu, Dec 31, 2015 at 12:15 AM, Andrew <acawo...@gmail.com wrote: > > Hi Mitch, > > This is my Aggregate install that Taylor posted about - he's handling the > JSON server side. A bit more info: > > We're running v1.4.7. We're on a free AppEngine instance which hits the > quota limits occasionally so a corrupted submission is definitely possible. > However: > > 1. There are 2 publishers set up on each of 2 forms (4 in total) - one > Google Spreadsheets and one JSON for each form. Only the JSON is giving > problems - the Google Spreadsheet appears to be receiving new data without > problems. > > 2. After looking at the link you supplied I searched both the "1" and > "background" logs for Errors containing "AURI", "_PARENT_AURI" or > "_DOM_AURI" but found no entries in either. > > Does this rule out a corrupted submission? > > What else could cause the errors? > > The errors appear to be repeating every 45min - is this the publisher's > standard retry-time? > Here is a slightly different error-log below (from the "1" log) > > Thanks and regards, > Andrew > > > ----------------- > > Last line of error: > E 13:45:15.706 > org.opendatakit.aggregate.task.gae.servlet.UploadSubmissionsTaskServlet > doGet: org.opendatakit.aggregate.exception.ODKExternalServiceException: ( > 202) > > From the top: > E 2015-12-19 > 13:45:05.062 500 358 B 10.65 s > /gae/uploadSubmissionsTask?fscUri=uuid%3A457660f6-383a-465b-b1c2- > 3a6d20f46805 > 0.1.0.2 - - [19/Dec/2015:03:45:05 -0800] "GET > /gae/uploadSubmissionsTask?fscUri=uuid%3A457660f6-383a-465b-b1c2-3a6d20f46805 > HTTP/1.1" 500 358 http://abalobisa3.appspot.com/gae/watchdog > "AppEngine-Google; (+http://code.google.com/appengine)" " > abalobisa3.appspot.com" ms=10645 cpu_ms=135 cpm_usd=0.000305324 > instance=00c61b117c4dade0a89bdb87df51e586948d67 app_engine_release=1.9.30 > trace_id=- > > // Some lines omitted > > I 13:45:05.074 > org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl > uploadAllSubmissions: Beginning UPLOAD service: uuid:3f482bc6-8234-4cfa- > b70e-3aebbc0f4ac5 form Boat_Based_Fisher_Logbook_v1_6 > > // Some lines omitted > I 13:45:05.859 > org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl > streamSubmissions: There are 10 submissions available for streaming > > I 13:45:05.859 > [e~abalobisa3/1.387814171653845557].: Sending one JSON Submission > > I 13:45:05.864 > [e~abalobisa3/1.387814171653845557].: https:// > openfn-core.herokuapp.com/inbox/3afab0f1-3937-4ca8-95a3-5491f6f32a4e/? > > I 13:45:05.865 > org.opendatakit.http.conn.GaeManagedClientConnection flush: URLFetch > timeout (socket + connection) (ms): 120000 > > E 13:45:15.641 > org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl > uploadAllSubmissions: org.opendatakit.aggregate.exception. > ODKExternalServiceException: (202) > at org.opendatakit.aggregate.externalservice.JsonServer.sendRequest( > JsonServer.java:143) > at org.opendatakit.aggregate.externalservice.JsonServer.insertData( > JsonServer.java:197) > at org.opendatakit.aggregate.externalservice.AbstractExternalService. > sendSubmission(AbstractExternalService.java:141) > at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl. > sendSubmissions(UploadSubmissionsWorkerImpl.java:318) > at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl. > streamSubmissions(UploadSubmissionsWorkerImpl.java:300) > at org.opendatakit.aggregate.task.UploadSubmissionsWorkerImpl. > uploadAllSubmissions(UploadSubmissionsWorkerImpl.java:194) > at org.opendatakit.aggregate.task.gae.servlet. > UploadSubmissionsTaskServlet.doGet(UploadSubmissionsTaskServlet.java:108) > at javax.servlet.http.HttpServlet.service(HttpServlet.java:617) > at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) > at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java: > 511) > at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter( > ServletHandler.java:1166) > at org.springframework.security.web. > FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) > at org.springframework.security.web.access.intercept. > FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118) > at org.springframework.security.web.access.intercept. > FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84) > at org.springframework.security.web. > FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at org.springframework.security.web.access.ExceptionTranslationFilter. > doFilter(ExceptionTranslationFilter.java:113) > at org.springframework.security.web. > FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at org.springframework.security.web.session.SessionManagementFilter. > doFilter(SessionManagementFilter.java:103) > at org.springframework.security.web. > FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at org.opendatakit.common.security.spring. > SecurityContextHolderAwareAuthPreservingRequestFilter.doFilter( > SecurityContextHolderAwareAuthPreservingRequestFilter.java:66) > at org.springframework.security.web. > FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at org.springframework.security.web.authentication. > AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java: > 113) > at org.springframework.security.web. > FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at org.springframework.security.web.savedrequest. > RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45) > at org.springframework.security.web. > FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at org.springframework.security.web.authentication.www. > DigestAuthenticationFilter.doFilter(DigestAuthenticationFilter.java:115) > at org.opendatakit.common.security.spring.DigestAuthenticationFilter. > doFilter(DigestAuthenticationFilter.java:40) > at org.springframework.security.web. > FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at org.opendatakit.common.security.spring.OutOfBandUserFilter.doFilter > (OutOfBandUserFilter.java:105) > at org.springframework.security.web. > FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at org.opendatakit.common.security.spring.Oauth2ResourceFilter. > doFilter(Oauth2ResourceFilter.java:354) > at org.springframework.security.web. > FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at org.springframework.security.web.authentication.logout.LogoutFilter > .doFilter(LogoutFilter.java:110) > at org.springframework.security.web. > FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at org.springframework.security.web.context. > SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter > .java:87) > at org > > ...

[Emma_Hosking]

Hi team

Wow this is all a bit beyond me, but I'm experiencing the same issue publishing to JSON - and happy to see @taylordowns2000 here as we have worked on a project together. Taylor do you have any advice on how to resolve for the not-so-technical?

Thanks
Emma

[Emma_Hosking]

This is the error I am getting:

[taylordowns2000]

Hey Emma, looks like it might be a different issue than @Andrew was facing, as the response from Open Function to ODK is now a 200—Andrew was dealing with a 202.

I think you're onto something with the corrupt submission idea, as mentioned in your email. I'll look into ways to remove or fix corrupt submissions and restart the publisher. (Must be some documentation for that online.)