Menu

#79 JVXML crashes due to BadFetchError

1.0
open
nobody
None
2015-08-21
2015-08-21
No

I observed the following error more than once when I went live with the Kaldi implementation of the pizza item. This seems to be an Apache Tomcat (OpenVXML application) error, but I'm opening a ticket for this just in case.

 [java] 2015-08-21 16:28:29,270 DEBUG conn.DefaultClientConnection [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: Sending request: POST /7711_kaldi/-/next?A_delivery=%7B+WOULD+LIKE+THAT+THE+GUY+ACCORDINGLY+%7D&lastresult=%3Clastresult%3E%3Cmark+name%3D%22NONE%22+offset%3D%220%22%2F%3E%3Cresult%3E%3Cconfidence%3E1%3C%2Fconfidence%3E%3Cutterance%3E%3C%21%5BCDATA%5B%7B+WOULD+LIKE+THAT+THE+GUY+ACCORDINGLY+%7D%5D%5D%3E%3C%2Futterance%3E%3Cinputmode%3E%3C%21%5BCDATA%5Bvoice%5D%5D%3E%3C%2Finputmode%3E%3Cinterpretation%3E%3C%21%5BCDATA%5Bnull%5D%5D%3E%3C%2Finterpretation%3E%3C%2Fresult%3E%3C%2Flastresult%3E&Action_0d4a362a538448eb9813dcf80ecef38d=success.filled HTTP/1.1
 [java] 2015-08-21 16:28:29,281 DEBUG http.wire [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: >> "POST /7711_kaldi/-/next?A_delivery=%7B+WOULD+LIKE+THAT+THE+GUY+ACCORDINGLY+%7D&lastresult=%3Clastresult%3E%3Cmark+name%3D%22NONE%22+offset%3D%220%22%2F%3E%3Cresult%3E%3Cconfidence%3E1%3C%2Fconfidence%3E%3Cutterance%3E%3C%21%5BCDATA%5B%7B+WOULD+LIKE+THAT+THE+GUY+ACCORDINGLY+%7D%5D%5D%3E%3C%2Futterance%3E%3Cinputmode%3E%3C%21%5BCDATA%5Bvoice%5D%5D%3E%3C%2Finputmode%3E%3Cinterpretation%3E%3C%21%5BCDATA%5Bnull%5D%5D%3E%3C%2Finterpretation%3E%3C%2Fresult%3E%3C%2Flastresult%3E&Action_0d4a362a538448eb9813dcf80ecef38d=success.filled HTTP/1.1[\r][\n]"
 [java] 2015-08-21 16:28:29,286 DEBUG http.wire [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: >> "Content-Length: 0[\r][\n]"
 [java] 2015-08-21 16:28:29,296 DEBUG http.wire [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: >> "Host: 141.31.8.128:8080[\r][\n]"
 [java] 2015-08-21 16:28:29,303 DEBUG http.wire [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: >> "Connection: Keep-Alive[\r][\n]"
 [java] 2015-08-21 16:28:29,313 DEBUG http.wire [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: >> "User-Agent: Apache-HttpClient/4.2.3 (java 1.5)[\r][\n]"
 [java] 2015-08-21 16:28:29,318 DEBUG http.wire [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: >> "Cookie: JSESSIONID=42A8C1EB6F06ADC2434FF13AB12BB5AE[\r][\n]"
 [java] 2015-08-21 16:28:29,325 DEBUG http.wire [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: >> "Cookie2: $Version=1[\r][\n]"
 [java] 2015-08-21 16:28:29,334 DEBUG http.wire [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: >> "[\r][\n]"
 [java] 2015-08-21 16:28:29,341 DEBUG http.headers [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: >> POST /7711_kaldi/-/next?A_delivery=%7B+WOULD+LIKE+THAT+THE+GUY+ACCORDINGLY+%7D&lastresult=%3Clastresult%3E%3Cmark+name%3D%22NONE%22+offset%3D%220%22%2F%3E%3Cresult%3E%3Cconfidence%3E1%3C%2Fconfidence%3E%3Cutterance%3E%3C%21%5BCDATA%5B%7B+WOULD+LIKE+THAT+THE+GUY+ACCORDINGLY+%7D%5D%5D%3E%3C%2Futterance%3E%3Cinputmode%3E%3C%21%5BCDATA%5Bvoice%5D%5D%3E%3C%2Finputmode%3E%3Cinterpretation%3E%3C%21%5BCDATA%5Bnull%5D%5D%3E%3C%2Finterpretation%3E%3C%2Fresult%3E%3C%2Flastresult%3E&Action_0d4a362a538448eb9813dcf80ecef38d=success.filled HTTP/1.1
 [java] 2015-08-21 16:28:29,348 DEBUG http.headers [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: >> Content-Length: 0
 [java] 2015-08-21 16:28:29,354 DEBUG http.headers [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: >> Host: 141.31.8.128:8080
 [java] 2015-08-21 16:28:29,360 DEBUG http.headers [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: >> Connection: Keep-Alive
 [java] 2015-08-21 16:28:29,364 DEBUG http.headers [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: >> User-Agent: Apache-HttpClient/4.2.3 (java 1.5)
 [java] 2015-08-21 16:28:29,374 DEBUG http.headers [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: >> Cookie: JSESSIONID=42A8C1EB6F06ADC2434FF13AB12BB5AE
 [java] 2015-08-21 16:28:29,380 DEBUG http.headers [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: >> Cookie2: $Version=1
 [java] 2015-08-21 16:28:29,388 DEBUG conn.DefaultClientConnection [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: Connection 0.0.0.0:47584<->141.31.8.128:8080 closed
 [java] 2015-08-21 16:28:29,397 DEBUG client.DefaultHttpClient [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: Closing the connection.
 [java] 2015-08-21 16:28:29,408 DEBUG conn.DefaultClientConnection [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: Connection 0.0.0.0:47584<->141.31.8.128:8080 closed
 [java] 2015-08-21 16:28:29,419 DEBUG conn.DefaultClientConnection [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: Connection 0.0.0.0:47584<->141.31.8.128:8080 shut down
 [java] 2015-08-21 16:28:29,425 DEBUG conn.BasicClientConnectionManager [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: Releasing connection org.apache.http.impl.conn.ManagedClientConnectionImpl@9c73765
 [java] 2015-08-21 16:28:29,436 DEBUG conn.BasicClientConnectionManager [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: Connection can be kept alive for 9223372036854775807 MILLISECONDS
 [java] 2015-08-21 16:28:29,444 INFO  scope.ScopeObserver [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: exiting scope 'document'...
 [java] 2015-08-21 16:28:29,451 DEBUG scope.ScopeObserver [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: current scope stack: [SESSION, APPLICATION]
 [java] 2015-08-21 16:28:29,456 ERROR interpreter.JVoiceXmlSession [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: error processing application 'Unknown application'
 [java] org.jvoicexml.event.error.BadFetchError: error.badfetch: The target server failed to respond
 [java]     at org.jvoicexml.documentserver.schemestrategy.HttpSchemeStrategy.getInputStream(HttpSchemeStrategy.java:215) ~[classes/:?]
 [java]     at org.jvoicexml.documentserver.JVoiceXmlDocumentServer.getDocument(JVoiceXmlDocumentServer.java:205) ~[classes/:?]
 [java]     at org.jvoicexml.interpreter.VoiceXmlInterpreterContext.acquireVoiceXmlDocument(VoiceXmlInterpreterContext.java:722) ~[classes/:?]
 [java]     at org.jvoicexml.interpreter.VoiceXmlInterpreterContext.loadDocument(VoiceXmlInterpreterContext.java:678) ~[classes/:?]
 [java]     at org.jvoicexml.interpreter.VoiceXmlInterpreterContext.process(VoiceXmlInterpreterContext.java:492) ~[classes/:?]
 [java]     at org.jvoicexml.interpreter.JVoiceXmlSession.run(JVoiceXmlSession.java:328) [classes/:?]
 [java] Caused by: org.apache.http.NoHttpResponseException: The target server failed to respond
 [java]     at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:95) ~[httpclient-4.2.3.jar:4.2.3]
 [java]     at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:62) ~[httpclient-4.2.3.jar:4.2.3]
 [java]     at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254) ~[httpcore-4.2.3.jar:4.2.3]
 [java]     at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289) ~[httpcore-4.2.3.jar:4.2.3]
 [java]     at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252) ~[httpclient-4.2.3.jar:4.2.3]
 [java]     at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191) ~[httpclient-4.2.3.jar:4.2.3]
 [java]     at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300) ~[httpcore-4.2.3.jar:4.2.3]
 [java]     at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127) ~[httpcore-4.2.3.jar:4.2.3]
 [java]     at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:717) ~[httpclient-4.2.3.jar:4.2.3]
 [java]     at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:522) ~[httpclient-4.2.3.jar:4.2.3]
 [java]     at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906) ~[httpclient-4.2.3.jar:4.2.3]
 [java]     at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805) ~[httpclient-4.2.3.jar:4.2.3]
 [java]     at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784) ~[httpclient-4.2.3.jar:4.2.3]
 [java]     at org.jvoicexml.documentserver.schemestrategy.HttpSchemeStrategy.getInputStream(HttpSchemeStrategy.java:205) ~[classes/:?]
 [java]     ... 5 more
 [java] 2015-08-21 16:28:29,468 DEBUG interpreter.JVoiceXmlSession [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: finished processing application 'Unknown application'
 [java] 2015-08-21 16:28:29,473 INFO  interpreter.JVoiceXmlSession [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: closing session...
 [java] 2015-08-21 16:28:29,485 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: closing implementation platform
 [java] 2015-08-21 16:28:29,490 DEBUG jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: PATRICK HACK: dont wait for empty queue
 [java] 2015-08-21 16:28:29,495 DEBUG jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: waiting for empty input not busy...
 [java] 2015-08-21 16:28:29,500 WARN  mrcpv2.Mrcpv2SpokenInput [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: isBusy check is not implemented.
 [java] 2015-08-21 16:28:29,504 DEBUG jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: ...input not busy.
 [java] 2015-08-21 16:28:29,515 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returning aqcuired resources
 [java] 2015-08-21 16:28:29,521 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: starting returnSystemOutput...
 [java] 2015-08-21 16:28:29,528 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returnSystemOutput
 [java] 2015-08-21 16:28:29,532 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returnSystemOutput 3
 [java] 2015-08-21 16:28:29,546 DEBUG jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returning system output of type 'mrcpv2'...
 [java] 2015-08-21 16:28:29,552 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: PATRICK HACK force queue count to 0
 [java] 2015-08-21 16:28:29,562 INFO  mrcpv2.Mrcpv2SynthesizedOutput [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: PATRICK HACK: setQueueCount to 0
 [java] 2015-08-21 16:28:29,566 DEBUG jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returning external resource 'mrcpv2' (org.jvoicexml.implementation.mrcpv2.Mrcpv2SynthesizedOutput) to pool...
 [java] 2015-08-21 16:28:29,571 DEBUG jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: disconnecting external resource.
 [java] 2015-08-21 16:28:29,579 DEBUG jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: ...disconnected
 [java] 2015-08-21 16:28:29,587 DEBUG mrcpv2.Mrcpv2SynthesizedOutput [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: passivating output...
 [java] 2015-08-21 16:28:29,591 DEBUG mrcpv2.Mrcpv2SynthesizedOutput [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: ...passivated output
 [java] 2015-08-21 16:28:29,599 INFO  pool.KeyedResourcePool [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returned object of type 'mrcpv2' (org.jvoicexml.implementation.mrcpv2.Mrcpv2SynthesizedOutput)
 [java] 2015-08-21 16:28:29,604 DEBUG pool.KeyedResourcePool [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: pool has now 0 active/1 idle for key 'mrcpv2' (org.jvoicexml.implementation.mrcpv2.Mrcpv2SynthesizedOutput) after return
 [java] 2015-08-21 16:28:29,612 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returned external resource 'mrcpv2' (org.jvoicexml.implementation.mrcpv2.Mrcpv2SynthesizedOutput) to pool
 [java] 2015-08-21 16:28:29,619 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returned system output of type 'mrcpv2'
 [java] 2015-08-21 16:28:29,625 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: starting returnUserInput...
 [java] 2015-08-21 16:28:29,635 DEBUG jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returning user input of type 'mrcpv2'...
 [java] 2015-08-21 16:28:29,640 DEBUG jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returning external resource 'mrcpv2' (org.jvoicexml.implementation.mrcpv2.Mrcpv2SpokenInput) to pool...
 [java] 2015-08-21 16:28:29,648 DEBUG jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: disconnecting external resource.
 [java] 2015-08-21 16:28:29,656 DEBUG mrcpv2.Mrcpv2SpokenInput [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: Disconnected the spoken input mrcpv2 client form the server
 [java] 2015-08-21 16:28:29,661 DEBUG jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: ...disconnected
 [java] 2015-08-21 16:28:29,666 DEBUG mrcpv2.Mrcpv2SpokenInput [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: passivating input...
 [java] 2015-08-21 16:28:29,673 INFO  pool.KeyedResourcePool [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returned object of type 'mrcpv2' (org.jvoicexml.implementation.mrcpv2.Mrcpv2SpokenInput)
 [java] 2015-08-21 16:28:29,680 DEBUG pool.KeyedResourcePool [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: pool has now 0 active/1 idle for key 'mrcpv2' (org.jvoicexml.implementation.mrcpv2.Mrcpv2SpokenInput) after return
 [java] 2015-08-21 16:28:29,684 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returned external resource 'mrcpv2' (org.jvoicexml.implementation.mrcpv2.Mrcpv2SpokenInput) to pool
 [java] 2015-08-21 16:28:29,692 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returned user input of type 'mrcpv2'
 [java] 2015-08-21 16:28:29,697 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: starting returnCallControl...
 [java] 2015-08-21 16:28:29,702 DEBUG jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returning call control of type 'dummy'...
 [java] 2015-08-21 16:28:29,710 DEBUG jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returning external resource 'dummy' (org.jvoicexml.implementation.jvxml.DummyTelephonySupport) to pool...
 [java] 2015-08-21 16:28:29,715 DEBUG jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: disconnecting external resource.
 [java] 2015-08-21 16:28:29,720 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: telephony connection closed
 [java] 2015-08-21 16:28:29,728 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returnSystemOutput
 [java] 2015-08-21 16:28:29,734 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returnSystemOutput 1
 [java] 2015-08-21 16:28:29,740 DEBUG jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: ...disconnected
 [java] 2015-08-21 16:28:29,751 DEBUG jvxml.DummyTelephonySupport [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: passivated telephony
 [java] 2015-08-21 16:28:29,756 INFO  pool.KeyedResourcePool [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returned object of type 'dummy' (org.jvoicexml.implementation.jvxml.DummyTelephonySupport)
 [java] 2015-08-21 16:28:29,765 DEBUG pool.KeyedResourcePool [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: pool has now 0 active/1 idle for key 'dummy' (org.jvoicexml.implementation.jvxml.DummyTelephonySupport) after return
 [java] 2015-08-21 16:28:29,769 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returned external resource 'dummy' (org.jvoicexml.implementation.jvxml.DummyTelephonySupport) to pool
 [java] 2015-08-21 16:28:29,775 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: returned call control of type 'dummy'
 [java] 2015-08-21 16:28:29,783 INFO  jvxml.JVoiceXmlImplementationPlatform [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: implementation platform closed
 [java] 2015-08-21 16:28:29,792 INFO  scope.ScopeObserver [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: exiting scope 'session'...
 [java] 2015-08-21 16:28:29,798 DEBUG scope.ScopeObserver [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: current scope stack: []
 [java] 2015-08-21 16:28:29,807 INFO  interpreter.JVoiceXmlSession [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: ...session closed
 [java] 2015-08-21 16:28:29,818 DEBUG sip.SipAgent [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: ------------- SENDING A SIP REQUEST ---------------
 [java] Sending a BYE SIP Request
 [java] Content-Length: 0
 [java]
 [java] Via: SIP/2.0/UDP 141.31.8.61:5090;branch=z9hG4bK-373037-fefb07ce5cc947f46528d342f3726752
 [java]
 [java] CSeq: 2 BYE
 [java]
 [java] From: <sip:cairogate@speechforge.org>;tag=175722874
 [java]
 [java] To: <sip:cairo@141.31.8.99>;tag=1107305834
 [java]
 [java] Call-ID: baf97cdc4d99bfbc978a72ffa0c71af0@141.31.8.61
 [java]
 [java] Max-Forwards: 70
 [java]
 [java] No content in the request.
 [java] 2015-08-21 16:28:29,824 DEBUG sip.SipAgent [67b288e4-3fac-4e1d-99f7-97a9b35d00da]: ------------- SENDING A SIP REQUEST ---------------

Discussion


Log in to post a comment.