Infrastructure at your Service

Oracle Team

Oracle 12.2 – How to rotate the 12.2 listener log (DIAG_ADR_ENABLED_LISTENER = OFF)

By William Sescu

The listener log file contains a lot of very useful information, like the program which was used for the connection, the IP address where the connection is coming from, the OS user which was used on the client  and many many more.

05-JUN-2017 12:36:19 * service_update * DBIT122 * 0
05-JUN-2017 12:36:19 * (CONNECT_DATA=(SERVICE_NAME=DBIT122_SITE1_DGMGRL)(UR=A)(CID=(PROGRAM=sqlplus@dbidg01)(HOST=dbidg01)(USER=oracle))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.56.201)(PORT=42619)) * establish * DBIT122_SITE1_DGMGRL * 0
05-JUN-2017 12:36:19 * (CONNECT_DATA=(SERVICE_NAME=DBIT122_SITE1_DGMGRL)(UR=A)(CID=(PROGRAM=sqlplus@dbidg01)(HOST=dbidg01)(USER=oracle))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.56.201)(PORT=42620)) * establish * DBIT122_SITE1_DGMGRL * 0

However, it does not contain only successful information; it also shows when connections have been rejected because of TCP.VALIDNODE_CHECKING or any type of TNS errors. So, why not using it for auditing? And what about the performance overhead of listener logging.

Let’s start first with the performance overhead. I am doing 4 types of tests here.

1. Performance with no listener logging (100 connections)
2. Performance with a small listener.log (100 connections)
3. Performance with big listener.log, close to 4G (100 connections)
4. Performance with a full listener.log, exactly 4G (100 connections)

 

Test 1: Performance with no listener logging (100 connections)

oracle@dbidg01:/home/oracle/ [DBIT122] time ./performance_listener.sh
SQLPlus count 1
SQLPlus count 2
...
...
SQLPlus count 99
SQLPlus count 100

real    0m3.360s
user    0m1.065s
sys     0m0.495s

Test 2: Performance with a small listener.log (100 connections)

oracle@dbidg01:/home/oracle/ [DBIT122] time ./performance_listener.sh
SQLPlus count 1
SQLPlus count 2
...
...
SQLPlus count 99
SQLPlus count 100

real    0m3.401s
user    0m1.049s
sys     0m0.511s

Test 3: Performance with big listener.log, close to 4G (100 connections)

oracle@dbidg01:/home/oracle/tmp/ [DBIT122] time ./performance_listener.sh
SQLPlus count 1
SQLPlus count 2
SQLPlus count 3
...
...
SQLPlus count 99
SQLPlus count 100

real    0m3.766s
user    0m1.110s
sys     0m0.522s

Test 4: Performance with a full listener.log, exactly 4G (100 connections)

oracle@dbidg01:/home/oracle/tmp/ [DBIT122] time ./performance_listener.sh
SQLPlus count 1
SQLPlus count 2
SQLPlus count 3
...
...
SQLPlus count 99
SQLPlus count 100

real    0m3.430s
user    0m1.068s
sys     0m0.501s

As you can see in the results, sqlplus connections without listener logging are the fastest one, and the bigger the file gets, the slower the connections are. But wait a second. What’s going on with test 4? As soon as the listener log is full, connections are faster again. The reason for test 4 being faster again, is that the listener is not logging anymore. As soon as it reaches the 4G limit, which is still the case with Oracle 12.2, the listener does not crash like in some older versions beforehand, but the logs are going to /dev/null. So, I will lose all my auditing information for those ones after the 4G limit was reached.

How do we overcome this issue? The answer is to rotate the listener log. But how do we do it? We can’t just simply move the old listener log away and create an empty new one, because the file descriptor is still open and you would create a huge mess.

We could stop the listener, rotate the listener log and start the listener again. A little better, but for the time the listener is stopped, no connection will be possible which is also not a good idea.

