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

Logs not available anymore? #23

Closed
acip opened this issue Apr 12, 2018 · 9 comments
Closed

Logs not available anymore? #23

acip opened this issue Apr 12, 2018 · 9 comments

Comments

@acip
Copy link

acip commented Apr 12, 2018 •
edited
Loading

Hi!
Downloading logs returns a 500 HTTP error today. Can you look into it?

Thanks!
Ciprian Amariei
@MichaelRoeder
Copy link

MichaelRoeder commented Apr 12, 2018 •
edited
Loading

That sounds like a problem of the HOBBIT platform itself. Can you please provide the ID of your experiment for which you would like to have the logs?

@acip
Copy link
Author

acip commented Apr 12, 2018 via email

@MichaelRoeder
Copy link

I can confirm that the server answers with HTTP 500 for both benchmark and system because of an internal problem retrieving the logs.

@earthquakesan from the logs of the GUI it looks like the result is empty (or something similar). In Kibana, there are no logs of the system and only two log messages from containers of the benchmark.

2018-04-12 11:15:23.969:WARN:oejs.HttpChannel:qtp758705033-11401: //master.project-hobbit.eu/rest/logs/system/query?id=1523524992970
javax.servlet.ServletException: javax.servlet.ServletException: org.json.JSONException: JSONArray[-1] not found.
	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:139)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
	at org.eclipse.jetty.server.Server.handle(Server.java:534)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:333)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
	at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
	at java.lang.Thread.run(Thread.java:748)
Caused by: 
javax.servlet.ServletException: org.json.JSONException: JSONArray[-1] not found.
	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:489)
	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:848)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1772)
	at org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:205)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
	at de.usu.research.hobbit.gui.util.ConnectionShutdownFilter.doFilter(ConnectionShutdownFilter.java:35)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
	at de.usu.research.hobbit.gui.util.CacheFilter.doFilter(CacheFilter.java:23)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
	at de.usu.research.hobbit.gui.util.CorsFilter.doFilter(CorsFilter.java:40)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1751)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:513)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:213)
	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:119)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
	at org.eclipse.jetty.server.Server.handle(Server.java:534)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:333)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
	at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
	at java.lang.Thread.run(Thread.java:748)
Caused by: 
org.json.JSONException: JSONArray[-1] not found.
	at org.json.JSONArray.get(JSONArray.java:201)
	at org.json.JSONArray.getJSONObject(JSONArray.java:364)
	at de.usu.research.hobbit.gui.rest.LogsResources.getLogsByType(LogsResources.java:194)
	at de.usu.research.hobbit.gui.rest.LogsResources.getSystemLogs(LogsResources.java:163)
	at de.usu.research.hobbit.gui.rest.LogsResources.query(LogsResources.java:151)
	at de.usu.research.hobbit.gui.rest.LogsResources.systemQuery(LogsResources.java:114)
	at sun.reflect.GeneratedMethodAccessor109.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144)
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161)
	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160)
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99)
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389)
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347)
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102)
	at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:267)
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)
	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)
	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)
	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)
	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:848)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1772)
	at org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:205)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
	at de.usu.research.hobbit.gui.util.ConnectionShutdownFilter.doFilter(ConnectionShutdownFilter.java:35)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
	at de.usu.research.hobbit.gui.util.CacheFilter.doFilter(CacheFilter.java:23)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
	at de.usu.research.hobbit.gui.util.CorsFilter.doFilter(CorsFilter.java:40)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1751)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:513)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:213)
	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:119)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
	at org.eclipse.jetty.server.Server.handle(Server.java:534)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:333)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
	at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
	at java.lang.Thread.run(Thread.java:748)

However, the platform controller logged that the experiment was executed without problems

2018-04-12 09:23:12,970 INFO [org.hobbit.controller.PlatformController] - <Adding experiment 1523524992970 with benchmark http://project-hobbit.eu/sml-benchmark-v2/benchmark, system http://project-hobbit.eu/resources/gc2018/test/debsparrotsystemexample and user XXX to the queue.>
2018-04-12 09:23:15,616 INFO [org.hobbit.controller.ExperimentManager] - <Creating next experiment 1523524992970 with benchmark http://project-hobbit.eu/sml-benchmark-v2/benchmark and system http://project-hobbit.eu/resources/gc2018/test/debsparrotsystemexample to the queue.>
2018-04-12 09:23:47,054 INFO [org.hobbit.controller.data.ExperimentStatus] - <Creating abort timer for http://w3id.org/hobbit/experiments#1523524992970 with 1200000ms.>
2018-04-12 09:24:06,433 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=DOCKER_CONTAINER_START>
2018-04-12 09:24:24,864 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=SYSTEM_READY_SIGNAL>
2018-04-12 09:24:24,875 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=DOCKER_CONTAINER_START>
2018-04-12 09:24:43,810 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=DATA_GENERATOR_READY_SIGNAL>
2018-04-12 09:24:43,948 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=DOCKER_CONTAINER_START>
2018-04-12 09:25:02,249 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=TASK_GENERATOR_READY_SIGNAL>
2018-04-12 09:25:02,324 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=EVAL_STORAGE_READY_SIGNAL>
2018-04-12 09:25:02,333 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=BENCHMARK_READY_SIGNAL>
2018-04-12 09:25:02,419 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=START_BENCHMARK_SIGNAL>
2018-04-12 09:25:02,422 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=TASK_GENERATOR_START_SIGNAL>
2018-04-12 09:25:02,423 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=DATA_GENERATOR_START_SIGNAL>
2018-04-12 09:25:09,999 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=DATA_GENERATION_FINISHED>
2018-04-12 09:25:15,021 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=TASK_GENERATION_FINISHED>
2018-04-12 09:25:20,118 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=EVAL_STORAGE_TERMINATE>
2018-04-12 09:25:20,120 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=EVAL_MODULE_READY_SIGNAL>
2018-04-12 09:25:20,921 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=EVAL_MODULE_FINISHED_SIGNAL>
2018-04-12 09:25:20,922 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=DOCKER_CONTAINER_TERMINATED>
2018-04-12 09:25:25,006 INFO [org.hobbit.controller.PlatformController] - <received command: session=1523524992970, command=BENCHMARK_FINISHED_SIGNAL>
2018-04-12 09:25:29,998 INFO [org.hobbit.controller.ExperimentManager] - <Benchmark terminated. Experiment 1523524992970 has been finished. Removing it from the queue and setting the config to null.>

@MichaelRoeder
Copy link

@acip an earlier run of your system created more than 400,000 log messages. It would be nice if you could reduce the number of log messages the system produces 😉

@earthquakesan
Copy link
Member

@MichaelRoeder It throws because the result set is empty. I will make a check for this.

Another issue is that the containers do not write logs to ELK.

@acip
Copy link
Author

acip commented Apr 12, 2018

@MichaelRoeder Indeed, that slipped in production :) We'll double check to prevent that from happening.

@clin99
Copy link

clin99 commented Apr 16, 2018

@MichaelRoeder Is the problem solved? We try to download the System log today and also get 500 HTTP error. Could you please take a look into this?

Thanks.

@MichaelRoeder
Copy link

We are facing a mixture of two problems. The first issue is already solved by @earthquakesan and he is currently working on the second issue.

@MichaelRoeder
Copy link

The problems regarding logging should be solved now in the new platform version.

Please note that logs > 500.000 lines won't be retrieved anymore.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@earthquakesan @acip @MichaelRoeder @clin99