Skip to content

Commit 7cc0a50

Browse files
authored
Merge pull request #558 from OpenConext/feature/improve_ebauth_parse_script
Improve ebauth log parsing, and parse stepup-authentication logs also
2 parents ced2dda + 0107394 commit 7cc0a50

5 files changed

Lines changed: 201 additions & 7 deletions

File tree

roles/rsyslog/tasks/main.yml

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,9 +1,10 @@
1-
- name: Install rsyslog
1+
- name: Install rsyslog and python modules
22
ansible.builtin.package:
33
name:
44
- rsyslog
55
- rsyslog-gnutls
66
- rsyslog-relp
7+
- python3-dateutil
78
state: present
89
notify:
910
- "restart rsyslog"

roles/rsyslog/tasks/process_auth_logs.yml

Lines changed: 22 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -39,7 +39,7 @@
3939
state: present
4040
when: ansible_os_family == "Debian"
4141

42-
- name: Create a python script that parses log_logins per environment
42+
- name: Create a python script that parses eb log_logins per environment
4343
ansible.builtin.template:
4444
src: parse_ebauth_to_mysql.py.j2
4545
dest: /usr/local/sbin/parse_ebauth_to_mysql_{{ item.name }}.py
@@ -49,7 +49,17 @@
4949
with_items: "{{ rsyslog_environments }}"
5050
when: item.db_loglogins_name is defined
5151

52-
- name: Put log_logins logrotate scripts
52+
- name: Create a python script that parses stepup log_logins per environment
53+
ansible.builtin.template:
54+
src: parse_stepupauth_to_mysql.py.j2
55+
dest: /usr/local/sbin/parse_stepupauth_to_mysql_{{ item.name }}.py
56+
mode: 0740
57+
owner: root
58+
group: root
59+
with_items: "{{ rsyslog_environments }}"
60+
when: item.db_loglogins_name is defined
61+
62+
- name: Put log_logins logrotate scripts for eb
5363
ansible.builtin.template:
5464
src: logrotate_ebauth.j2
5565
dest: /etc/logrotate.d/logrotate_ebauth_{{ item.name }}
@@ -59,6 +69,16 @@
5969
with_items: "{{ rsyslog_environments }}"
6070
when: item.db_loglogins_name is defined
6171

72+
- name: Put log_logins logrotate scripts for stepup
73+
ansible.builtin.template:
74+
src: logrotate_stepupauth.j2
75+
dest: /etc/logrotate.d/logrotate_stepupauth_{{ item.name }}
76+
mode: 0644
77+
owner: root
78+
group: root
79+
with_items: "{{ rsyslog_environments }}"
80+
when: item.db_loglogins_name is defined
81+
6282
- name: Create logdirectory for log_logins cleanup script
6383
ansible.builtin.file:
6484
path: "{{ rsyslog_dir }}/apps/{{ item.name }}/loglogins_cleanup/"
Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,16 @@
1+
{{ rsyslog_dir }}/log_logins/{{ item.name }}/stepup-authentication.log
2+
{
3+
missingok
4+
daily
5+
rotate 180
6+
sharedscripts
7+
dateext
8+
dateyesterday
9+
compress
10+
delaycompress
11+
create 0640 root {{ rsyslog_read_group }}
12+
postrotate
13+
/usr/local/sbin/parse_stepupauth_to_mysql_{{ item.name }}.py > /dev/null
14+
systemctl kill -s HUP rsyslog.service
15+
endscript
16+
}

roles/rsyslog/templates/parse_ebauth_to_mysql.py.j2

Lines changed: 9 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -21,11 +21,17 @@ cursor = db.cursor()
2121

2222
def update_lastseen(user_id, date):
2323
query = """
24-
REPLACE INTO last_login (userid, lastseen)
24+
INSERT INTO last_login (userid, lastseen)
2525
VALUES (%s, %s)
26+
ON DUPLICATE KEY UPDATE
27+
lastseen = GREATEST(lastseen, VALUES(lastseen))
2628
"""
27-
cursor.execute(query, (user_id, date))
28-
db.commit()
29+
try:
30+
cursor.execute(query, (user_id, date))
31+
db.commit()
32+
except Exception as e:
33+
db.rollback()
34+
print(f"Error updating last_login for user {user_id}: {e}")
2935

3036
def load_in_mysql(a,b,c,d,e,f,g,h):
3137
sql = """insert into log_logins(idpentityid,spentityid,loginstamp,userid,keyid,sessionid,requestid,trustedproxyentityid) values(%s,%s,%s,%s,%s,%s,%s,%s)"""
@@ -73,4 +79,3 @@ for filename in os.listdir(workdir):
7379

