Failed to start portal server after importing data

brady · September 1, 2016, 12:52pm

I am new to discussion board, not sure I am using the right topics name.

I am having problem start portal servers after I imported data. Below is what I did:

I imported index into elastic search with command:

java -Xmx10g -jar dcc-download-import.jar -i release.tar -es es://lxv-icgc-elastic01:9300 -p LAML-CN

untared and copied data.open.tar to hdfs with command on one of hdfs nodes:

hdfs dfs -copyFromLocal /mnt/download01/data.open-untared/release_21 /icgc/input

After these, I restarted portal servers with command:

./bin/dcc-portal-server restart

I got the following error in portal logs. It appears to be config issue, but it is hard to pinpoint to the config issue based on the error messages.

In wrapper.log:

INFO   | jvm 1    | 2016/09/01 05:19:07 | org.springframework.context.ApplicationContextException: Unable to start embedded container; nested exception is org.springframework.boot.context.embedded.EmbeddedServletContainerException: Unable to start embedded Tomcat
INFO   | jvm 1    | 2016/09/01 05:19:07 |       at org.springframework.boot.context.embedded.EmbeddedWebApplicationContext.onRefresh(EmbeddedWebApplicationContext.java:133)
INFO   | jvm 1    | 2016/09/01 05:19:07 |       at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:532)
INFO   | jvm 1    | 2016/09/01 05:19:07 |       at org.springframework.boot.context.embedded.EmbeddedWebApplicationContext.refresh(EmbeddedWebApplicationContext.java:118)
INFO   | jvm 1    | 2016/09/01 05:19:07 |       at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:760)
INFO   | jvm 1    | 2016/09/01 05:19:07 |       at org.springframework.boot.SpringApplication.createAndRefreshContext(SpringApplication.java:360)
INFO   | jvm 1    | 2016/09/01 05:19:07 |       at org.springframework.boot.SpringApplication.run(SpringApplication.java:306)
INFO   | jvm 1    | 2016/09/01 05:19:07 |       at org.springframework.boot.SpringApplication.run(SpringApplication.java:1185)
INFO   | jvm 1    | 2016/09/01 05:19:07 |       at org.springframework.boot.SpringApplication.run(SpringApplication.java:1174)
INFO   | jvm 1    | 2016/09/01 05:19:07 |       at org.icgc.dcc.portal.server.ServerMain.main(ServerMain.java:31)
INFO   | jvm 1    | 2016/09/01 05:19:07 |       at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
INFO   | jvm 1    | 2016/09/01 05:19:07 |       at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
INFO   | jvm 1    | 2016/09/01 05:19:07 |       at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
INFO   | jvm 1    | 2016/09/01 05:19:07 |       at java.lang.reflect.Method.invoke(Method.java:498)
INFO   | jvm 1    | 2016/09/01 05:19:07 |       at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:54)
INFO   | jvm 1    | 2016/09/01 05:19:07 |       at org.springframework.boot.loader.Launcher.launch(Launcher.java:104)

In server.log:

2016-09-01 05:18:57,356 [localhost-startStop-1] INFO  c.h.c.LifecycleService - [localhost]:5701 [dcc-prod] [3.2.3] Address[localhost]:5701 is STARTED
2016-09-01 05:18:58,062 [localhost-startStop-1] WARN  o.o.s.RealmVerifier - RP discovery / realm validation disabled;
2016-09-01 05:19:01,930 [localhost-startStop-1] INFO  o.i.d.p.s.c.SearchConfig - Initializing Elasticsearch Transport Client with settings: {client.transport.sniff=true}
2016-09-01 05:19:02,248 [localhost-startStop-1] INFO  o.e.plugins - [Jean DeWolff] loaded [], sites []
2016-09-01 05:19:06,201 [localhost-startStop-1] INFO  o.i.d.p.s.r.TermsLookupRepository - Checking index 'terms-lookup' for existence...
2016-09-01 05:19:06,213 [localhost-startStop-1] INFO  o.i.d.p.s.r.TermsLookupRepository - Creating index 'terms-lookup'...
2016-09-01 05:19:07,144 [localhost-startStop-1] ERROR o.s.b.c.e.t.TomcatStarter - Error starting Tomcat context: org.springframework.beans.factory.UnsatisfiedDependencyException
2016-09-01 05:19:07,227 [WrapperSimpleAppMain] WARN  o.s.b.c.e.AnnotationConfigEmbeddedWebApplicationContext - Exception encountered during context initialization - cancelling refresh attempt: org.springframework.context.ApplicationContextException: Unable to start embedded container; nested exception is org.springframework.boot.context.embedded.EmbeddedServletContainerException: Unable to start embedded Tomcat
2016-09-01 05:19:07,331 [WrapperSimpleAppMain] INFO  c.h.c.LifecycleService - [localhost]:5701 [dcc-prod] [3.2.3] Address[localhost]:5701 is SHUTTING_DOWN
2016-09-01 05:19:07,435 [WrapperSimpleAppMain] INFO  c.h.initializer - [localhost]:5701 [dcc-prod] [3.2.3] Destroying node initializer.
2016-09-01 05:19:07,437 [WrapperSimpleAppMain] INFO  c.h.instance.Node - [localhost]:5701 [dcc-prod] [3.2.3] Hazelcast Shutdown is completed in 104 ms.
2016-09-01 05:19:07,437 [WrapperSimpleAppMain] INFO  c.h.c.LifecycleService - [localhost]:5701 [dcc-prod] [3.2.3] Address[localhost]:5701 is SHUTDOWN
2016-09-01 05:19:07,454 [WrapperSimpleAppMain] ERROR o.s.b.SpringApplication - Application startup failed
org.springframework.context.ApplicationContextException: Unable to start embedded container; nested exception is org.springframework.boot.context.embedded.EmbeddedServletContainerException: Unable to start embedded Tomcat
        at org.springframework.boot.context.embedded.EmbeddedWebApplicationContext.onRefresh(EmbeddedWebApplicationContext.java:133)
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:532)
        at org.springframework.boot.context.embedded.EmbeddedWebApplicationContext.refresh(EmbeddedWebApplicationContext.java:118)
        at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:760)
        at org.springframework.boot.SpringApplication.createAndRefreshContext(SpringApplication.java:360)
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:306)
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1185)
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1174)
        at org.icgc.dcc.portal.server.ServerMain.main(ServerMain.java:31)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:54)
        at org.springframework.boot.loader.Launcher.launch(Launcher.java:104)
        at org.springframework.boot.loader.Launcher.launch(Launcher.java:61)
        at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:52)
