Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

logconv.pl does not correctly show "Peak Concurrent Connections" after log format changes in 389ds v2.1 #5640

Closed
aivanov389 opened this issue Feb 8, 2023 · 4 comments
Assignees
Labels
needs triage The issue will be triaged during scrum
Milestone

Comments

@aivanov389
Copy link

aivanov389 commented Feb 8, 2023

Issue Description
logconv.pl does not correctly show "Peak Concurrent Connections" after log format changes in #5029 . It does not detect correctly the "Disconnect - Cleanly Closed Connection - U1" string used now in logs instead of "closed error - U1".

Steps to Reproduce
Steps to reproduce the behavior:

  1. Install 389ds server with minimal activity
  2. logconv.pl /.../access

Expected results
The number of "Peak Concurrent Connections" should be minimal for a low-activity server. logconv.pl insteads shows a huge number since it considers all the opened connections in access log as concurrent. The reason is the incorrect way to detect when they are closed.

How to Fix
One of the possibilities is to make the "connection closed" event detection case-insensitive.

@@ -2249,7 +2249,7 @@
                $fdTaken++;
                if ($1 > $highestFdTaken){ $highestFdTaken = $1; }
        }
-       if (m/ fd=/ && m/closed/){
+       if (m/ fd=/ && m/closed/i){
                ($connID) = $_ =~ /conn=(\d*)\s/;
                handleConnClose($connID);

There may be other side effects since in #5029 the word "closed" was replaced by "Disconnect"

@aivanov389 aivanov389 added the needs triage The issue will be triaged during scrum label Feb 8, 2023
@mreynolds389 mreynolds389 self-assigned this Feb 13, 2023
mreynolds389 added a commit to mreynolds389/389-ds-base that referenced this issue Feb 14, 2023
Description:  Some of the "closed" m,essages inteh access log are now a mixed
case, and logconv should be able to process it.

relates: 389ds#5640

Reviewed by: jchapman & tbordaz (Thanks!!)
mreynolds389 added a commit that referenced this issue Feb 14, 2023
Description:  Some of the "closed" m,essages inteh access log are now a mixed
case, and logconv should be able to process it.

relates: #5640

Reviewed by: jchapman & tbordaz (Thanks!!)
mreynolds389 added a commit that referenced this issue Feb 14, 2023
Description:  Some of the "closed" m,essages inteh access log are now a mixed
case, and logconv should be able to process it.

relates: #5640

Reviewed by: jchapman & tbordaz (Thanks!!)
mreynolds389 added a commit that referenced this issue Feb 14, 2023
Description:  Some of the "closed" m,essages inteh access log are now a mixed
case, and logconv should be able to process it.

relates: #5640

Reviewed by: jchapman & tbordaz (Thanks!!)
mreynolds389 added a commit that referenced this issue Feb 14, 2023
Description:  Some of the "closed" m,essages inteh access log are now a mixed
case, and logconv should be able to process it.

relates: #5640

Reviewed by: jchapman & tbordaz (Thanks!!)
mreynolds389 added a commit that referenced this issue Feb 14, 2023
Description:  Some of the "closed" m,essages inteh access log are now a mixed
case, and logconv should be able to process it.

relates: #5640

Reviewed by: jchapman & tbordaz (Thanks!!)
@mreynolds389
Copy link
Contributor

ad73687..50a2bb7 389-ds-base-2.2 -> 389-ds-base-2.2
838a9f2..f86675b 389-ds-base-2.1 -> 389-ds-base-2.1
b09a460..45beb31 389-ds-base-2.0 -> 389-ds-base-2.0
a46160c..ff93944 389-ds-base-1.4.3 -> 389-ds-base-1.4.3

@aivanov389
Copy link
Author

aivanov389 commented Feb 20, 2023

This commit resolves the problem only partially (probably only cleanly closed connections are counted as closed). As i said in the first message, the commit 26a1e0c has replaced the log file keyword "closed" by "Disconnect".

The values of "Peak Concurrent Connections" on our production servers are about 600-800, while the new logconv.pl still displays about 3000-4000.

Here are the changes that take into account the replacement of the keyword in addition to case sensitivity of the word "closed":

@@ -2249,7 +2249,7 @@
                $fdTaken++;
                if ($1 > $highestFdTaken){ $highestFdTaken = $1; }
        }
-       if (m/ fd=/ && m/closed/i){
+       if (m/ fd=/ && m/(closed|disconnect)/i){
                ($connID) = $_ =~ /conn=(\d*)\s/;
                handleConnClose($connID);
        }
@@ -2362,7 +2362,7 @@
                }
                $isVlvNotes = 0;
        }
