Thursday, March 18, 2021

Login storm on Oracle?

Recently have customer complain that there was problem with connections to one oracle the database and if we can check if there was a "listener storm". I will not explain what this is or how this impact the system, as you can google that almost anywhere.
I will focus how to efficiently check this claim. As listener in this case had 7,7 GB, it was very hard to make any unoptimized asks against it. Here is what I do. First check day (if you do not know exact time), lister.log is default name (change it in your particular case to relevant listener name if needed).
So I moved my focus to 14-MAR-2021, when problems seems to happened (according customer claim), and see logins by hour (summary):
fgrep "14-MAR-2021"     listener.log | fgrep "establish" | awk '{ print $1 " " $2 }' | awk -F: '{ print $1 }'        | sort | uniq -c
1392 14-MAR-2021 00
1376 14-MAR-2021 01
1340 14-MAR-2021 02
1388 14-MAR-2021 03
1411 14-MAR-2021 04
1394 14-MAR-2021 05
1817 14-MAR-2021 06
1503 14-MAR-2021 07
1580 14-MAR-2021 08
1653 14-MAR-2021 09
1742 14-MAR-2021 10    <---will take this hour for further analyze
1769 14-MAR-2021 11
1648 14-MAR-2021 12
1643 14-MAR-2021 13
1677 14-MAR-2021 14
1675 14-MAR-2021 15
1681 14-MAR-2021 16
1750 14-MAR-2021 17
1700 14-MAR-2021 18
1875 14-MAR-2021 19
3336 14-MAR-2021 20
2478 14-MAR-2021 21
1512 14-MAR-2021 22
1474 14-MAR-2021 23

Then check listener.log for that day if there were any erros in that period. In my case there were none, so I moved my focus to 14-MARCH, 10 o'clock time. So here is chosen hour by minutes :
fgrep "14-MAR-2021 10:" listener.log | fgrep "establish" | awk '{ print $1 " " $2 }' | awk -F: '{ print $1 ":" $2 }' | sort | uniq -c
  29 14-MAR-2021 10:00
  38 14-MAR-2021 10:01
  28 14-MAR-2021 10:02
  28 14-MAR-2021 10:03
  28 14-MAR-2021 10:04
  28 14-MAR-2021 10:05
  36 14-MAR-2021 10:06
  35 14-MAR-2021 10:07
  26 14-MAR-2021 10:08
  22 14-MAR-2021 10:09
  32 14-MAR-2021 10:10
  43 14-MAR-2021 10:11
  23 14-MAR-2021 10:12
  33 14-MAR-2021 10:13
  39 14-MAR-2021 10:14            <---will take this minute for further analyze
  25 14-MAR-2021 10:15
  26 14-MAR-2021 10:16
  34 14-MAR-2021 10:17
  29 14-MAR-2021 10:18
  19 14-MAR-2021 10:19
  22 14-MAR-2021 10:20
  50 14-MAR-2021 10:21
  30 14-MAR-2021 10:22
  23 14-MAR-2021 10:23
  24 14-MAR-2021 10:24
  28 14-MAR-2021 10:25
  31 14-MAR-2021 10:26
  24 14-MAR-2021 10:27
  32 14-MAR-2021 10:28
  20 14-MAR-2021 10:29
  29 14-MAR-2021 10:30
  37 14-MAR-2021 10:31
  31 14-MAR-2021 10:32
  24 14-MAR-2021 10:33
  18 14-MAR-2021 10:34
  23 14-MAR-2021 10:35
  37 14-MAR-2021 10:36
  33 14-MAR-2021 10:37
  35 14-MAR-2021 10:38
  24 14-MAR-2021 10:39
  32 14-MAR-2021 10:40
  40 14-MAR-2021 10:41
  26 14-MAR-2021 10:42
  30 14-MAR-2021 10:43
  32 14-MAR-2021 10:44
  30 14-MAR-2021 10:45
  21 14-MAR-2021 10:46
  27 14-MAR-2021 10:47
  27 14-MAR-2021 10:48
  21 14-MAR-2021 10:49
  32 14-MAR-2021 10:50
  45 14-MAR-2021 10:51
  27 14-MAR-2021 10:52
  27 14-MAR-2021 10:53
  22 14-MAR-2021 10:54
  26 14-MAR-2021 10:55
  33 14-MAR-2021 10:56
  17 14-MAR-2021 10:57
  27 14-MAR-2021 10:58
  24 14-MAR-2021 10:59
----
1742

Similar but grouped one by minute, you can get with:
fgrep "14-MAR-2021 10:14:" listener.log | fgrep "establish" | awk '{ print $1 " " $2 }' | awk -F: '{ print $1 ":" $2 }' | sort | uniq -c
  39 14-MAR-2021 10:14

And finally, the most important one is login by seconds, as this really shows if there were any problematic tresholds:
fgrep "14-MAR-2021 10:14:" listener.log | fgrep "establish" | awk '{ print $1 " " $2 }' | awk -F: '{ print $1 ":" $2":"$3 }'  | sort | uniq -c
   3 14-MAR-2021 10:14:01
   1 14-MAR-2021 10:14:04
   1 14-MAR-2021 10:14:07
   7 14-MAR-2021 10:14:14
   1 14-MAR-2021 10:14:16
   1 14-MAR-2021 10:14:20
   1 14-MAR-2021 10:14:27
   1 14-MAR-2021 10:14:29
   1 14-MAR-2021 10:14:34
   1 14-MAR-2021 10:14:43
   1 14-MAR-2021 10:14:44
   1 14-MAR-2021 10:14:47
   2 14-MAR-2021 10:14:50
   1 14-MAR-2021 10:14:55
   1 14-MAR-2021 10:14:56
   7 14-MAR-2021 10:14:57
   8 14-MAR-2021 10:14:59
----
  39

So there was no login storm!

Hope this helps someone.

Cheers!

1 comment:

  1. Also if you need to see several lines before and after some greped patter you can get (on Linux):

    grep -B 3 -A 2 error listener.log

    and result is (just last part showed:
    TNS-12592: TNS:bad packet
    20-OCT-2021 23:39:35 * (ADDRESS=(PROTOCOL=tcp)(HOST=10.89.200.5)(PORT=37298)) * * 12547
    TNS-12547: TNS:lost contact
    TNS-12560: TNS:protocol adapter error
    TNS-00517: Lost contact
    Linux Error: 104: Connection reset by peer
    --
    2021-10-20T23:39:49.632038+02:00
    20-OCT-2021 23:39:49 * (ADDRESS=(PROTOCOL=tcp)(HOST=10.89.200.5)(PORT=33216)) * * 12547
    TNS-12547: TNS:lost contact
    TNS-12560: TNS:protocol adapter error
    TNS-00517: Lost contact
    Linux Error: 104: Connection reset by peer
    --
    2021-10-20T23:46:17.243599+02:00
    20-OCT-2021 23:46:17 * (ADDRESS=(PROTOCOL=tcp)(HOST=10.89.200.5)(PORT=54108)) * * 12547
    TNS-12547: TNS:lost contact
    TNS-12560: TNS:protocol adapter error
    TNS-00517: Lost contact
    Linux Error: 104: Connection reset by peer

    ReplyDelete