...
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        ... 1 common frames omitted
Caused by: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'resourceConfig' defined in class path resource [org/icgc/dcc/portal/server/config/WebConfig.class]: Unsatisfied dependency expressed through constructor argument with index 1 of type [java.util.Set]: Error creating bean with name 'versionResource' defined in URL [jar:file:/srv/dcc-portal-server-4.3.6-SNAPSHOT/lib/dcc-portal-server.jar!/org/icgc/dcc/portal/server/resource/core/VersionResource.class]: Unsatisfied dependency expressed through constructor argument with index 0 of type [org.icgc.dcc.portal.server.model.Versions]: Error creating bean with name 'versions' defined in class path resource [org/icgc/dcc/portal/server/config/SearchConfig.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.icgc.dcc.portal.server.model.Versions]: Factory method 'versions' threw exception; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'releaseIndexMetadata' defined in class path resource [org/icgc/dcc/portal/server/config/SearchConfig.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.util.Map]: Factory method 'releaseIndexMetadata' threw exception; nested exception is java.util.NoSuchElementException; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'versions' defined in class path resource [org/icgc/dcc/portal/server/config/SearchConfig.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.icgc.dcc.portal.server.model.Versions]: Factory method 'versions' threw exception; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'releaseIndexMetadata' defined in class path resource [org/icgc/dcc/portal/server/config/SearchConfig.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.util.Map]: Factory method 'releaseIndexMetadata' threw exception; nested exception is java.util.NoSuchElementException; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'versionResource' defined in URL [jar:file:/srv/dcc-portal-server-4.3.6-SNAPSHOT/lib/dcc-portal-server.jar!/org/icgc/dcc/portal/server/resource/core/VersionResource.class]: Unsatisfied dependency expressed through constructor argument with index 0 of type [org.icgc.dcc.portal.server.model.Versions]: Error creating bean with name 'versions' defined in class path resource [org/icgc/dcc/portal/server/config/SearchConfig.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.icgc.dcc.portal.server.model.Versions]: Factory method 'versions' threw exception; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'releaseIndexMetadata' defined in class path resource [org/icgc/dcc/portal/server/config/SearchConfig.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.util.Map]: Factory method 'releaseIndexMetadata' threw exception; nested exception is java.util.NoSuchElementException; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'versions' defined in class path resource [org/icgc/dcc/portal/server/config/SearchConfig.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.icgc.dcc.portal.server.model.Versions]: Factory method 'versions' threw exception; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'releaseIndexMetadata' defined in class path resource [org/icgc/dcc/portal/server/config/SearchConfig.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.util.Map]: Factory method 'releaseIndexMetadata' threw exception; nested exception is java.util.NoSuchElementException
        at org.springframework.beans.factory.support.ConstructorResolver.createArgumentArray(ConstructorResolver.java:749)
        at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:464)
...
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'versions' defined in class path resource [org/icgc/dcc/portal/server/config/SearchConfig.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.icgc.dcc.portal.server.model.Versions]: Factory method 'versions' threw exception; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'releaseIndexMetadata' defined in class path resource [org/icgc/dcc/portal/server/config/SearchConfig.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.util.Map]: Factory method 'releaseIndexMetadata' threw exception; nested exception is java.util.NoSuchElementException
        at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:599)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:11

Please take a look. I can upload logs if necessary.

Thanks,

Brady

andricDu · September 1, 2016, 1:43pm

Hi Brady,

What does the elasticsearch portion of the applicaiton.yml look like? The stacktrace seems to suggest that it cannot find an index on the elasticsearch cluster.

Make sure you have set the following seciton to use your cluster and index:

# ElasticSearch index and hosts
elastic:
  indexName: "<your release index name>"
  repoIndexName: ""<repository index name>"
  nodeAddresses:
     - host: "<elasticsearch host>"
       port: 9300
  client:
    "client.transport.sniff": true

brady · September 1, 2016, 1:44pm

Config files and logs can be found at: https://drive.google.com/open?id=0Bxm0mL5Lxsa6enI0UVIxZjZxM0U

brady · September 1, 2016, 1:51pm

Hi Andric,

Thanks for quick reply. Below are the information you have asked:

ElasticSearch index and hosts

elastic:
indexName: icgc21-0-0
nodeAddresses:
- host: lxv-icgc-elastic01
port: 9300

List of TransportClient settings.

E.g.

“client.transport.sniff”: true

client:
“client.transport.sniff”: true

It looks the index is wrong. Vitalii told me to use the following command to delete index after partial import:

curl -XDELETE lxv-icgc-elastic01:9200/icgc21-0-3

So I should use icgc-21-0-3 here. Do you know where I can get this index name?

andricDu · September 1, 2016, 1:55pm

CURL -XGET http://lxv-icgc-elastic01:9200/_cat/indices

That will list your available indices. Make sure you are using one of those.

brady · September 1, 2016, 2:38pm

Thanks for the command.

This is what I got:

curl -XGET http://lxv-icgc-elastic02:9200/_cat/indices
green open .marvel-2016.08.31 1 1 102301 0 434.6mb 217.8mb
green open .marvel-2016.09.01 1 1 69950 0 298.3mb 149.5mb
green open .marvel-2016.08.29 1 1 10277 0 45.6mb 23mb
green open icgc22-13 15 1 55977215 0 27.9gb 13.9gb
green open .marvel-2016.08.30 1 1 86640 0 373.5mb 186.6mb
green open icgc21-0-0 1 1 0 0 230b 115b
green open terms-lookup 1 5 0 0 690b 115b

Looks like I was using wrong one. icgc21-0-0 exists, but its em
pty. I should use icgc22-13. Not sure what thoe .marvel-* are and terms-lookup.

I changed configs, and restarted, now portal servers are up.

However, when I connect to nginx server, I got the following error:

Error 503 Service Unavailable

Service Unavailable

Guru Meditation:

XID: 1825844596

Varnish cache server

I connected to varnish server directly at 5381, got similar error.

varnish server is up:

ps -ef |grep varnish
root 11583 1 0 Aug29 ? 00:00:06 /usr/sbin/varnishd -P /var/run/varnishd.pid -a :5381 -T localhost:5383 -f /etc/varnish/portal.vcl -s malloc,8G
nobody 11584 11583 0 Aug29 ? 00:02:20 /usr/sbin/varnishd -P /var/run/varnishd.pid -a :5381 -T localhost:5383 -f /etc/varnish/portal.vcl -s malloc,8G

sudo varnishlog
0 CLI - Rd ping
0 CLI - Wr 200 19 PONG 1472740205 1.0
0 CLI - Rd ping
0 CLI - Wr 200 19 PONG 1472740208 1.0
0 Backend_health - www1 Still sick 4–X— 0 3 5 0.000000 0.000000
0 Backend_health - www2 Still sick 4–X— 0 3 5 0.000000 0.000000
0 CLI - Rd ping
0 CLI - Wr 200 19 PONG 1472740211 1.0
0 Backend_health - www1 Still sick 4–X— 0 3 5 0.000000 0.000000
0 Backend_health - www2 Still sick 4–X— 0 3 5 0.000000 0.000000
0 CLI - Rd ping
0 CLI - Wr 200 19 PONG 1472740214 1.0
0 CLI - Rd ping
0 CLI - Wr 200 19 PONG 1472740217 1.0
0 Backend_health - www1 Still sick 4–X— 0 3 5 0.000000 0.000000
0 Backend_health - www2 Still sick 4–X— 0 3 5 0.000000 0.000000

It says www1 and www2 are not ok.

Based on varnish server config file /etc/varnish/portal.vcl, it connects to portal server at 8080.

backend www1 {
.host = “lxv-icgc-portal01”;
.port = “8080”;
.probe = {
.url = “/”;
.interval = 5s;
.timeout = 1s;
.window = 5;
.threshold = 3;
}
}

