Project

General

Profile

Actions

Incident #10373

closed

Authorisation service dev and preprod is broken

Added by Massimiliano Assante over 7 years ago. Updated over 7 years ago.

Status:
Closed
Priority:
Urgent
Assignee:
_InfraScience Systems Engineer
Category:
-
Start date:
Nov 21, 2017
Due date:
Nov 21, 2017
% Done:

100%

Estimated time:
Infrastructure:
Development, Pre-Production

Description

according to @roberto.cirillo@isti.cnr.it and @lucio.lelii@isti.cnr.it the issue is in pgpool

Actions #1

Updated by Massimiliano Assante over 7 years ago

  • Is duplicate of Incident #10372: Authorization service: pgpool problem added
Actions #2

Updated by Massimiliano Assante over 7 years ago

  • Status changed from New to Closed
Actions #3

Updated by Massimiliano Assante over 7 years ago

  • Is duplicate of deleted (Incident #10372: Authorization service: pgpool problem)
Actions #4

Updated by Massimiliano Assante over 7 years ago

  • Due date changed from Nov 20, 2017 to Nov 21, 2017
  • Status changed from Closed to In Progress
  • Start date changed from Nov 20, 2017 to Nov 21, 2017

Authorisation service dev and preprod is broken again today

Actions #5

Updated by Andrea Dell'Amico over 7 years ago

Wut. Sorry, my fault. I didn't remove a broken script.

Actions #6

Updated by Andrea Dell'Amico over 7 years ago

Hm. But on one of the servers only. The other one has open connections since yesterday:

postgres 14025  0.0  0.2 104936  4060 ?        S    Nov20   0:00 pgpool: authorization authorization auth-d.dev.d4science.org(42564) idle
postgres 14027  0.0  0.2 106500  5908 ?        S    Nov20   0:04 pgpool: authorization authorization auth-d.dev.d4science.org(42235) idle
postgres 14028  0.0  0.2 104940  4060 ?        S    Nov20   0:01 pgpool: authorization authorization auth-d.dev.d4science.org(42242) idle
postgres 14030  0.0  0.2 104932  4276 ?        S    Nov20   0:02 pgpool: authorization authorization auth-d.dev.d4science.org(42240) idle
postgres 14031  0.0  0.2 104940  4064 ?        S    Nov20   0:08 pgpool: authorization authorization auth-d.dev.d4science.org(42236) idle
postgres 14032  0.0  0.2 104804  4060 ?        S    Nov20   0:01 pgpool: authorization authorization auth-d.dev.d4science.org(42241) idle
postgres 14034  0.0  0.2 104940  4064 ?        S    Nov20   0:04 pgpool: authorization authorization auth-d.dev.d4science.org(42238) idle
postgres 14035  0.0  0.2 104940  4064 ?        S    Nov20   0:03 pgpool: authorization authorization auth-d.dev.d4science.org(42239) idle
postgres 14036  0.0  0.2 104940  4064 ?        S    Nov20   0:05 pgpool: authorization authorization auth-d.dev.d4science.org(42237) idle
Actions #7

Updated by Andrea Dell'Amico over 7 years ago

And I don't see any errors in the authorization logs. Can you give any details?

Actions #8

Updated by Massimiliano Assante over 7 years ago

2017-11-21 11:06:35,997 ERROR o.g.p.t.SmartGearsPortalValve [http-bio-9090-exec-270,invoke:62][PORTAL] 667919079 [http-bio-9090-exec-270] ERROR org.gcube.portal.threadlocalexec.SmartGearsPortalValve - Something went wrong in generating token for mister.orange in scope /gcube/preprod/preVRE
java.net.SocketException: Connection reset
2017-11-21 11:06:35,997 ERROR o.g.p.t.SmartGearsPortalValve [http-bio-9090-exec-257,invoke:62][PORTAL] 667919079 [http-bio-9090-exec-257] ERROR org.gcube.portal.threadlocalexec.SmartGearsPortalValve - Something went wrong in generating token for mister.orange in scope /gcube/preprod/preVRE
    at java.net.SocketInputStream.read(SocketInputStream.java:210)
    at java.net.SocketInputStream.read(SocketInputStream.java:141)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
    at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:735)
    at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:678)
    at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:706)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1569)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1474)
    at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
    at org.gcube.common.authorization.client.proxy.DefaultAuthorizationProxy.resolveTokenByUserAndContext(DefaultAuthorizationProxy.java:136)
    at org.gcube.portal.threadlocalexec.SmartGearsPortalValve.invoke(SmartGearsPortalValve.java:53)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
    at org.apache.catalina.ha.tcp.ReplicationValve.invoke(ReplicationValve.java:333)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:423)
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1079)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:620)
    at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)
