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.

Sign up for GitHub

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

Jump to bottom

Sometimes one or more processes just get stuck running #44

Open
MichaelLangbein opened this issue Jan 17, 2023 · 3 comments
Open

Sometimes one or more processes just get stuck running #44

MichaelLangbein opened this issue Jan 17, 2023 · 3 comments
Assignees
@MichaelLangbein

Comments

@MichaelLangbein
Copy link
Contributor

This is hard to debug, I'm afraid ...
Sometimes processes will just remain in Running state. The logs for their wrapper or for the wps show nothing notable.

Example: currently, my shakyground process is stuck.

Logs shakyground-wrapper:

async-shakyground_wrapper-1  | order message handler receiver: {"orderId":1}
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,607 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Got new order to handle with wrapper 1
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,608 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Added literal input constraint for shakyground vsgrid: USGSSlopeBasedTopographyProxy
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,608 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Added literal input constraint for shakyground gmpe: MontalvaEtAl2016SInter
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,608 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Added complex input constraint for shakyground quakeMLFile
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,608 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Parsed constraints
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,608 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Define the literal constraints for the jobs
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,608 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Define the complex constraints for the jobs
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,608 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Define the bbox constraints for the jobs
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,608 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Process job
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,610 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Lookup the process id
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,610 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Got the procss id 4
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,611 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Created one job
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,612 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Added literal input for vsgrid: USGSSlopeBasedTopographyProxy
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,612 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Added literal input for gmpe: MontalvaEtAl2016SInter
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,613 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Added complex input (as value) for quakeMLFile
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,613 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Added job to order
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,614 [shakyground-asyncwrapper_new-order_subscription] INFO  AbstractWrapper: Start mapping to wps inputs
async-shakyground_wrapper-1  | 2023-01-17 08:14:43,614 [shakyground-asyncwrapper_new-order_subscription] INFO  org.n52.geoprocessing.wps.client.WPSClientSession: CONNECT
async-shakyground_wrapper-1  | order message handler receiver: {"orderId":1}
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,934 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Got new order to handle with wrapper 1
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,935 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Added literal input constraint for shakyground vsgrid: USGSSlopeBasedTopographyProxy
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,935 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Added literal input constraint for shakyground gmpe: MontalvaEtAl2016SInter
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,935 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Added complex input constraint for shakyground quakeMLFile
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,935 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Parsed constraints
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,935 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Define the literal constraints for the jobs
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,935 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Define the complex constraints for the jobs
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,936 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Define the bbox constraints for the jobs
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,936 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Process job
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,938 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Lookup the process id
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,938 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Got the procss id 4
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,939 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Created one job
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,939 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Added literal input for vsgrid: USGSSlopeBasedTopographyProxy
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,940 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Added literal input for gmpe: MontalvaEtAl2016SInter
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,941 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Added complex input (as value) for quakeMLFile
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,941 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Added job to order
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,942 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  AbstractWrapper: Start mapping to wps inputs
async-shakyground_wrapper-1  | 2023-01-17 08:14:45,942 [shakyground-asyncwrapper_quakeledger-success_subscription] INFO  org.n52.geoprocessing.wps.client.WPSClientSession: CONNECT
async-shakyground_wrapper-1  | 2023-01-17 08:15:34,439 [pulsar-timer-9-1] INFO  org.apache.pulsar.client.impl.ConsumerStatsRecorderImpl: [new-order] [shakyground-asyncwrapper_new-order_subscription] [3f3b9] Prefetched messages: 0 --- Consume throughput received: 0.05 msgs/s --- 0.00 Mbit/s --- Ack sent rate: 0.03 ack/s --- Failed messages: 0 --- batch messages: 0 ---Failed acks: 0
async-shakyground_wrapper-1  | 2023-01-17 08:15:34,441 [pulsar-timer-8-1] INFO  org.apache.pulsar.client.impl.ConsumerStatsRecorderImpl: [quakeledger-success] [shakyground-asyncwrapper_quakeledger-success_subscription] [24cc5] Prefetched messages: 0 --- Consume throughput received: 0.02 msgs/s --- 0.00 Mbit/s --- Ack sent rate: 0.00 ack/s --- Failed messages: 0 --- batch messages: 0 ---Failed acks: 0

Logs wps:

