Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

With the transaction timeout set unresonably low. a resulting error due to timeout does not reflect a timeout #2149

Closed
d0roppe opened this issue Mar 25, 2021 · 4 comments
Labels
bug Something isn't working

Comments

@d0roppe
Copy link
Collaborator

d0roppe commented Mar 25, 2021

Describe the bug
A clear and concise description of what the bug is.
If you set the transaction timeout to something unreasonable like 2 seconds. this causes errors to happen that were not expected, and the reported error is not reflective of the fact you hit the transaction timeout.
To Reproduce
Steps to reproduce the behavior:

  1. Go to '...'
  2. Click on '....'
  3. Scroll down to '....'
  4. See error

Expected behavior
A clear and concise description of what you expected to happen.
Either have a reasonable minimum transaction timeout and a lower value is ignored with a log message at startup. Or always report errors related to transaction timeout as timeout errors.
Additional context
Add any other context about the problem here.

@d0roppe
Copy link
Collaborator Author

d0roppe commented Mar 29, 2021

message from FHIR:
{
"resourceType": "OperationOutcome",
"id": "ac-11-7d-a6-25236f29-e37f-434d-a6ea-50cabacdd9ad",
"issue": [{
"severity": "error",
"code": "exception",
"diagnostics": "Server Side Error for Batch Framework"
}]
}

