pgaudit_analyze
pgaudit_analyze copied to clipboard
when using pam authentication all logon failures marked as success
The issue is when using PAM auth a log msg of level LOG created before the FATAL msg Pass in the msg and check it to catch this case.
Example logs from csv:
2021-07-22 14:49:47.420 EDT,,,13208,"127.0.0.1:34254",60f9bdcb.3398,1,"",2021-07-22 14:49:47 EDT,,0,LOG,00000,"connection received: host=127.0.0.1 port=34254",,,,,,,,,""
2021-07-22 14:49:48.938 EDT,"XXXXX","pgaudit",13208,"127.0.0.1:34254",60f9bdcb.3398,2,"authentication",2021-07-22 14:49:47 EDT,3/843974,0,LOG,00000,"pam_authenticate failed: User not known to the underlying authentication module",,,,,,,,,""
2021-07-22 14:49:48.938 EDT,"XXXXX","pgaudit",13208,"127.0.0.1:34254",60f9bdcb.3398,3,"authentication",2021-07-22 14:49:47 EDT,3/843974,0,FATAL,28000,"PAM authentication failed for user ""XXXXX""","Connection matched pg_hba.conf line 90: ""host all all 127.0.0.1/32 pam""",,,,,,,,""
It is not clear to me why this change is needed. Why is the FATAL not enough? Is it just that you want the PAM message to be logged as an error, or is something not working as expected?
The issue is it is incorrectly recording a successful authentication in the logon table and incorrectly not logging an error in the session table for pam failures.
FATAL would be enough if PAM did not create a msg LOG right before the FATAL msg.
Here are 2 sample table excerpts for when authentication failed using pam:
pgaudit.logon
user_name | last_success | current_success | last_failure | failures_since_last_success
-----------------------------------------------------------------+--------------+------------------------+--------------+-----------------------------
############################################################### | | 2021-07-20 04:42:04-04 | | 0
conda activate base | | 2021-07-21 13:15:35-04 | | 0
(2 rows)
pgaudit.session
session_id | process_id | session_start_time | user_name | application_name | connection_from | state
------------------+------------+------------------------+-----------------------------------------------------------------+------------------+-----------------------+-------
60f68c5c.1382 | 4994 | 2021-07-20 04:42:04-04 | ############################################################### | [unknown] | REMOVED | ok
60f85637.33b66 | 211814 | 2021-07-21 13:15:35-04 | conda activate base | [unknown] | REMOVED | ok
(2 rows)
Below is one example from the csv log:
2021-07-21 13:15:37.304 EDT,"conda activate base","xxxx",211814,"REMOVED",60f85637.33b66,2,"authentication",2021-07-21 13:15:35 EDT,10/1940967,0,LOG,00000,"pam_authenticate failed: User not known to the underlying authentication module",,,,,,,,,""
2021-07-21 13:15:37.304 EDT,"conda activate base","xxxx",211814,"REMOVED",60f85637.33b66,3,"authentication",2021-07-21 13:15:35 EDT,10/1940967,0,FATAL,28000,"PAM authentication failed for user ""conda activate base""","Connection matched pg_hba.conf line 128:```
Generalized the check for detecting authentication LOG messages that can precede a FATAL authentication message. Added another PAM message and an ident message that are labeled as LOG but indicate an authentication error.
Below are example csv log entries of 3 error messages accounted for in this PR
2023-06-23 14:01:00.956 EDT,,,25987,"10.150.20.18:50840",6495dddc.6583,1,"",2023-06-23 14:01:00 EDT,,0,LOG,00000,"connection received: host=10.150.20.18 port=50840",,,,,,,,,"","not initialized",,0
2023-06-23 14:01:01.217 EDT,"amalek","test",25987,"10.150.20.18:50840",6495dddc.6583,2,"authentication",2023-06-23 14:01:00 EDT,22/235732,0,LOG,00000,"pam_authenticate failed: Authentication failure",,,,,,,,,"","client backend",,-8259055824528607182
2023-06-23 14:01:01.217 EDT,"amalek","test",25987,"10.150.20.18:50840",6495dddc.6583,3,"authentication",2023-06-23 14:01:00 EDT,22/235732,0,FATAL,28000,"PAM authentication failed for user ""amalek""","Connection matched pg_hba.conf line 148: ""hostssl test all 0.0.0.0/0 pam""",,,,,,,,"","client backend",,-8259055824528607182
2023-06-23 14:02:02.079 EDT,,,66217,"10.150.20.18:50834",6495de1a.102a9,1,"",2023-06-23 14:02:02 EDT,,0,LOG,00000,"connection received: host=10.150.20.18 port=50834",,,,,,,,,"","not initialized",,0
2023-06-23 14:02:02.362 EDT,"amalek","test",66217,"10.150.20.18:50834",6495de1a.102a9,2,"authentication",2023-06-23 14:02:02 EDT,22/235737,0,LOG,00000,"error from underlying PAM layer: /usr/local/sbin/duo_sentinel failed: exit code 1",,,,,,,,,"","client backend",,0
2023-06-23 14:05:01.257 EDT,"amalek","test",66217,"10.150.20.18:50834",6495de1a.102a9,3,"authentication",2023-06-23 14:02:02 EDT,22/235737,0,LOG,00000,"pam_authenticate failed: Have exhausted maximum number of retries for service",,,,,,,,,"","client backend",,0
2023-06-23 14:05:01.257 EDT,"amalek","test",66217,"10.150.20.18:50834",6495de1a.102a9,4,"authentication",2023-06-23 14:02:02 EDT,22/235737,0,FATAL,57014,"canceling authentication due to timeout",,,,,,,,,"","client backend",,0
2023-06-23 14:30:02.620 EDT,,,63188,"192.168.9.252:47784",6495e4aa.f6d4,1,"",2023-06-23 14:30:02 EDT,,0,LOG,00000,"connection received: host=192.168.9.252 port=47784",,,,,,,,,"","not initialized",,0
2023-06-23 14:30:02.645 EDT,"amalek","test",63188,"192.168.9.252:47784",6495e4aa.f6d4,2,"authentication",2023-06-23 14:30:02 EDT,35/268140,0,LOG,XX000,"could not connect to Ident server at address ""192.168.9.252"", port 113: Connection refused",,,,,,,,,"","client backend",,-1059774696014560043
2023-06-23 14:30:02.645 EDT,"amalek","test",63188,"192.168.9.252:47784",6495e4aa.f6d4,3,"authentication",2023-06-23 14:30:02 EDT,35/268140,0,FATAL,28000,"Ident authentication failed for user ""amalek""","Connection matched pg_hba.conf line 144: ""hostssl test all 192.168.8.0/21 ident""",,,,,,,,"","client backend",,-1059774696014560043