async-riesgos-wps-1  | 17-Jan-2023 07:22:29.727 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
async-riesgos-wps-1  | 17-Jan-2023 07:22:29.736 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in [13611] milliseconds
async-riesgos-wps-1  | 2023-01-17 08:14:43,202 [http-nio-8080-exec-3] WARN  org.n52.wps.server.request.Request: Parameter <language> not found.
async-riesgos-wps-1  | 2023-01-17 08:14:43,202 [http-nio-8080-exec-1] WARN  org.n52.wps.server.request.Request: Parameter <language> not found.
async-riesgos-wps-1  | 2023-01-17 08:14:43,202 [http-nio-8080-exec-2] WARN  org.n52.wps.server.request.Request: Parameter <language> not found.
async-riesgos-wps-1  | 2023-01-17 08:14:43,202 [http-nio-8080-exec-4] WARN  org.n52.wps.server.request.Request: Parameter <language> not found.
async-riesgos-wps-1  | 2023-01-17 08:14:43,203 [http-nio-8080-exec-3] INFO  org.n52.wps.server.request.Request: Handled GetCapabilitiesRequest successfully!
async-riesgos-wps-1  | 2023-01-17 08:14:43,203 [http-nio-8080-exec-1] INFO  org.n52.wps.server.request.Request: Handled GetCapabilitiesRequest successfully!
async-riesgos-wps-1  | 2023-01-17 08:14:43,203 [http-nio-8080-exec-4] INFO  org.n52.wps.server.request.Request: Handled GetCapabilitiesRequest successfully!
async-riesgos-wps-1  | 2023-01-17 08:14:43,203 [http-nio-8080-exec-2] INFO  org.n52.wps.server.request.Request: Handled GetCapabilitiesRequest successfully!
async-riesgos-wps-1  | 2023-01-17 08:14:43,206 [http-nio-8080-exec-2] INFO  org.n52.wps.webapp.util.ResourcePathUtil: Resolved webapp resource'config/wpsCapabilitiesSkeleton.xml' to '/usr/local/tomcat/webapps/wps/config/wpsCapabilitiesSkeleton.xml'
async-riesgos-wps-1  | 2023-01-17 08:14:43,218 [http-nio-8080-exec-2] INFO  org.n52.wps.webapp.util.JDomUtil: /usr/local/tomcat/webapps/wps/config/wpsCapabilitiesSkeleton.xml is parsed and a Document is returned.
async-riesgos-wps-1  | 2023-01-17 08:14:43,220 [http-nio-8080-exec-2] INFO  org.n52.wps.webapp.dao.XmlCapabilitiesDAO: '/usr/local/tomcat/webapps/wps/config/wpsCapabilitiesSkeleton.xml' is parsed and a ServiceIdentification object is returned
async-riesgos-wps-1  | 2023-01-17 08:14:43,220 [http-nio-8080-exec-2] INFO  org.n52.wps.webapp.util.ResourcePathUtil: Resolved webapp resource'config/wpsCapabilitiesSkeleton.xml' to '/usr/local/tomcat/webapps/wps/config/wpsCapabilitiesSkeleton.xml'
async-riesgos-wps-1  | 2023-01-17 08:14:43,221 [http-nio-8080-exec-2] INFO  org.n52.wps.webapp.util.JDomUtil: /usr/local/tomcat/webapps/wps/config/wpsCapabilitiesSkeleton.xml is parsed and a Document is returned.
async-riesgos-wps-1  | 2023-01-17 08:14:43,222 [http-nio-8080-exec-2] INFO  org.n52.wps.webapp.dao.XmlCapabilitiesDAO: '/usr/local/tomcat/webapps/wps/config/wpsCapabilitiesSkeleton.xml' is parsed and a ServiceProvider object is returned
async-riesgos-wps-1  | 2023-01-17 08:14:43,408 [http-nio-8080-exec-5] WARN  org.n52.wps.server.request.Request: Parameter <language> not found.
async-riesgos-wps-1  | 2023-01-17 08:14:43,409 [http-nio-8080-exec-5] INFO  org.n52.wps.server.request.Request: Handled GetCapabilitiesRequest successfully!
async-riesgos-wps-1  | 2023-01-17 08:14:43,472 [http-nio-8080-exec-6] WARN  org.n52.wps.server.request.Request: Parameter <language> not found.
async-riesgos-wps-1  | 2023-01-17 08:14:43,472 [http-nio-8080-exec-6] INFO  org.n52.wps.server.request.Request: Handled GetCapabilitiesRequest successfully!
async-riesgos-wps-1  | 2023-01-17 08:14:43,520 [http-nio-8080-exec-7] WARN  org.n52.wps.server.request.Request: Parameter <language> not found.
async-riesgos-wps-1  | 2023-01-17 08:14:43,520 [http-nio-8080-exec-7] INFO  org.n52.wps.server.request.Request: Handled GetCapabilitiesRequest successfully!
async-riesgos-wps-1  | 2023-01-17 08:14:43,579 [http-nio-8080-exec-8] WARN  org.n52.wps.server.request.Request: Parameter <language> not found.
async-riesgos-wps-1  | 2023-01-17 08:14:43,580 [http-nio-8080-exec-8] INFO  org.n52.wps.server.request.Request: Handled GetCapabilitiesRequest successfully!
async-riesgos-wps-1  | 2023-01-17 08:14:43,586 [http-nio-8080-exec-9] WARN  org.n52.wps.server.request.Request: Parameter <language> not found.
async-riesgos-wps-1  | 2023-01-17 08:14:43,586 [http-nio-8080-exec-9] INFO  org.n52.wps.server.request.Request: Handled GetCapabilitiesRequest successfully!
async-riesgos-wps-1  | 2023-01-17 08:14:43,661 [http-nio-8080-exec-10] WARN  org.n52.wps.server.request.Request: Parameter <language> not found.
async-riesgos-wps-1  | 2023-01-17 08:14:43,661 [http-nio-8080-exec-10] INFO  org.n52.wps.server.request.Request: Handled GetCapabilitiesRequest successfully!
async-riesgos-wps-1  | 2023-01-17 08:14:43,756 [http-nio-8080-exec-3] WARN  org.n52.wps.server.request.Request: Parameter <language> not found.
async-riesgos-wps-1  | 2023-01-17 08:14:43,762 [http-nio-8080-exec-3] INFO  org.n52.wps.server.request.Request: Handled Request successfully for: org.n52.gfz.riesgos.algorithm.impl.QuakeledgerProcess
async-riesgos-wps-1  | 2023-01-17 08:14:43,892 [pool-7-thread-1] INFO  org.n52.wps.commons.context.ExecutionContextFactory: Context registered
async-riesgos-wps-1  | 2023-01-17 08:14:43,900 [pool-7-thread-1] WARN  org.n52.wps.server.request.InputHandler: Could not find class org.n52.gfz.riesgos.algorithm.impl.QuakeledgerProcess
async-riesgos-wps-1  | 2023-01-17 08:14:44,027 [pool-7-thread-1] INFO  org.n52.gfz.riesgos.algorithm.impl.QuakeledgerProcess: Cache-Hash: a32746c8d6107d2763a12b2a3d7ae9cf
async-riesgos-wps-1  | 2023-01-17 08:14:44,027 [pool-7-thread-1] INFO  org.n52.gfz.riesgos.algorithm.impl.QuakeledgerProcess: There is no result in the cache
async-riesgos-wps-1  | 2023-01-17 08:14:45,290 [pool-7-thread-1] INFO  org.n52.wps.server.response.ResponseData: Using generator org.n52.gfz.riesgos.formats.quakeml.generators.QuakeMLValidatedXmlGenerator for Schema: http://quakeml.org/xmlns/quakeml/1.2/QuakeML-1.2.xsd
async-riesgos-wps-1  | 2023-01-17 08:14:45,294 [pool-7-thread-1] INFO  org.n52.wps.server.response.ResponseData: Using generator org.n52.gfz.riesgos.formats.quakeml.generators.QuakeMLGeoJsonGenerator for Schema: null
async-riesgos-wps-1  | 2023-01-17 08:14:45,528 [pool-7-thread-1] INFO  org.n52.wps.commons.context.ExecutionContextFactory: Context unregistered
async-riesgos-wps-1  | 2023-01-17 08:14:45,528 [http-nio-8080-exec-1] INFO  org.n52.wps.server.handler.RequestHandler: Served ExecuteRequest.
async-riesgos-wps-1  | 2023-01-17 08:14:45,873 [http-nio-8080-exec-6] INFO  org.n52.wps.server.RetrieveResultServlet: 42 bytes written in response to id c8c1433e-551f-4cc0-a332-8c7372525ae5selectedRows.5e76b1a9-32b8-47cf-a51e-05ea13fbe50b
async-riesgos-wps-1  | 2023-01-17 08:22:22,201 [FlatFileDatabase File Wiper] INFO  org.n52.wps.server.database.FlatFileDatabase: FlatFileDatabase file wiper, checking /usr/local/tomcat/temp/Database/Results for files older than 604800000 ms
async-riesgos-wps-1  | 2023-01-17 09:22:22,201 [FlatFileDatabase File Wiper] INFO  org.n52.wps.server.database.FlatFileDatabase: FlatFileDatabase file wiper, checking /usr/local/tomcat/temp/Database/Results for files older than 604800000 ms
@MichaelLangbein MichaelLangbein self-assigned this Feb 13, 2023
@MichaelLangbein
Copy link
Contributor Author

@michael: provide reproduction

@nbrinckm
Copy link
Contributor

Seems to be that the wrapper is stuck on checking if the server is already done.

Question here: You used the local wps that is inside the docker-compose right?

@MichaelLangbein
Copy link
Contributor Author

Yes, I did. This issue is from last week, though - things might have changed by now! I'll look out for this error re-surfacing with our current setup.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@MichaelLangbein MichaelLangbein

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@nbrinckm @MichaelLangbein