From my point of view, the best solution is to stop listener logging online as soon as it hits 1G, rotate the listener log and start listener logging again, like in the following example:

lsnrctl <<-EOF
set current_listener $ListenerName
set log_status off
EOF

mv ${ListenerLogFile} ${ListenerLogFile}.${Date}

lsnrctl <<-EOF
set current_listener $ListenerName
set log_status on
EOF

Now you have the advantage, that the log rotation is an online operation, and you don’t create any mess with open file descriptors. And if you rotate the listener log before it reaches 1G, it is also less likely to run into performance issues.

Conclusion

Take care of your listener log, so that it does not hit the 4G file size limit. You might lose very important information which will not be logged anymore. And do the listener log rotation correctly. ;-)

7 Comments

  • William says:

    Hi, nice post
    Btw is okey for you if i dont need listener logging info for the moment and Do cat /dev/null > listener.log ?

    • William Sescu says:

      If it’s ok for you to lose all the log entries, the current one (4G), and the next one’s, then it is ok.
      In case you run a cat /dev/null on the listener.log, all the next sqlplus sessions will not be logged
      until the listener is restarted.

      oracle@dbidg01:/u01/app/oracle/network/log/ [DBIT122] ls -l listener.log
      -rw-r—– 1 oracle oinstall 4294954507 Jun 5 19:40 listener.log

      oracle@dbidg01:/u01/app/oracle/network/log/ [DBIT122] df -h .
      Filesystem Size Used Avail Use% Mounted on
      /dev/mapper/vg_ora_u01-lv_ora_u01 50G 46G 4.4G 92% /u01

      oracle@dbidg01:/u01/app/oracle/network/log/ [DBIT122] cat /dev/null > listener.log

      oracle@dbidg01:/u01/app/oracle/network/log/ [DBIT122] df -h .
      Filesystem Size Used Avail Use% Mounted on
      /dev/mapper/vg_ora_u01-lv_ora_u01 50G 42G 8.4G 84% /u01

      oracle@dbidg01:/home/oracle/ [DBIT122] ./performance_listener.sh
      SQLPlus count 1
      SQLPlus count 2
      SQLPlus count 3
      SQLPlus count 4
      SQLPlus count 5
      SQLPlus count 6
      SQLPlus count 7
      SQLPlus count 8
      SQLPlus count 9
      SQLPlus count 10

      #– listener log has 0 bytes

      oracle@dbidg01:/u01/app/oracle/network/log/ [DBIT122] ls -l listener.log
      -rw-r—– 1 oracle oinstall 0 Jun 5 19:40 listener.log

  • Foued says:

    Thank you for sharing this post.

  • zhwsh says:

    I use logrotate,I don’t know it exist problem??

    $ cat /etc/logrotate.d/oracle
    /u01/app/11.2.0.4/grid/network/log/listener.log {
    weekly
    rotate 5
    copytruncate
    compress
    notifempty
    missingok
    }

    • William Sescu says:

      I don’t know. I would still prefer my method. What data is in your listener.log.1 or listener.log.2, and from when is it? Is it the one where the copy started, or the copy finished? E.g. copying a 4G listener.log file and zipping it afterwards takes about 2 minutes on my laptop. (About 20 seconds for copying and 130 seconds for a gzip). You are using “copytruncate” and “compress”. Please remember that there is a time slice between copying the file and truncating it. So … some logging data might be lost by doing it with logrotate.

  • Hi,
    if you really wanted to be sure not to loose any connection information (which could be an issue in some security tight companies possibly?), which could happen if your move was a bit slow or your connection rate really intense, or just plain bad luck, you could just point your logfile to a secondary name with lsnrctl set log_file temp_logfile_name, and then you could take all you time to rename the old log file without loosing any information. Then switch back to the old one and add the content of the temp logfile back to the archived one….

    could be useful if the logrotate didn’t work or was forgotten and you ended up with a big file to archive.

Leave a Reply

Oracle Team
Oracle Team