Repeated login/logout messages "session opened for user grid by root" in /var/log/secure
(Doc ID 2574495.1)
Last updated on JULY 20, 2024
Applies to:
Oracle Database - Enterprise Edition - Version 12.2.0.1 to 12.2.0.1 [Release 12.2]Linux x86-64
Symptoms
1. On : 12.2.0.1 RAC/Grid environment, repeated log message has been found in node /var/log/secure log:
Aug 27 23:53:18 <node name>sshd[11570]: pam_unix(sshd:session): session opened for user grid by (uid=0)
Aug 27 23:53:18 <node name>sshd[11572]: Received disconnect from <remote node IP>: 11: disconnected by user
Aug 27 23:53:18 <node name>sshd[11570]: pam_unix(sshd:session): session closed for user grid
Aug 27 23:53:21 <node name>sshd[11584]: Accepted publickey for grid from <remote node IP> port 52558 ssh2
Aug 27 23:53:21 <node name>sshd[11584]: pam_unix(sshd:session): session opened for user grid by (uid=0)
Aug 27 23:53:21 <node name>sshd[11586]: Received disconnect from <remote node IP>: 11: disconnected by user
Aug 27 23:53:21 <node name>sshd[11584]: pam_unix(sshd:session): session closed for user grid
Aug 27 23:53:21 <node name>sshd[11608]: Accepted publickey for grid from <remote node IP> port 52559 ssh2
2. In the CVU log files, we can find it try to connect to remote node for tasks:
[Worker 3] [ 2019-08-27 23:53:18.093 EDT ] [RuntimeExec.runCommand:325] RunTimeExec: error>
[Worker 3] [ 2019-08-27 23:53:18.093 EDT ] [RuntimeExec.runCommand:351] Returning from RunTimeExec.runCommand
[Worker 3] [ 2019-08-27 23:53:18.093 EDT ] [NativeSystem.isCmdScv:547] isCmdScv: cmd=[/usr/bin/scp -p /tmp/CVU_12.2.0.1.0_resource/getfileinfoconfigfile_832419608000482185.txt <node name>:'/tmp/CVU_12.2.0.1.0_resource/getfileinfoconfigfile_5625562400889886878.txt']
[Worker 3] [ 2019-08-27 23:53:18.093 EDT ] [NativeSystem.isCmdScv:597] isCmdScv: /usr/bin/scp is present.
[Worker 3] [ 2019-08-27 23:53:18.094 EDT ] [NativeSystem.isCmdScv:599] isCmdScv: /usr/bin/scp is a file.
[Worker 3] [ 2019-08-27 23:53:18.094 EDT ] [NativeSystem.isCmdScv:616] isCmdScv: returned true
[Worker 3] [ 2019-08-27 23:53:18.094 EDT ] [NativeSystem.rununixcmd:1283] NativeSystem.rununixcmd: RetString 1| :successful
[Worker 3] [ 2019-08-27 23:53:18.094 EDT ] [NativeResult.<init>:93] NativeResult: The String obtained is1| :successful
[Worker 3] [ 2019-08-27 23:53:18.094 EDT ] [NativeResult.<init>:101] The status string is: 1
[Worker 3] [ 2019-08-27 23:53:18.094 EDT ] [NativeResult.<init>:114] The result string is: :successful 1
[Worker 3] [ 2019-08-27 23:53:18.094 EDT ] [ClusterConfig$ExecuteCommand.returnCommandToClient:3301] returnCommandToClient; fillCount=1 is full=false
[Worker 3] [ 2019-08-27 23:53:18.094 EDT ] [Semaphore.acquire:109] SyncBufferEmpty:Acquire called by thread Worker 3 m_count=99
[Worker 3] [ 2019-08-27 23:53:18.094 EDT ] [Semaphore.release:85] SyncBufferFull:Release called by thread Worker 3 m_count=2
[Worker 3] [ 2019-08-27 23:53:18.094 EDT ] [ClientResource.getListener:157] Calling getListener
[Worker 3] [ 2019-08-27 23:53:18.094 EDT ] [ClusterConfig$ExecuteCommand.run:3396] Owner Thread name of the blocking Semaphore main
[Worker 3] [ 2019-08-27 23:53:18.094 EDT ] [ClusterConfig$ExecuteCommand.run:3404] Obtained Semaphore
[Worker 3] [ 2019-08-27 23:53:18.095 EDT ] [Semaphore.release:85] ClientResource Constructor:Blocking Semaphore owned by main:Release called by thread Worker 3 m_count=1
[Worker 3] [ 2019-08-27 23:53:18.095 EDT ] [ClusterConfig$ExecuteCommand.run:3419] Released Semaphore by worker=Worker 3
Cause
To view full details, sign in with your My Oracle Support account. |
|
Don't have a My Oracle Support account? Click to get started! |
In this Document
| Symptoms |
| Cause |
| Solution |