java.net.SocketException: Connection reset

Actions #9

Updated by Massimiliano Assante over 7 years ago

The authorisation service is not responding, according to the logs.

2017-11-21 11:08:40,157 ERROR o.g.c.p.PortalContext [http-bio-9090-exec-264,getCurrentUserToken:393][PORTAL] 668043239 [http-bio-9090-exec-264] ERROR org.gcube.common.portal.PortalContext - Error while trying to generate token for user massimiliano.assantein scope /gcube
java.net.SocketException: Connection reset
    at java.net.SocketInputStream.read(SocketInputStream.java:210)
    at java.net.SocketInputStream.read(SocketInputStream.java:141)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
    at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:735)
    at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:678)
    at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:706)

Actions #10

Updated by Massimiliano Assante over 7 years ago

  • % Done changed from 0 to 100

it works now

Actions #11

Updated by Andrea Dell'Amico over 7 years ago

  • % Done changed from 100 to 0

OK, there were a lot of connections from the authorization that were stuck, some lasting 24 hours. I had to kill postgres to get rid of them:

[...]
2017-11-21 12:17:38 CET [21365-3] authorization@authorization FATAL:  terminating connection due to administrator command
2017-11-21 12:17:38 CET [21365-4] authorization@authorization LOG:  disconnection: session time: 2:00:17.162 user=authorization database=authorization host=postgres2-d-d4s.d4science.org port=42645
2017-11-21 12:17:38 CET [16462-3] authorization@authorization FATAL:  terminating connection due to administrator command
2017-11-21 12:17:38 CET [16462-4] authorization@authorization LOG:  disconnection: session time: 8:19:24.323 user=authorization database=authorization host=postgres2-d-d4s.d4science.org port=42629
2017-11-21 12:17:38 CET [10862-3] authorization@authorization FATAL:  terminating connection due to administrator command
2017-11-21 12:17:38 CET [10862-4] authorization@authorization LOG:  disconnection: session time: 9:16:33.511 user=authorization database=authorization host=postgres2-d-d4s.d4science.org port=42611
2017-11-21 12:17:38 CET [7559-3] authorization@authorization FATAL:  terminating connection due to administrator command
2017-11-21 12:17:38 CET [7559-4] authorization@authorization LOG:  disconnection: session time: 9:50:02.203 user=authorization database=authorization host=postgres2-d-d4s.d4science.org port=42601
2017-11-21 12:17:38 CET [17013-3] authorization@authorization FATAL:  terminating connection due to administrator command
2017-11-21 12:17:38 CET [17013-4] authorization@authorization LOG:  disconnection: session time: 24:11:30.680 user=authorization database=authorization host=postgres2-d-d4s.d4science.org port=42592
2017-11-21 12:17:38 CET [17011-3] authorization@authorization FATAL:  terminating connection due to administrator command
2017-11-21 12:17:38 CET [17011-4] authorization@authorization LOG:  disconnection: session time: 24:11:30.722 user=authorization database=authorization host=postgres2-d-d4s.d4science.org port=42588
[...]
Actions #12

Updated by Andrea Dell'Amico over 7 years ago

  • Status changed from In Progress to Feedback
  • % Done changed from 0 to 100
Actions #13

Updated by Massimiliano Assante over 7 years ago

  • Status changed from Feedback to Closed
Actions

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 8.91 MB)