7480
cursor.close()
7581
db.close()
76-
Lines changed: 152 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,152 @@
1+
#!/usr/bin/python3
2+
# This script parses rotated stepup-authentication.log files produced by engineblock.
3+
# It filters for successful logins (authentication_result:OK) and inserts the data
4+
# into the log_logins and last_login MySQL tables.
5+
# This script is intended to be run separately during logrotate.
6+
7+
import os
8+
import sys
9+
import json
10+
import MySQLdb
11+
from dateutil.parser import parse
12+
13+
# Configuration variables (to be injected by Ansible/Jinja2)
14+
mysql_host="{{ item.db_loglogins_host }}"
15+
mysql_user="{{ item.db_loglogins_user }}"
16+
mysql_password="{{ item.db_loglogins_password }}"
17+
mysql_db="{{ item.db_loglogins_name }}"
18+
workdir="{{ rsyslog_dir }}/log_logins/{{ item.name}}/"
19+
20+
# Establish database connection
21+
try:
22+
db = MySQLdb.connect(mysql_host,mysql_user,mysql_password,mysql_db )
23+
cursor = db.cursor()
24+
except Exception as e:
25+
print(f"Error connecting to MySQL: {e}")
26+
sys.exit(1)
27+
28+
# --- Database Functions ---
29+
30+
def update_lastseen(user_id, date):
31+
"""
32+
Updates the last_login table.
33+
Uses GREATEST() to ensure only newer dates overwrite the existing 'lastseen' value.
34+
"""
35+
query = """
36+
INSERT INTO last_login (userid, lastseen)
37+
VALUES (%s, %s)
38+
ON DUPLICATE KEY UPDATE
39+
lastseen = GREATEST(lastseen, VALUES(lastseen))
40+
"""
41+
try:
42+
cursor.execute(query, (user_id, date))
43+
db.commit()
44+
except Exception as e:
45+
db.rollback()
46+
print(f"Error updating last_login for user {user_id}: {e}")
47+
48+
def load_stepup_in_mysql(idp, sp, loginstamp, userid, requestid):
49+
"""
50+
Inserts Step-up login data into the log_logins table.
51+
Fills keyid, sessionid, and trustedproxyentityid with NULL.
52+
"""
53+
# Columns in log_logins: idpentityid, spentityid, loginstamp, userid, keyid, sessionid, requestid, trustedproxyentityid
54+
55+
keyid = None
56+
sessionid = None
57+
trustedproxyentityid = None
58+
59+
sql = """
60+
INSERT INTO log_logins(idpentityid, spentityid, loginstamp, userid, keyid, sessionid, requestid, trustedproxyentityid)
61+
VALUES(%s, %s, %s, %s, %s, %s, %s, %s)
62+
"""
63+
try:
64+
cursor.execute(sql, (idp, sp, loginstamp, userid, keyid, sessionid, requestid, trustedproxyentityid))
65+
db.commit()
66+
except Exception as e:
67+
db.rollback()
68+
print(f"Error inserting stepup data: {e}")
69+
# Print the data that failed insertion
70+
print((idp, sp, loginstamp, userid, keyid, sessionid, requestid, trustedproxyentityid))
71+
72+
# --- Parsing Function ---
73+
74+
def parse_stepup_lines(a):
75+
"""
76+
Opens the stepup log file, parses each line, filters for successful logins,
77+
and loads the data into MySQL.
78+
"""
79+
input_file = open((a), 'r')
80+
for line in input_file:
81+
try:
82+
# Assumes JSON data starts after the first ']:'
83+
jsonline = line.split(']:',2)[1]
84+
data = json.loads(jsonline)
85+
except:
86+
continue
87+
88+
# 1. Filtering condition: Only parse logs having authentication_result:OK
89+
# Only successful authentications are logged, so this check is not
90+
# necessary. There is currently a bug in the Stepup-Gateway where
91+
# FAILED is logged, even though the result is OK, making this check
92+
# do the wrong thing now.
93+
#
94+
#if data.get("context").("authentication_result") != "OK":
95+
# continue
96+
97+
# 2. Extract required fields
98+
context = data.get("context")
99+
100+
if not isinstance(context, dict):
101+
print("Skipping line: context is missing or invalid")
102+
continue
103+
104+
user_id = context.get("identity_id")
105+
timestamp = context.get("datetime")
106+
request_id = context.get("request_id")
107+
sp_entity_id = context.get("requesting_sp")
108+
idp_entity_id = context.get("authenticating_idp")
109+
110+
# Basic data validation
111+
if not user_id or not timestamp:
112+
print(
113+
"Skipping line: validation failed "
114+
f"(user_id={user_id!r}, timestamp={timestamp!r}, request_id={request_id!r})"
115+
)
116+
continue
117+
118+
try:
119+
# 3. Format date and time for MySQL
120+
loginstamp = parse(timestamp).strftime("%Y-%m-%d %H:%M:%S")
121+
last_login_date = parse(timestamp).strftime("%Y-%m-%d")
122+
except:
123+
print(
124+
"Skipping line: timestamp parsing failed "
125+
f"(timestamp={timestamp!r}, user_id={user_id!r}, error={e})"
126+
)
127+
continue
128+
129+
# 4. Insert into MySQL
130+
load_stepup_in_mysql(idp_entity_id, sp_entity_id, loginstamp, user_id, request_id)
131+
132+
# 5. Update last login date
133+
update_lastseen(user_id, last_login_date)
134+
135+
136+
# --- Main Execution ---
137+
138+
## Loop over the files and parse them one by one
139+
for filename in os.listdir(workdir):
140+
filetoparse=(os.path.join(workdir, filename))
141+
142+
# Check for Stepup files, ignore compressed files
143+
if os.path.isfile(filetoparse) and filename.startswith("stepup-authentication.log-") and not filename.endswith(".gz"):
144+
print(f"Parsing stepup log file: {filename}")
145+
parse_stepup_lines(filetoparse)
146+
else:
147+
continue
148+
149+
# Close database connection
150+
cursor.close()
151+
db.close()
152+
print("Stepup log parsing complete.")

0 commit comments

Comments
 (0)