[OPENAM-7864] Failure to connect to syslog server can cause OpenAM to hang - ForgeRock JIRA

Details

Type: Bug
Status: Resolved
Priority: Critical
Resolution: Fixed
Affects Version/s: 12.0.0, 12.0.1, 12.0.2
Fix Version/s: 12.0.3, 13.5.0
Component/s: audit logging
Labels:
Environment:

Hide
CentOS Linux release 7.0.1406 (Core)
3.10.0-123.9.3.el7.x86_64 #1 SMP Thu Nov 6 15:06:03 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux

java version "1.7.0_75"
Java(TM) SE Runtime Environment (build 1.7.0_75-b13)
Java HotSpot(TM) 64-Bit Server VM (build 24.75-b04, mixed mode)

Show
CentOS Linux release 7.0.1406 (Core) 3.10.0-123.9.3.el7.x86_64 #1 SMP Thu Nov 6 15:06:03 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux java version "1.7.0_75" Java(TM) SE Runtime Environment (build 1.7.0_75-b13) Java HotSpot(TM) 64-Bit Server VM (build 24.75-b04, mixed mode)

Target Version/s:

12.0.3, 13.5.0

Sprint:
AM Sustaining Sprint 16, AM Sustaining Sprint 17, AM Sustaining Sprint 18

Support Ticket IDs:

Verified Version/s:

12.0.3, 13.5.0

Description

When audit logging to a remote syslog server, in some circumstances OpenAM can become unresponsive. Login via console or ssoadm will not work.

Steps to reproduce:

1. Configure audit logging to use remote syslog over UDP and confirm it's working.
2. Bring up a firewall on the syslog host which blocks all requests from OpenAM, regardless of protocol.
3. Configure audit logging to use TCP and submit more requests against OpenAM, such as authentications. Observer audit logging failures.
4. Switch protocol back to UDP and test OpenAM for responsiveness.

It appears OpenAM gets blocked on TCP timeouts, though generally only when the protocol for audit logging is switched between TCP/UDP.

Workarounds:

Only use one protocol for remote syslog connections.
If the protocol must be changed, don't change when the remote syslog server is unavailable.
Reduce the value of 'Syslog connection timeout'.

Jstack output:

"http-bio-8080-exec-92" daemon prio=10 tid=0x00007f7b4da72800 nid=0x2ad4 waiting for monitor entry [0x00007f7b409a9000]      java.lang.Thread.State: BLOCKED (on object monitor)      at org.forgerock.openam.log.handlers.syslog.SyslogHandler.publish(SyslogHandler.java:143)      - waiting to lock <0x00000000b4ba7eb0> (a org.forgerock.openam.log.handlers.syslog.SyslogHandler)      at java.util.logging.Logger.log(Logger.java:616)      at com.sun.identity.log.Logger.writeToLog(Logger.java:399)      at com.sun.identity.log.Logger.log(Logger.java:383)      at com.sun.identity.authentication.service.AuthD.logIt(AuthD.java:831)      at com.sun.identity.authentication.service.LoginState.logSuccess(LoginState.java:4800)      at com.sun.identity.authentication.service.AMLoginContext.runLogin(AMLoginContext.java:623)      at com.sun.identity.authentication.server.AuthContextLocal.submitRequirements(AuthContextLocal.java:699)      at org.forgerock.openam.forgerockrest.authn.core.wrappers.AuthContextLocalWrapper.submitRequirements(AuthContextLocalWrapper.java:114)      at org.forgerock.openam.forgerockrest.authn.core.LoginProcess.next(LoginProcess.java:171)      at org.forgerock.openam.forgerockrest.authn.RestAuthenticationHandler.processAuthentication(RestAuthenticationHandler.java:250)      at org.forgerock.openam.forgerockrest.authn.RestAuthenticationHandler.authenticate(RestAuthenticationHandler.java:160)      at org.forgerock.openam.forgerockrest.authn.RestAuthenticationHandler.initiateAuthentication(RestAuthenticationHandler.java:93)      at org.forgerock.openam.forgerockrest.authn.restlet.AuthenticationServiceV1.authenticate(AuthenticationServiceV1.java:133)      at

"SystemTimer" prio=10 tid=0x00007f7b4c3a4800 nid=0x29f3 runnable [0x00007f7b431f0000]      java.lang.Thread.State: RUNNABLE      at java.net.PlainSocketImpl.socketConnect(Native Method)      at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)      - locked <
0x00000000b79531d0> (a java.net.SocksSocketImpl)      at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)      at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)      at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)      at java.net.Socket.connect(Socket.java:579)      at org.forgerock.openam.log.handlers.syslog.SyslogTcpPublisher.connect(SyslogTcpPublisher.java:65)      at org.forgerock.openam.log.handlers.syslog.SyslogTcpPublisher.reconnect(SyslogTcpPublisher.java:59)      at org.forgerock.openam.log.handlers.syslog.SyslogPublisher.publishLogRecords(SyslogPublisher.java:54)      at org.forgerock.openam.log.handlers.syslog.SyslogHandler$FlushTask.run(SyslogHandler.java:201)      - locked <
0x00000000b4ba7f00> (a java.lang.Object)      at org.forgerock.openam.log.handlers.syslog.SyslogHandler.flush(SyslogHandler.java:102)      - locked <
0x00000000b4ba7eb0> (a org.forgerock.openam.log.handlers.syslog.SyslogHandler)      at org.forgerock.openam.log.handlers.syslog.SyslogHandler$TimeBufferingTask.run(SyslogHandler.java:219)      at com.sun.identity.common.TimerPool$WorkerThread.run(TimerPool.java:434)

Attachments

Issue Links

relates to

CAUD-428 Logging to Syslog stop logging when host unresolvable

Open

OPENAM-11957 AM becomes unresponsive when audit logging to syslog with TCP

Open

Activity

People

Assignee:

Peter Major [X] (Inactive)

Reporter:

Andrew Dunn [X] (Inactive)

QA Assignee:

Filip Kubáň [X] (Inactive)

Votes:

0 Vote for this issue

Watchers:

5 Start watching this issue

Dates

Created:

14/Dec/15 12:55 PM

Updated:

08/Mar/18 1:21 PM

Resolved:

25/Feb/16 9:04 AM

Time Tracking

Estimated:

Remaining:

Logged: