Empty timestamp in linelog
Ashraf Al-Basti
albasti at gmail.com
Mon Nov 27 16:43:48 UTC 2023
Hi,
I have configured Linelog to log the accept/reject messages but I'm
facing an issue if the username has "@".
if the username has "@" the timestamp will become empty. below the conf and
the debug for both cases
linelog llog-auth-reject {
filename = /log/authentication/auth-reject-%Y%m%d.csv
escape_filenames = no
permissions = 0640
format = ""
reference = "messages.%{%{reply:Packet-Type}:-default}"
messages {
default = "Unknown packet type %{Packet-Type}"
Access-Accept =
"%{Event-Timestamp},%{User-Name},%{NAS-Identifier},%{reply:Packet-Type},%l,%{NAS-IP-Address},%{ERX-Dhcp-Mac-Addr},%{reply:Reply-Message}"
Access-Reject =
"%{Event-Timestamp},%{User-Name},%{NAS-Identifier},%{reply:Packet-Type},%l,%{NAS-IP-Address},%{ERX-Dhcp-Mac-Addr},%{reply:Reply-Message}"
Access-Challenge = ""
}
}
*Username with @*
(0) Received Access-Request Id 25 from 192.168.1.21:61062 to
192.168.1.157:1812 length 153
(0) User-Name = "test at wifi"
(0) User-Password = "yyyyyyy"
(0) NAS-Port = 25
(0) Service-Type = Login-User
(0) NAS-IP-Address = 10.129.10.50
(0) Connect-Info = "1|10"
(0) Calling-Station-Id = "11-33-44-55-a5-11"
(0) NAS-Identifier = "SRC"
(0) Called-Station-Id = "12345"
(0) ERX-Dhcp-Mac-Addr = "11-33-44-55-a5-12"
(0) NAS-Port-Id = "mx480-0-re0#ae2:3500##"
(0) # Executing section authorize from file /etc/raddb/sites-enabled/default
(0) authorize {
(0) policy filter_username {
(0) if (&User-Name) {
(0) if (&User-Name) -> TRUE
(0) if (&User-Name) {
(0) if (&User-Name =~ / /) {
(0) if (&User-Name =~ / /) -> FALSE
(0) if (&User-Name =~ /@[^@]*@/ ) {
(0) if (&User-Name =~ /@[^@]*@/ ) -> FALSE
(0) if (&User-Name =~ /\.\./ ) {
(0) if (&User-Name =~ /\.\./ ) -> FALSE
(0) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) {
(0) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) ->
TRUE
(0) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) {
(0) update request {
(0) &Module-Failure-Message += 'Rejected: Realm does not have
at least one dot separator'
(0) } # update request = noop
(0) [reject] = reject
(0) } # if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))
= reject
(0) } # if (&User-Name) = reject
(0) } # policy filter_username = reject
(0) } # authorize = reject
*(0) Invalid user (Rejected: Realm does not have at least one dot
separator): [test at wifi] (from client test1 port 25 cli 11-33-44-55-a5-11)*
(0) Using Post-Auth-Type Reject
(0) # Executing group from file /etc/raddb/sites-enabled/default
(0) Post-Auth-Type REJECT {
(0) llog-auth-reject: EXPAND messages.%{%{reply:Packet-Type}:-default}
(0) llog-auth-reject: --> messages.Access-Reject
(0) llog-auth-reject: EXPAND
%{Event-Timestamp},%{User-Name},%{NAS-Identifier},%{reply:Packet-Type},%l,%{NAS-IP-Address},%{ERX-Dhcp-Mac-Addr},%{reply:Reply-Message}
(0) llog-auth-reject: --> ,test at wifi
,SRC,Access-Reject,1701103042,10.129.10.50,11-33-44-55-a5-12,
(0) llog-auth-reject: EXPAND /log/authentication/auth-reject-%Y%m%d.csv
(0) llog-auth-reject: --> /log/authentication/auth-reject-20231127.csv
(0) [llog-auth-reject] = ok
(0) } # Post-Auth-Type REJECT = ok
(0) Delaying response for 1.000000 seconds
Waking up in 0.3 seconds.
Waking up in 0.6 seconds.
(0) Sending delayed response
(0) Sent Access-Reject Id 25 from 192.168.1.157:1812 to 192.168.1.21:61062
length 20
Waking up in 3.9 seconds.
(0) Cleaning up request packet ID 25 with timestamp +6
Username without "@"
(1) Received Access-Request Id 26 from 192.168.1.21:56579 to
192.168.1.157:1812 length 148
(1) User-Name = "test"
(1) User-Password = "yyyyyyy"
(1) NAS-Port = 26
(1) Service-Type = Login-User
(1) NAS-IP-Address = 10.129.10.50
(1) Connect-Info = "1|10"
(1) Calling-Station-Id = "11-33-44-55-a5-11"
(1) NAS-Identifier = "SRC"
(1) Called-Station-Id = "12345"
(1) ERX-Dhcp-Mac-Addr = "11-33-44-55-a5-12"
(1) NAS-Port-Id = "mx480-0-re0#ae2:3500##"
(1) # Executing section authorize from file /etc/raddb/sites-enabled/default
(1) authorize {
(1) policy filter_username {
(1) if (&User-Name) {
(1) if (&User-Name) -> TRUE
(1) if (&User-Name) {
(1) if (&User-Name =~ / /) {
(1) if (&User-Name =~ / /) -> FALSE
(1) if (&User-Name =~ /@[^@]*@/ ) {
(1) if (&User-Name =~ /@[^@]*@/ ) -> FALSE
(1) if (&User-Name =~ /\.\./ ) {
(1) if (&User-Name =~ /\.\./ ) -> FALSE
(1) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) {
(1) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) ->
FALSE
(1) if (&User-Name =~ /\.$/) {
(1) if (&User-Name =~ /\.$/) -> FALSE
(1) if (&User-Name =~ /@\./) {
(1) if (&User-Name =~ /@\./) -> FALSE
(1) } # if (&User-Name) = notfound
(1) } # policy filter_username = notfound
(1) [preprocess] = ok
(1) [chap] = noop
(1) [mschap] = noop
(1) [digest] = noop
(1) suffix: Checking for suffix after "@"
(1) suffix: No '@' in User-Name = "test", looking up realm NULL
(1) suffix: No such realm "NULL"
(1) [suffix] = noop
(1) [files] = noop
(1) sql: EXPAND %{User-Name}
(1) sql: --> test
(1) sql: SQL-User-Name set to 'test'
rlm_sql (sql): 0 of 0 connections in use. You may need to increase "spare"
*rlm_sql (sql): Opening additional connection (0), 1 of 500 pending slots
used*
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket,
server version 8.0.30, protocol version 10
rlm_sql (sql): Reserved connection (0)
(1) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck
WHERE username = '%{SQL-User-Name}' ORDER BY id
(1) sql: --> SELECT id, username, attribute, value, op FROM radcheck
WHERE username = 'test' ORDER BY id
(1) sql: Executing select query: SELECT id, username, attribute, value, op
FROM radcheck WHERE username = 'test' ORDER BY id
*(1) sql: WARNING: User not found in radcheck table.*
rlm_sql (sql): 1 of 1 connections in use. You may need to increase "spare"
*rlm_sql (sql): Opening additional connection (1), 1 of 499 pending slots
used*
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket,
server version 8.0.30, protocol version 10
rlm_sql (sql): Reserved connection (1)
rlm_sql (sql): Released connection (1)
*Need 9 more connections to reach 10 spares*
*rlm_sql (sql): Opening additional connection (2), 1 of 498 pending slots
used*
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket,
server version 8.0.30, protocol version 10
(1) sql: EXPAND SELECT groupname FROM radusergroup WHERE username =
'%{SQL-User-Name}' ORDER BY priority
(1) sql: --> SELECT groupname FROM radusergroup WHERE username = 'test'
ORDER BY priority
(1) sql: Executing select query: SELECT groupname FROM radusergroup WHERE
username = 'test' ORDER BY priority
(1) sql: User not found in any groups
rlm_sql (sql): Released connection (0)
(1) [sql] = notfound
(1) [expiration] = noop
(1) [logintime] = noop
*(1) pap: WARNING: No "known good" password found for the user. Not
setting Auth-Type*
*(1) pap: WARNING: Authentication will fail unless a "known good" password
is available*
(1) [pap] = noop
(1) } # authorize = ok
*(1) ERROR: No Auth-Type found: rejecting the user via Post-Auth-Type =
Reject*
(1) Failed to authenticate the user
(1) Using Post-Auth-Type Reject
(1) # Executing group from file /etc/raddb/sites-enabled/default
(1) Post-Auth-Type REJECT {
(1) llog-auth-reject: EXPAND messages.%{%{reply:Packet-Type}:-default}
(1) llog-auth-reject: --> messages.Access-Reject
(1) llog-auth-reject: EXPAND
%{Event-Timestamp},%{User-Name},%{NAS-Identifier},%{reply:Packet-Type},%l,%{NAS-IP-Address},%{ERX-Dhcp-Mac-Addr},%{reply:Reply-Message}
(1) llog-auth-reject: --> Nov 27 2023 20:38:10
+04,test,SRC,Access-Reject,1701103090,10.129.10.50,11-33-44-55-a5-12,
(1) llog-auth-reject: EXPAND /log/authentication/auth-reject-%Y%m%d.csv
(1) llog-auth-reject: --> /log/authentication/auth-reject-20231127.csv
(1) [llog-auth-reject] = ok
(1) } # Post-Auth-Type REJECT = ok
(1) Delaying response for 1.000000 seconds
Waking up in 0.3 seconds.
Waking up in 0.6 seconds.
(1) Sending delayed response
(1) Sent Access-Reject Id 26 from 192.168.1.157:1812 to 192.168.1.21:56579
length 20
Waking up in 3.9 seconds.
(1) Cleaning up request packet ID 26 with timestamp +54
--
Best regards,
Ashraf Al-Basti
More information about the Freeradius-Users
mailing list