backend www2 {
.host = “lxv-icgc-portal02”;
.port = “8080”;
.probe = {
.url = “/”;
.interval = 5s;
.timeout = 1s;
.window = 5;
.threshold = 3;
}
}

But Port 8080 is open on portal server:

lxv-icgc-varnish01:/etc/varnish$ telnet lxv-icgc-portal01 8080
Trying 10.103.131.11…
Connected to lxv-icgc-portal01.gc01.cgiprod.com.
Escape character is ‘^]’.
^]
telnet> quit
Connection closed.

If I access http://<portal_ip>:8080, browser say there is no data.

It seems to me port server is running but something is wrong on it.

Where should I look at?

andricDu · September 1, 2016, 3:18pm

It might be because we enabled SSL on your portal server if I remember correctly. If so, remove the SSL config because NGINX will be the SSL termination and varnish will want to talk to the portal over the regular http 8080 port.

brady · September 1, 2016, 3:51pm

That is a good guess!

After removing the ssl config, I am able to see the portal.

On initial connection, I got the following error at the top of the page:

Internal Server Error. There was an error processing your request, with the message of 'java.net.ConnectException: Connection refused'. It has been logged (ID 90118348ac37e492). Home Close

I found the following error message in portal server log at /srv/dcc-portal-server/logs:

INFO   | jvm 1    | 2016/09/01 08:37:27 | Caused by: java.net.ConnectException: Connection refused
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at java.net.PlainSocketImpl.socketConnect(Native Method)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at java.net.Socket.connect(Socket.java:589)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at java.net.Socket.connect(Socket.java:538)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at sun.net.NetworkClient.doConnect(NetworkClient.java:180)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at sun.net.www.http.HttpClient.openServer(HttpClient.java:432)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at sun.net.www.http.HttpClient.openServer(HttpClient.java:527)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at sun.net.www.http.HttpClient.<init>(HttpClient.java:211)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at sun.net.www.http.HttpClient.New(HttpClient.java:308)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at sun.net.www.http.HttpClient.New(HttpClient.java:326)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at sun.net.www.protocol.http.HttpURLConnection.getNewHttpClient(HttpURLConnection.java:1169)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at sun.net.www.protocol.http.HttpURLConnection.plainConnect0(HttpURLConnection.java:1105)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:999)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at sun.net.www.protocol.http.HttpURLConnection.connect(HttpURLConnection.java:933)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1513)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1441)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at com.sun.jersey.client.urlconnection.URLConnectionClientHandler._invoke(URLConnectionClientHandler.java:249)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       at com.sun.jersey.client.urlconnection.URLConnectionClientHandler.handle(URLConnectionClientHandler.java:149)
INFO   | jvm 1    | 2016/09/01 08:37:27 |       ... 72 common frames omitted
INFO   | jvm 1    | 2016/09/01 08:37:27 | 2016-09-01 08:37:27,844 [http-nio-8080-exec-2] INFO  o.i.d.c.c.m.Mailer - Mail not enabled. Skipping...
INFO   | jvm 1    | 2016/09/01 08:37:29 | 2016-09-01 08:37:29,276 [http-nio-8080-exec-3] INFO  o.i.d.p.s.r.e.ProjectResource - Request for '100' Project from index '1', sorted by 'totalLiveDonorCount' in 'desc' order with filters '{}'

Seems it tries to connect to a mail server.

When I click on “Data Repository” menu, I got the following error in a yellow banner:

Internal Server Error. Error handling a request: a37215d802b2bca0

I am wondering if I still have wrong data, or some data is not ready.

andricDu · September 1, 2016, 5:45pm

You should double check the download portion of your config and check to see if it is configured to use your provisioned download server.

Also the exception you see when loading the portal for the first ti me might be due to you not having a CUD (central user directory) server to connect to.

brady · September 1, 2016, 10:40pm

Do I need a central CUD server? Since login need to go through icgc.org. Should I point CUD server to it?

I changed the download section to the following:

download:
enabled: true
serverUrl: “http://lxv-icgc-download01:9090”
publicServerUrl: “http://lxv-icgc-download01:9090”
sharedSecret: “deadbeefdeadbeefdeadbeefdeadbeef”
aesKey: “deadbeefdeadbeef”

The problem still exists. Now I realized that I haven’t imported repository.tar.gz. Maybe that is the reason there is no repository. How do I import repository.tar.gz?

btiernay · September 14, 2016, 5:25pm

Hi @brady, you should be able to use the Knapsack Plugin for this. As mentioned in the other thread, this will not be required shortly.

vitalii · September 15, 2016, 2:02pm

@brady I would recommend to re-import the repository.tar.gz archive with the dcc-download-import tool as mentioned in this post. The repository Elasticsearch index should be deleted before re-importorting the data.