-       if (m/ closed error 32/i){
+       if (m/ (closed|disconnect) error 32/i){
                $brokenPipeCount++;
                if (m/- T1/){ $hashes->{rc}->{"T1"}++; }
                elsif (m/- T2/){ $hashes->{rc}->{"T2"}++; }
@@ -2377,7 +2377,7 @@
                elsif (m/- U1/){ $hashes->{rc}->{"U1"}++; }
                else { $hashes->{rc}->{"other"}++; }
        }
-       if (m/ closed error 131/i || m/ closed error -5961/i){
+       if (m/ (closed|disconnect) error 131/i || m/ (closed|disconnect) error -5961/i){
                $connResetByPeerCount++;
                if (m/- T1/){ $hashes->{src}->{"T1"}++; }
                elsif (m/- T2/){ $hashes->{src}->{"T2"}++; }
@@ -2392,7 +2392,7 @@
                elsif (m/- U1/){ $hashes->{src}->{"U1"}++; }
                else { $hashes->{src}->{"other"}++; }
        }
-       if (m/ closed error 11/i){
+       if (m/ (closed|disconnect) error 11/i){
                $resourceUnavailCount++;
                if (m/- T1/){ $hashes->{rsrc}->{"T1"}++; }
                elsif (m/- T2/){ $hashes->{rsrc}->{"T2"}++; }

@mreynolds389
Copy link
Contributor

Sorry @aivanov389 I'll get this fixed right away...

@mreynolds389 mreynolds389 reopened this Feb 20, 2023
mreynolds389 added a commit to mreynolds389/389-ds-base that referenced this issue Feb 23, 2023
Description:  Some of the "closed" messages have been replaced by "disconnect"
              The tool needs to handles these changes

relates: 389ds#5640

Reviewed by: spichugi(Thanks!)
mreynolds389 added a commit that referenced this issue Feb 23, 2023
Description:  Some of the "closed" messages have been replaced by "disconnect"
              The tool needs to handles these changes

relates: #5640

Reviewed by: spichugi(Thanks!)
mreynolds389 added a commit that referenced this issue Feb 23, 2023
Description:  Some of the "closed" messages have been replaced by "disconnect"
              The tool needs to handles these changes

relates: #5640

Reviewed by: spichugi(Thanks!)
mreynolds389 added a commit that referenced this issue Feb 23, 2023
Description:  Some of the "closed" messages have been replaced by "disconnect"
              The tool needs to handles these changes

relates: #5640

Reviewed by: spichugi(Thanks!)
mreynolds389 added a commit that referenced this issue Feb 23, 2023
Description:  Some of the "closed" messages have been replaced by "disconnect"
              The tool needs to handles these changes

relates: #5640

Reviewed by: spichugi(Thanks!)
mreynolds389 added a commit that referenced this issue Feb 23, 2023
Description:  Some of the "closed" messages have been replaced by "disconnect"
              The tool needs to handles these changes

relates: #5640

Reviewed by: spichugi(Thanks!)
@mreynolds389
Copy link
Contributor

acee4ca..d4b9fb0 389-ds-base-2.2 -> 389-ds-base-2.2
9d92f6a..6de88be 389-ds-base-2.1 -> 389-ds-base-2.1
0ffe4ab..11fa11f 389-ds-base-2.0 -> 389-ds-base-2.0
fb49e68..ce54e81 389-ds-base-1.4.3 -> 389-ds-base-1.4.3

Ok should be good now...

@tbordaz tbordaz added this to the 1.4.3 milestone Jan 17, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
needs triage The issue will be triaged during scrum
Projects
None yet
Development

No branches or pull requests

3 participants