Here is from the log:
bootstrap.sh - [INFO]: 2021-03-25_17:14:46 - Current directory: /opt/ibm-fhir-server
bootstrap.sh - [INFO]: 2021-03-25_17:14:46 - Skipping Derby database bootstrapping
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"Launching fhir-server (Open Liberty 21.0.0.1/wlp-1.0.48.cl210120210113-1459) on Eclipse OpenJ9 VM, version 1.8.0_282-b08 (en_US)","ibm_datetime":"2021-03-25T17:14:47.371+0000","ibm_sequence":"1616692487373_0000000000001"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"CWWKE0001I: The server fhir-server has been launched.","ibm_threadId":"00000001","ibm_datetime":"2021-03-25T17:14:47.551+0000","ibm_messageId":"CWWKE0001I","module":"com.ibm.ws.kernel.launch.internal.FrameworkManager","level":"AUDIT","ibm_sequence":"1616692487551_0000000000001"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"CWWKG0093A: Processing configuration drop-ins resource: /opt/ol/wlp/usr/servers/fhir-server/configDropins/defaults/bulkdata.xml","ibm_threadId":"0000001f","ibm_datetime":"2021-03-25T17:14:50.446+0000","ibm_messageId":"CWWKG0093A","module":"com.ibm.ws.config.xml.internal.ServerXMLConfiguration","level":"AUDIT","ibm_sequence":"1616692490446_0000000000002"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"CWWKG0093A: Processing configuration drop-ins resource: /opt/ol/wlp/usr/servers/fhir-server/configDropins/defaults/datasource.xml","ibm_threadId":"0000001f","ibm_datetime":"2021-03-25T17:14:50.495+0000","ibm_messageId":"CWWKG0093A","module":"com.ibm.ws.config.xml.internal.ServerXMLConfiguration","level":"AUDIT","ibm_sequence":"1616692490495_0000000000003"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"CWWKG0093A: Processing configuration drop-ins resource: /opt/ol/wlp/usr/servers/fhir-server/configDropins/defaults/host.xml","ibm_threadId":"0000001f","ibm_datetime":"2021-03-25T17:14:50.505+0000","ibm_messageId":"CWWKG0093A","module":"com.ibm.ws.config.xml.internal.ServerXMLConfiguration","level":"AUDIT","ibm_sequence":"1616692490505_0000000000004"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"CWWKG0093A: Processing configuration drop-ins resource: /opt/ol/wlp/usr/servers/fhir-server/configDropins/defaults/keystore.xml","ibm_threadId":"0000001f","ibm_datetime":"2021-03-25T17:14:50.509+0000","ibm_messageId":"CWWKG0093A","module":"com.ibm.ws.config.xml.internal.ServerXMLConfiguration","level":"AUDIT","ibm_sequence":"1616692490509_0000000000005"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"CWWKG0093A: Processing configuration drop-ins resource: /opt/ol/wlp/usr/servers/fhir-server/configDropins/defaults/openapi.xml","ibm_threadId":"0000001f","ibm_datetime":"2021-03-25T17:14:50.512+0000","ibm_messageId":"CWWKG0093A","module":"com.ibm.ws.config.xml.internal.ServerXMLConfiguration","level":"AUDIT","ibm_sequence":"1616692490512_0000000000006"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"CWWKG0093A: Processing configuration drop-ins resource: /opt/ol/wlp/usr/servers/fhir-server/configDropins/defaults/transaction-manager.xml","ibm_threadId":"0000001f","ibm_datetime":"2021-03-25T17:14:50.516+0000","ibm_messageId":"CWWKG0093A","module":"com.ibm.ws.config.xml.internal.ServerXMLConfiguration","level":"AUDIT","ibm_sequence":"1616692490516_0000000000007"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"CWWKG0093A: Processing configuration drop-ins resource: /opt/ol/wlp/usr/servers/fhir-server/configDropins/overrides/trustDefault.xml","ibm_threadId":"0000001f","ibm_datetime":"2021-03-25T17:14:50.561+0000","ibm_messageId":"CWWKG0093A","module":"com.ibm.ws.config.xml.internal.ServerXMLConfiguration","level":"AUDIT","ibm_sequence":"1616692490561_0000000000008"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"CWWKZ0058I: Monitoring dropins for applications.","ibm_threadId":"00000037","ibm_datetime":"2021-03-25T17:15:03.081+0000","ibm_messageId":"CWWKZ0058I","module":"com.ibm.ws.app.manager.internal.monitor.DropinMonitor","level":"AUDIT","ibm_sequence":"1616692503081_000000000000D"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"CWWKT0016I: Web application available (default_host): https://uffdaonfhir-5f94ffcbb7-vmlm6:9443/ibm/api/","ibm_threadId":"0000002f","ibm_datetime":"2021-03-25T17:15:07.961+0000","ibm_messageId":"CWWKT0016I","module":"com.ibm.ws.http.internal.VirtualHostImpl","level":"AUDIT","ibm_sequence":"1616692507961_000000000002C"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"CWWKT0016I: Web application available (default_host): https://uffdaonfhir-5f94ffcbb7-vmlm6:9443/jwt/","ibm_threadId":"0000002d","ibm_datetime":"2021-03-25T17:15:07.984+0000","ibm_messageId":"CWWKT0016I","module":"com.ibm.ws.http.internal.VirtualHostImpl","level":"AUDIT","ibm_sequence":"1616692507984_000000000002D"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"SRVE9967W: The manifest class path jaxb-core.jar can not be found in jar file file:/opt/ol/wlp/usr/servers/fhir-server/apps/expanded/fhir-bulkdata-webapp.war/WEB-INF/lib/jaxb-impl-2.3.0.jar or its parent.","ibm_threadId":"0000002a","ibm_datetime":"2021-03-25T17:15:09.489+0000","ibm_messageId":"SRVE9967W","module":"com.ibm.ws.container.service.app.deploy.ManifestClassPathUtils","level":"WARNING","ibm_sequence":"1616692509489_0000000000034"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"SRVE9967W: The manifest class path jaxb-api.jar can not be found in jar file file:/opt/ol/wlp/usr/servers/fhir-server/apps/expanded/fhir-bulkdata-webapp.war/WEB-INF/lib/jaxb-core-2.3.0.jar or its parent.","ibm_threadId":"0000002a","ibm_datetime":"2021-03-25T17:15:09.535+0000","ibm_messageId":"SRVE9967W","module":"com.ibm.ws.container.service.app.deploy.ManifestClassPathUtils","level":"WARNING","ibm_sequence":"1616692509535_0000000000035"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"CWWKS4104A: LTPA keys created in 6.369 seconds. LTPA key file: /opt/ol/wlp/usr/servers/fhir-server/resources/security/ltpa.keys","ibm_threadId":"0000002e","ibm_datetime":"2021-03-25T17:15:10.713+0000","ibm_messageId":"CWWKS4104A","module":"com.ibm.ws.security.token.ltpa.LTPAKeyInfoManager","level":"AUDIT","ibm_sequence":"1616692510713_0000000000037"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"SRVE9967W: The manifest class path jaxb-core.jar can not be found in jar file file:/opt/ol/wlp/usr/servers/fhir-server/apps/expanded/fhir-bulkdata-webapp.war/WEB-INF/lib/jaxb-impl-2.3.0.jar or its parent.","ibm_threadId":"0000002a","ibm_datetime":"2021-03-25T17:15:10.812+0000","ibm_messageId":"SRVE9967W","module":"com.ibm.ws.container.service.app.deploy.ManifestClassPathUtils","level":"WARNING","ibm_sequence":"1616692510812_000000000003A"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"SRVE9967W: The manifest class path jaxb-api.jar can not be found in jar file file:/opt/ol/wlp/usr/servers/fhir-server/apps/expanded/fhir-bulkdata-webapp.war/WEB-INF/lib/jaxb-core-2.3.0.jar or its parent.","ibm_threadId":"0000002a","ibm_datetime":"2021-03-25T17:15:10.821+0000","ibm_messageId":"SRVE9967W","module":"com.ibm.ws.container.service.app.deploy.ManifestClassPathUtils","level":"WARNING","ibm_sequence":"1616692510821_000000000003B"}
{"type":"liberty_message","host":"uffdaonfhir-5f94ffcbb7-vmlm6","ibm_userDir":"/opt/ol/wlp/usr/","ibm_serverName":"fhir-server","message":"CWWKT0016I: Web application available (default_host): https://uffdaonfhir-5f94ffcbb7-vmlm6:94...

@lmsurpre
Copy link
Member

I added a stack trace of what this should look like at #2150 (comment)

@d0roppe
Copy link
Collaborator Author

d0roppe commented Apr 23, 2021

Re-tested this with the latest code with both 2 and 1 second timeout, and the error in the joblog is:
[4/23/21, 19:54:09:615 UTC] 0000008a com.ibm.tx.jta.embeddable.impl.EmbeddableTimeoutManager I WTRN0124I: When the timeout occurred the thread with which the transaction is, or was most recently, associated was Thread[Default Executor-thread-4,5,Default Executor Thread Group]. The stack trace of this thread when the timeout occurred was:
org.eclipse.osgi.internal.loader.classpath.ClasspathManager.findLocalClass(ClasspathManager.java:569)
org.eclipse.osgi.internal.loader.ModuleClassLoader.findLocalClass(ModuleClassLoader.java:346)

@d0roppe
Copy link
Collaborator Author

d0roppe commented Apr 26, 2021

Closing issue as the new timeout message is OK for figuring out that you have timed out.

@d0roppe d0roppe closed this as completed Apr 26, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants