May 07 22:02:29 gw freeradius[574424]: (0) Received Access-Request Id 186 from 127.0.0.1:39708 to 127.0.0.1:1812 length 102
May 07 22:02:29 gw freeradius[574424]: (0)   Framed-Protocol = PPP
May 07 22:02:29 gw freeradius[574424]: (0)   Message-Authenticator = 0x78a4b5cee5995f6f4791cc3100b376e9
May 07 22:02:29 gw freeradius[574424]: (0)   NAS-IP-Address = 10.146.109.1
May 07 22:02:29 gw freeradius[574424]: (0)   NAS-Port = 0
May 07 22:02:29 gw freeradius[574424]: (0)   Service-Type = Framed-User
May 07 22:02:29 gw freeradius[574424]: (0)   User-Name = "ramy"
May 07 22:02:29 gw freeradius[574424]: (0)   User-Password = "df0I1t1cgHgR7TeT23r1djffy6dIIfo"
May 07 22:02:29 gw freeradius[574424]: (0) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default
May 07 22:02:29 gw freeradius[574424]: (0)   authorize {
May 07 22:02:29 gw freeradius[574424]: (0)     policy filter_username {
May 07 22:02:29 gw freeradius[574424]: (0)       if (&User-Name) {
May 07 22:02:29 gw freeradius[574424]: (0)       if (&User-Name)  -> TRUE
May 07 22:02:29 gw freeradius[574424]: (0)       if (&User-Name)  {
May 07 22:02:29 gw freeradius[574424]: (0)         if (&User-Name =~ / /) {
May 07 22:02:29 gw freeradius[574424]: (0)         if (&User-Name =~ / /)  -> FALSE
May 07 22:02:29 gw freeradius[574424]: (0)         if (&User-Name =~ /@[^@]*@/ ) {
May 07 22:02:29 gw freeradius[574424]: (0)         if (&User-Name =~ /@[^@]*@/ )  -> FALSE
May 07 22:02:29 gw freeradius[574424]: (0)         if (&User-Name =~ /\.\./ ) {
May 07 22:02:29 gw freeradius[574424]: (0)         if (&User-Name =~ /\.\./ )  -> FALSE
May 07 22:02:29 gw freeradius[574424]: (0)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
May 07 22:02:29 gw freeradius[574424]: (0)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
May 07 22:02:29 gw freeradius[574424]: (0)         if (&User-Name =~ /\.$/)  {
May 07 22:02:29 gw freeradius[574424]: (0)         if (&User-Name =~ /\.$/)   -> FALSE
May 07 22:02:29 gw freeradius[574424]: (0)         if (&User-Name =~ /@\./)  {
May 07 22:02:29 gw freeradius[574424]: (0)         if (&User-Name =~ /@\./)   -> FALSE
May 07 22:02:29 gw freeradius[574424]: (0)       } # if (&User-Name)  = notfound
May 07 22:02:29 gw freeradius[574424]: (0)     } # policy filter_username = notfound
May 07 22:02:29 gw freeradius[574424]: (0)     [preprocess] = ok
May 07 22:02:29 gw freeradius[574424]: (0)     [chap] = noop
May 07 22:02:29 gw freeradius[574424]: (0)     [mschap] = noop
May 07 22:02:29 gw freeradius[574424]: (0)     [digest] = noop
May 07 22:02:29 gw freeradius[574424]: (0) suffix: Checking for suffix after "@"
May 07 22:02:29 gw freeradius[574424]: (0) suffix: No '@' in User-Name = "ramy", looking up realm NULL
May 07 22:02:29 gw freeradius[574424]: (0) suffix: No such realm "NULL"
May 07 22:02:29 gw freeradius[574424]: (0)     [suffix] = noop
May 07 22:02:29 gw freeradius[574424]: (0) eap: No EAP-Message, not doing EAP
May 07 22:02:29 gw freeradius[574424]: (0)     [eap] = noop
May 07 22:02:29 gw freeradius[574424]: (0) files: users: Matched entry ramy at line 92
May 07 22:02:29 gw freeradius[574424]: (0)     [files] = ok
May 07 22:02:29 gw freeradius[574424]: (0)     [expiration] = noop
May 07 22:02:29 gw freeradius[574424]: (0)     [logintime] = noop
May 07 22:02:29 gw freeradius[574424]: (0)     [pap] = updated
May 07 22:02:29 gw freeradius[574424]: (0)   } # authorize = updated
May 07 22:02:29 gw freeradius[574424]: (0) Found Auth-Type = PAP
May 07 22:02:29 gw freeradius[574424]: (0) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
May 07 22:02:29 gw freeradius[574424]: (0)   Auth-Type PAP {
May 07 22:02:29 gw freeradius[574424]: (0) pap: Login attempt with password
May 07 22:02:29 gw freeradius[574424]: (0) pap: Comparing with "known good" Cleartext-Password
May 07 22:02:29 gw freeradius[574424]: (0) pap: User authenticated successfully
May 07 22:02:29 gw freeradius[574424]: (0)     [pap] = ok
May 07 22:02:29 gw freeradius[574424]: (0)   } # Auth-Type PAP = ok
May 07 22:02:29 gw freeradius[574424]: (0) # Executing section post-auth from file /etc/freeradius/3.0/sites-enabled/default
May 07 22:02:29 gw freeradius[574424]: (0)   post-auth {
May 07 22:02:29 gw freeradius[574424]: (0)     if (session-state:User-Name && reply:User-Name && request:User-Name && (reply:User-Name == request:User-Name)) {
May 07 22:02:29 gw freeradius[574424]: (0)     if (session-state:User-Name && reply:User-Name && request:User-Name && (reply:User-Name == request:User-Name))  -> FALSE
May 07 22:02:29 gw freeradius[574424]: (0)     update {
May 07 22:02:29 gw freeradius[574424]: (0)       No attributes updated for RHS &session-state:
May 07 22:02:29 gw freeradius[574424]: (0)     } # update = noop
May 07 22:02:29 gw freeradius[574424]: (0)     [exec] = noop
May 07 22:02:29 gw freeradius[574424]: (0)     policy remove_reply_message_if_eap {
May 07 22:02:29 gw freeradius[574424]: (0)       if (&reply:EAP-Message && &reply:Reply-Message) {
May 07 22:02:29 gw freeradius[574424]: (0)       if (&reply:EAP-Message && &reply:Reply-Message)  -> FALSE
May 07 22:02:29 gw freeradius[574424]: (0)       else {
May 07 22:02:29 gw freeradius[574424]: (0)         [noop] = noop
May 07 22:02:29 gw freeradius[574424]: (0)       } # else = noop
May 07 22:02:29 gw freeradius[574424]: (0)     } # policy remove_reply_message_if_eap = noop
May 07 22:02:29 gw freeradius[574424]: (0)   } # post-auth = noop
May 07 22:02:29 gw freeradius[574424]: (0) Sent Access-Accept Id 186 from 127.0.0.1:1812 to 127.0.0.1:39708 length 20
May 07 22:02:29 gw freeradius[574424]: (0) Finished request
May 07 22:02:29 gw freeradius[574424]: Waking up in 4.9 seconds.
May 07 22:02:34 gw freeradius[574424]: (0) Cleaning up request packet ID 186 with timestamp +14 due to cleanup_delay was reached
May 07 22:02:34 gw freeradius[574424]: Waking up in 11.9 seconds.
May 07 22:04:06 gw freeradius[574424]: (2) Received Access-Request Id 190 from 127.0.0.1:37788 to 127.0.0.1:1812 length 118
May 07 22:04:06 gw freeradius[574424]: (2)   Framed-Protocol = PPP
May 07 22:04:06 gw freeradius[574424]: (2)   Message-Authenticator = 0xaaf26bebf0e2043a6ec40f5acf215690
May 07 22:04:06 gw freeradius[574424]: (2)   NAS-IP-Address = 10.146.80.1
May 07 22:04:06 gw freeradius[574424]: (2)   NAS-Port = 0
May 07 22:04:06 gw freeradius[574424]: (2)   Service-Type = Framed-User
May 07 22:04:06 gw freeradius[574424]: (2)   User-Name = "\\x72\\x61\\x6d\\x79\\x0a"
May 07 22:04:06 gw freeradius[574424]: (2)   User-Password = "df0I1t1cgHgR7TeT23r1djffy6dIIfo"
May 07 22:04:06 gw freeradius[574424]: (2) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default
May 07 22:04:06 gw freeradius[574424]: (2)   authorize {
May 07 22:04:06 gw freeradius[574424]: (2)     policy filter_username {
May 07 22:04:06 gw freeradius[574424]: (2)       if (&User-Name) {
May 07 22:04:06 gw freeradius[574424]: (2)       if (&User-Name)  -> TRUE
May 07 22:04:06 gw freeradius[574424]: (2)       if (&User-Name)  {
May 07 22:04:06 gw freeradius[574424]: (2)         if (&User-Name =~ / /) {
May 07 22:04:06 gw freeradius[574424]: (2)         if (&User-Name =~ / /)  -> FALSE
May 07 22:04:06 gw freeradius[574424]: (2)         if (&User-Name =~ /@[^@]*@/ ) {
May 07 22:04:06 gw freeradius[574424]: (2)         if (&User-Name =~ /@[^@]*@/ )  -> FALSE
May 07 22:04:06 gw freeradius[574424]: (2)         if (&User-Name =~ /\.\./ ) {
May 07 22:04:06 gw freeradius[574424]: (2)         if (&User-Name =~ /\.\./ )  -> FALSE
May 07 22:04:06 gw freeradius[574424]: (2)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
May 07 22:04:06 gw freeradius[574424]: (2)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
May 07 22:04:06 gw freeradius[574424]: (2)         if (&User-Name =~ /\.$/)  {
May 07 22:04:06 gw freeradius[574424]: (2)         if (&User-Name =~ /\.$/)   -> FALSE
May 07 22:04:06 gw freeradius[574424]: (2)         if (&User-Name =~ /@\./)  {
May 07 22:04:06 gw freeradius[574424]: (2)         if (&User-Name =~ /@\./)   -> FALSE
May 07 22:04:06 gw freeradius[574424]: (2)       } # if (&User-Name)  = notfound
May 07 22:04:06 gw freeradius[574424]: (2)     } # policy filter_username = notfound
May 07 22:04:06 gw freeradius[574424]: (2)     [preprocess] = ok
May 07 22:04:06 gw freeradius[574424]: (2)     [chap] = noop
May 07 22:04:06 gw freeradius[574424]: (2)     [mschap] = noop
May 07 22:04:06 gw freeradius[574424]: (2)     [digest] = noop
May 07 22:04:06 gw freeradius[574424]: (2) suffix: Checking for suffix after "@"
May 07 22:04:06 gw freeradius[574424]: (2) suffix: No '@' in User-Name = "\x72\x61\x6d\x79\x0a", looking up realm NULL
May 07 22:04:06 gw freeradius[574424]: (2) suffix: No such realm "NULL"
May 07 22:04:06 gw freeradius[574424]: (2)     [suffix] = noop
May 07 22:04:06 gw freeradius[574424]: (2) eap: No EAP-Message, not doing EAP
May 07 22:04:06 gw freeradius[574424]: (2)     [eap] = noop
May 07 22:04:06 gw freeradius[574424]: (2) files: users: Matched entry DEFAULT at line 174
May 07 22:04:06 gw freeradius[574424]: (2)     [files] = ok
May 07 22:04:06 gw freeradius[574424]: (2)     [expiration] = noop
May 07 22:04:06 gw freeradius[574424]: (2)     [logintime] = noop
May 07 22:04:06 gw freeradius[574424]: (2) pap: WARNING: No "known good" password found for the user.  Not setting Auth-Type
May 07 22:04:06 gw freeradius[574424]: (2) pap: WARNING: Authentication will fail unless a "known good" password is available
May 07 22:04:06 gw freeradius[574424]: (2)     [pap] = noop
May 07 22:04:06 gw freeradius[574424]: (2)   } # authorize = ok
May 07 22:04:06 gw freeradius[574424]: (2) ERROR: No Auth-Type found: rejecting the user via Post-Auth-Type = Reject
May 07 22:04:06 gw freeradius[574424]: (2) Failed to authenticate the user
May 07 22:04:06 gw freeradius[574424]: (2) Using Post-Auth-Type Reject
May 07 22:04:06 gw freeradius[574424]: (2) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
May 07 22:04:06 gw freeradius[574424]: (2)   Post-Auth-Type REJECT {
May 07 22:04:06 gw freeradius[574424]: (2) attr_filter.access_reject: EXPAND %{User-Name}
May 07 22:04:06 gw freeradius[574424]: (2) attr_filter.access_reject:    --> \\x72\\x61\\x6d\\x79\\x0a
May 07 22:04:06 gw freeradius[574424]: (2) attr_filter.access_reject: Matched entry DEFAULT at line 11
May 07 22:04:06 gw freeradius[574424]: (2)     [attr_filter.access_reject] = updated
May 07 22:04:06 gw freeradius[574424]: (2)     [eap] = noop
May 07 22:04:06 gw freeradius[574424]: (2)     policy remove_reply_message_if_eap {
May 07 22:04:06 gw freeradius[574424]: (2)       if (&reply:EAP-Message && &reply:Reply-Message) {
May 07 22:04:06 gw freeradius[574424]: (2)       if (&reply:EAP-Message && &reply:Reply-Message)  -> FALSE
May 07 22:04:06 gw freeradius[574424]: (2)       else {
May 07 22:04:06 gw freeradius[574424]: (2)         [noop] = noop
May 07 22:04:06 gw freeradius[574424]: (2)       } # else = noop
May 07 22:04:06 gw freeradius[574424]: (2)     } # policy remove_reply_message_if_eap = noop
May 07 22:04:06 gw freeradius[574424]: (2)   } # Post-Auth-Type REJECT = updated
May 07 22:04:06 gw freeradius[574424]: (2) Delaying response for 1.000000 seconds
May 07 22:04:06 gw freeradius[574424]: Waking up in 0.3 seconds.
May 07 22:04:06 gw freeradius[574424]: Waking up in 0.6 seconds.
May 07 22:04:07 gw freeradius[574424]: (2) Sending delayed response
May 07 22:04:07 gw freeradius[574424]: (2) Sent Access-Reject Id 190 from 127.0.0.1:1812 to 127.0.0.1:37788 length 20
May 07 22:04:07 gw freeradius[574424]: Waking up in 3.9 seconds.
May 07 22:04:11 gw freeradius[574424]: (2) Cleaning up request packet ID 190 with timestamp +111 due to cleanup_delay was reached
May 07 22:04:11 gw freeradius[574424]: Waking up in 4.8 seconds.
May 07 22:04:15 gw freeradius[574424]: Emitting systemd watchdog notification
May 07 22:04:15 gw freeradius[574424]: Waking up in 29.9 seconds.