problem with mikrotik / freeradius

RouterOS General
1

Hi,

I have setup a hotspot with mikrotik RB450G running version 4.11 software. I also have a freeRadius 2.1.9 server which works fine. The problem is that Mikrotik can not authenticate clients using my radius server. This is from mikrotik’s log

17:20:03 radius,debug new request 3f:3c code=Access-Request service=hotspot called-id=vHotspot
17:20:03 radius,debug sending 3f:3c to X.X.X.X:1812
17:20:03 radius,debug,packet sending Access-Request with id 23 to X.X.X.X:1812
17:20:03 radius,debug,packet     Signature = 0x404a2d4966949dc5fc3107c685b0534d
17:20:03 radius,debug,packet     NAS-Port-Type = 19
17:20:03 radius,debug,packet     Calling-Station-Id = "00:1C:23:8F:9E:19"
17:20:03 radius,debug,packet     Called-Station-Id = "vHotspot"
17:20:03 radius,debug,packet     NAS-Port-Id = "eth3 HOTSPOT"
17:20:03 radius,debug,packet     User-Name = "test1"
17:20:03 radius,debug,packet     NAS-Port = 2156920848
17:20:03 radius,debug,packet     Acct-Session-Id = "80900010"
17:20:03 radius,debug,packet     Framed-IP-Address = 192.168.12.100
17:20:03 radius,debug,packet     MT-Host-IP = 192.168.12.100
17:20:03 radius,debug,packet     CHAP-Challenge = 0xa3657ff1f5e2ab8ce096f754e6d74f2e
17:20:03 radius,debug,packet     CHAP-Password = 0xa5ceb1c383769b17f84337f2b5a7e98d
17:20:03 radius,debug,packet       6c
17:20:03 radius,debug,packet     Service-Type = 1
17:20:03 radius,debug,packet     WISPr-Logoff-URL = "http://192.168.12.1/logout"
17:20:03 radius,debug,packet     NAS-Identifier = "HOTSPOT"
17:20:03 radius,debug,packet     NAS-IP-Address = 192.168.1.3
17:20:03 radius,debug,packet received bad Access-Accept with id 23 from X.X.X.X:1812
17:20:03 radius,debug,packet     Signature = bad 0x9a8d9d1e944358615435655b39c389ad
17:20:03 radius,debug received packet for 3f:3c with bad signature, dropping
17:20:06 radius,debug resending 3f:3c

I can check the account on the server itself and it is working fine:

# radtest test1 test1 127.0.0.1 0 xxxxxxxx
Sending Access-Request of id 8 to 127.0.0.1 port 1812
        User-Name = "test1"
        User-Password = "test1"
        NAS-IP-Address = 127.0.1.1
        NAS-Port = 0
rad_recv: Access-Accept packet from host 127.0.0.1 port 1812, id=8, length=20

and also the freeRadius log is like below, when mikrotik attemps to authenticate the user, it states that Accept message sent to mikrotik. I wonder why mikrotik does say it is bad?

rad_recv: Access-Request packet from host Y.Y.Y.Y port 48718, id=24, length=202
        NAS-Port-Type = Wireless-802.11
        Calling-Station-Id = "00:1C:23:8F:9E:19"
        Called-Station-Id = "vHotspot"
        NAS-Port-Id = "eth3 HOTSPOT"
        User-Name = "test1"
        NAS-Port = 2156920850
        Acct-Session-Id = "80900012"
        Framed-IP-Address = 192.168.12.100
        Mikrotik-Host-IP = 192.168.12.100
        CHAP-Challenge = 0x525d30c725f67c5aa6a17e0e1cc2ad8a
        CHAP-Password = 0xc3deed5b93614cd9062533c82ba81f46b7
        Service-Type = Login-User
        WISPr-Logoff-URL = "http://192.168.12.1/logout"
        NAS-Identifier = "HOTSPOT"
        NAS-IP-Address = 192.168.1.3
Wed Sep  1 17:30:04 2010 : Info: +- entering group authorize {...}
Wed Sep  1 17:30:04 2010 : Info: ++[preprocess] returns ok
Wed Sep  1 17:30:04 2010 : Info: [chap] Setting 'Auth-Type := CHAP'
Wed Sep  1 17:30:04 2010 : Info: ++[chap] returns ok
Wed Sep  1 17:30:04 2010 : Info: ++[mschap] returns noop
Wed Sep  1 17:30:04 2010 : Info: [sql]  expand: %{User-Name} -> test1
Wed Sep  1 17:30:04 2010 : Info: [sql] sql_set_user escaped user --> 'test1'
Wed Sep  1 17:30:04 2010 : Debug: rlm_sql (sql): Reserving sql socket id: 2
Wed Sep  1 17:30:04 2010 : Info: [sql]  expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'test1'           ORDER BY id
Wed Sep  1 17:30:04 2010 : Info: [sql] User found in radcheck table
Wed Sep  1 17:30:04 2010 : Info: [sql]  expand: SELECT id, username, attribute, value, op           FROM radreply           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radreply           WHERE username = 'test1'           ORDER BY id
Wed Sep  1 17:30:04 2010 : Info: [sql]  expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'test1'           ORDER BY priority
Wed Sep  1 17:30:04 2010 : Debug: rlm_sql (sql): Released sql socket id: 2
Wed Sep  1 17:30:04 2010 : Info: ++[sql] returns ok
Wed Sep  1 17:30:04 2010 : Info: ++[expiration] returns noop
Wed Sep  1 17:30:04 2010 : Info: ++[logintime] returns noop
Wed Sep  1 17:30:04 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Wed Sep  1 17:30:04 2010 : Info: ++[pap] returns noop
Wed Sep  1 17:30:04 2010 : Info: Found Auth-Type = CHAP
Wed Sep  1 17:30:04 2010 : Info: +- entering group CHAP {...}
Wed Sep  1 17:30:04 2010 : Info: [chap] login attempt by "test1" with CHAP password
Wed Sep  1 17:30:04 2010 : Info: [chap] Using clear text password "test1" for user test1 authentication.
Wed Sep  1 17:30:04 2010 : Info: [chap] chap user test1 authenticated succesfully
Wed Sep  1 17:30:04 2010 : Info: ++[chap] returns ok
Wed Sep  1 17:30:04 2010 : Info: +- entering group post-auth {...}
Wed Sep  1 17:30:04 2010 : Info: ++[exec] returns noop
Sending Access-Accept of id 24 to Y.Y.Y.Y port 48718
Wed Sep  1 17:30:04 2010 : Info: Finished request 1.
Wed Sep  1 17:30:04 2010 : Debug: Going to the next request
Wed Sep  1 17:30:04 2010 : Debug: Waking up in 4.9 seconds.
Wed Sep  1 17:30:09 2010 : Info: Cleaning up request 1 ID 24 with timestamp +20
Wed Sep  1 17:30:09 2010 : Info: Ready to process requests.

what is going wrong here?

2

I would guess it is the radius secret. Check “/radius” and insure the radius secret is correct.

17:20:03 radius,debug,packet Signature = bad 0x9a8d9d1e944358615435655b39c389ad
17:20:03 radius,debug received packet for 3f:3c with bad signature, dropping

3

Thank you for your response, i have checked the secret and it is ok. The radius server also accepts the request and processes it.

Mikrotik ip is also included in freeradius clients list.

4

It appears to be your router setup. This is the response sent from the radius server:

Sending Access-Accept of id 24 to Y.Y.Y.Y port 48718

This is how it is received by the router:

17:20:03 radius,debug,packet received bad Access-Accept with id 23 from X.X.X.X:1812

Is everything else set on the router? I always use ntp with the hotspot. Maybe the system date/time in the router? And you are certain that is the correct radius secret for this router in the radius clients.conf file?

5

Double check it again. CHAP, accepts on the server and ‘bad request’ on the router is virtually guaranteed to be due to a bad secret or timeouts.

Troubleshooting

My radius server accepts authentication request from the client with “Auth: Login OK:…”, but the user cannot log on. The bad replies counter is incrementing under radius monitor.
This situation can occur, if the radius client and server have high delay link between them. Try to increase the radius client’s timeout to 600ms or more instead of the default 300ms! Also, double check, if the secrets match on client and server!



When RADIUS server is authenticating user with CHAP, MS-CHAPv1, MS-CHAPv2, it is not using shared secret, secret is used only in authentication reply, and router is verifying it. So if you have wrong shared secret, RADIUS server will accept request, but router won’t accept reply. You can see that with /radius monitor command, “bad-replies” number should increase whenever somebody tries to connect.

http://wiki.mikrotik.com/wiki/Manual:RADIUS_Client

6

And given what Tim’s eagle eyes just spotted it is timeouts. The router sends an ACCESS-REQUEST. The server sends an ACCESS-ACCEPT, but so late that the router has already sent another request. It treats the original reply as one to the second request (RADIUS is more or less stateless) and discards it as bad because it doesn’t match.

7

I have changed public IP of my radius server to x.x.x.x and that of mikrotik to y.y.y.y to avoid security risks

radius is sending access accept to y.y.y.y (it is my mikrotik)
and mikrotik is recieving it from x.x.x.x (radius server)

8

@fewi. I think that would also generate a “radius server not found” on the login page tho.

Is that part of the fail? Otherwise, I still suspect radius secret if this error is not present. If it is, then timeout would be the challenge.

9

the timestamps on logs from radius and mikrotik are not related to the same request/response pair. this is why their is a huge gap between them. the actual link is not slow.

i have also set the timeout to 3000 msec

10

You have only one entry in the “/radius” settings on the router? I still think radius secret.

11

The secret was indeed wrong. I had tried retyping the radius secret a few times before posting this topic but i was wrong. Anyway it is working now, but I have a new problem.

It authenticates users i create by inserting into the database, but does not authenticate users i create with dialup admin, it seems that dialup admin encrypts the passwords and inserts them into the table but freeradius does not expect encrypted passwords.

thank you everybody for your support

12

This is a little off-topic, but it is a dialup admin setting. You need to change the encryption method.
http://wiki.freeradius.org/Dialup_admin#Encryption_Method
Default is md5. You want clear.