Hey all,
I just upgraded my routerboard from RouterOS 5.26 to 6.30.2, and when I did, I lost my ability to VPN into our domain. I’m using Radius and Network Policy Server
Here’s some basic information about the setup:
Routerboard: RB951G-2HnD w RouterOS 6.30.2. Using PPTP and Radius.
Domain Server: Windows Server 2012 R2, Network Policy Server running Radius, Domain=SR
Network
After the upgrade, I get the following error:
user testuser authentication failed - radius timeout
Detailed logging shows the following:
Aug/05/2015 11:19:07 pptp,ppp,debug,packet E=691 R=0 C=9ECBEFFD3C5292A4D7526BF7D71D6B14 V=3 M=bad username or password
I’ve quadruple checked that the username and password are correct. Besides the RouterOS update, nothing changed. It’s still using the correct Domain (SR) and correct username/pwd. I reset the pwd on a couple test accounts to make sure it is correct.
When looking at the Radius logs on the server, I don’t see any logs at all after the Router upgrade, so I’m not sure it’s even talking to the server anymore.
Here are the detailed connection logs:
Aug/05/2015 12:03:42 pptp,info TCP connection established from 192.168.12.6
Aug/05/2015 12:03:42 pptp,debug,packet rcvd Start-Control-Connection-Request from 192.168.12.6
Aug/05/2015 12:03:42 pptp,debug,packet protocol-version=0x0100
Aug/05/2015 12:03:42 pptp,debug,packet framing-capabilities=1
Aug/05/2015 12:03:42 pptp,debug,packet bearer-capabilities=1
Aug/05/2015 12:03:42 pptp,debug,packet maximum-channels=0
Aug/05/2015 12:03:42 pptp,debug,packet firmware-revision=0
Aug/05/2015 12:03:42 pptp,debug,packet host-name=
Aug/05/2015 12:03:42 pptp,debug,packet vendor-name=Microsoft
Aug/05/2015 12:03:42 pptp,debug,packet sent Start-Control-Connection-Reply to 192.168.12.6
Aug/05/2015 12:03:42 pptp,debug,packet protocol-version=0x0100
Aug/05/2015 12:03:42 pptp,debug,packet result-code=1
Aug/05/2015 12:03:42 pptp,debug,packet error-code=0
Aug/05/2015 12:03:42 pptp,debug,packet framing-capabilities=2
Aug/05/2015 12:03:42 pptp,debug,packet bearer-capabilities=0
Aug/05/2015 12:03:42 pptp,debug,packet maximum-channels=0
Aug/05/2015 12:03:42 pptp,debug,packet firmware-revision=1
Aug/05/2015 12:03:42 pptp,debug,packet host-name=SR-RB01
Aug/05/2015 12:03:42 pptp,debug,packet vendor-name=MikroTik
Aug/05/2015 12:03:42 pptp,debug,packet rcvd Outgoing-Call-Request from 192.168.12.6
Aug/05/2015 12:03:42 pptp,debug,packet call-id=37726
Aug/05/2015 12:03:42 pptp,debug,packet call-serial-number=33
Aug/05/2015 12:03:42 pptp,debug,packet minimum-bps=300
Aug/05/2015 12:03:42 pptp,debug,packet maximum-bps=100000000
Aug/05/2015 12:03:42 pptp,debug,packet bearer-type=3
Aug/05/2015 12:03:42 pptp,debug,packet framing-type=3
Aug/05/2015 12:03:42 pptp,debug,packet packet-recv-window-size=64
Aug/05/2015 12:03:42 pptp,debug,packet packet-processing-delay=0
Aug/05/2015 12:03:42 pptp,debug,packet phone-number-length=0
Aug/05/2015 12:03:42 pptp,debug,packet phone-number=
Aug/05/2015 12:03:42 pptp,debug,packet subaddress=
Aug/05/2015 12:03:42 pptp,ppp,debug <21>: LCP lowerup
Aug/05/2015 12:03:42 pptp,ppp,debug <21>: LCP open
Aug/05/2015 12:03:42 pptp,debug,packet sent Outgoing-Call-Reply to 192.168.12.6
Aug/05/2015 12:03:42 pptp,debug,packet call-id=21
Aug/05/2015 12:03:42 pptp,debug,packet peers-call-id=37726
Aug/05/2015 12:03:42 pptp,debug,packet result-code=1
Aug/05/2015 12:03:42 pptp,debug,packet error-code=0
Aug/05/2015 12:03:42 pptp,debug,packet cause-code=0
Aug/05/2015 12:03:42 pptp,debug,packet connect-speed=100000
Aug/05/2015 12:03:42 pptp,debug,packet packet-recv-window-size=100
Aug/05/2015 12:03:42 pptp,debug,packet packet-processing-delay=0
Aug/05/2015 12:03:42 pptp,debug,packet physical-channel-id=0
Aug/05/2015 12:03:42 pptp,debug,packet rcvd Set-Link-Info from 192.168.12.6
Aug/05/2015 12:03:42 pptp,debug,packet peers-call-id=21
Aug/05/2015 12:03:42 pptp,debug,packet send-accm=0xffffffff
Aug/05/2015 12:03:42 pptp,debug,packet receive-accm=0xffffffff
Aug/05/2015 12:03:42 pptp,debug,packet sent Set-Link-Info to 192.168.12.6
Aug/05/2015 12:03:42 pptp,debug,packet peers-call-id=37726
Aug/05/2015 12:03:42 pptp,debug,packet send-accm=0xffffffff
Aug/05/2015 12:03:42 pptp,debug,packet receive-accm=0xffffffff
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <21>: rcvd LCP ConfReq id=0x0
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <mru 1400>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <magic 0x53b14020>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <pcomp>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <accomp>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <callback 0x06>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <21>: sent LCP ConfReq id=0x1
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <mru 1460>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <magic 0x2179e7f>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <auth mschap2>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <21>: sent LCP ConfRej id=0x0
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <pcomp>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <accomp>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <21>: rcvd LCP ConfAck id=0x1
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <mru 1460>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <magic 0x2179e7f>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <auth mschap2>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <21>: rcvd LCP ConfReq id=0x1
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <mru 1400>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <magic 0x53b14020>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <callback 0x06>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <21>: sent LCP ConfAck id=0x1
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <mru 1400>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <magic 0x53b14020>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <callback 0x06>
Aug/05/2015 12:03:42 pptp,ppp,debug <21>: LCP opened
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <21>: sent CHAP Challenge id=0x1
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <challenge len=16>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <name SR-RB01>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <21>: rcvd LCP Ident id=0x2
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <magic 0x53b14020>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet MSRASV5.20
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <21>: rcvd LCP Ident id=0x3
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <magic 0x53b14020>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet MSRAS-0-SR-0200
Aug/05/2015 12:03:42 pptp,debug,packet rcvd Set-Link-Info from 192.168.12.6
Aug/05/2015 12:03:42 pptp,debug,packet peers-call-id=21
Aug/05/2015 12:03:42 pptp,debug,packet send-accm=0xffffffff
Aug/05/2015 12:03:42 pptp,debug,packet receive-accm=0xffffffff
Aug/05/2015 12:03:42 pptp,debug,packet sent Set-Link-Info to 192.168.12.6
Aug/05/2015 12:03:42 pptp,debug,packet peers-call-id=37726
Aug/05/2015 12:03:42 pptp,debug,packet send-accm=0xffffffff
Aug/05/2015 12:03:42 pptp,debug,packet receive-accm=0xffffffff
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <21>: rcvd LCP Ident id=0x4
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <magic 0x53b14020>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet UJìjéÿHŽFì»üÍë
Aug/05/2015 12:03:42 radius,debug new request 1b:20 code=Access-Request service=ppp called-id=27.052.214.11 domain=SR
Aug/05/2015 12:03:42 radius,debug sending 1b:20 to 192.168.3.1:1812
Aug/05/2015 12:03:42 radius,debug,packet sending Access-Request with id 31 to 192.168.3.1:1812
Aug/05/2015 12:03:42 radius,debug,packet Signature = 0xf72841221cc5ec47bcfc7199c3c353f4
Aug/05/2015 12:03:42 radius,debug,packet Service-Type = 2
Aug/05/2015 12:03:42 radius,debug,packet Framed-Protocol = 1
Aug/05/2015 12:03:42 radius,debug,packet NAS-Port = 15728661
Aug/05/2015 12:03:42 radius,debug,packet NAS-Port-Type = 5
Aug/05/2015 12:03:42 radius,debug,packet User-Name = "testuser"
Aug/05/2015 12:03:42 radius,debug,packet Calling-Station-Id = "192.168.12.6"
Aug/05/2015 12:03:42 radius,debug,packet Called-Station-Id = "27.052.214.11"
Aug/05/2015 12:03:42 radius,debug,packet MS-CHAP-Domain = "SR"
Aug/05/2015 12:03:42 radius,debug,packet MS-CHAP-Challenge = 0x40426eb223543809c83246cbd44928a3
Aug/05/2015 12:03:42 radius,debug,packet MS-CHAP2-Response = 0x01007ea556cc68df433cef5a87c4a168
Aug/05/2015 12:03:42 radius,debug,packet b2650000000000000000b1b2f8dd0c8d
Aug/05/2015 12:03:42 radius,debug,packet 6adf6435fe69543870a4331fe2b98c43
Aug/05/2015 12:03:42 radius,debug,packet 4fab
Aug/05/2015 12:03:42 radius,debug,packet NAS-Identifier = "SR-RB01"
Aug/05/2015 12:03:42 radius,debug,packet MT-Realm = 0x544c
Aug/05/2015 12:03:42 radius,debug,packet NAS-IP-Address = 192.168.0.1
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <21>: rcvd CHAP Response id=0x1
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <response len=49>
Aug/05/2015 12:03:42 pptp,ppp,debug,packet <name SR\testuser>
Aug/05/2015 12:03:43 radius,debug resending 1b:20
Aug/05/2015 12:03:43 radius,debug,packet sending Access-Request with id 31 to 192.168.3.1:1812
Aug/05/2015 12:03:43 radius,debug,packet Signature = 0xf72841221cc5ec47bcfc7199c3c353f4
Aug/05/2015 12:03:43 radius,debug,packet Service-Type = 2
Aug/05/2015 12:03:43 radius,debug,packet Framed-Protocol = 1
Aug/05/2015 12:03:43 radius,debug,packet NAS-Port = 15728661
Aug/05/2015 12:03:43 radius,debug,packet NAS-Port-Type = 5
Aug/05/2015 12:03:43 radius,debug,packet User-Name = "testuser"
Aug/05/2015 12:03:43 radius,debug,packet Calling-Station-Id = "192.168.12.6"
Aug/05/2015 12:03:43 radius,debug,packet Called-Station-Id = "27.052.214.11"
Aug/05/2015 12:03:43 radius,debug,packet MS-CHAP-Domain = "SR"
Aug/05/2015 12:03:43 radius,debug,packet MS-CHAP-Challenge = 0x40426eb223543809c83246cbd44928a3
Aug/05/2015 12:03:43 radius,debug,packet MS-CHAP2-Response = 0x01007ea556cc68df433cef5a87c4a168
Aug/05/2015 12:03:43 radius,debug,packet b2650000000000000000b1b2f8dd0c8d
Aug/05/2015 12:03:43 radius,debug,packet 6adf6435fe69543870a4331fe2b98c43
Aug/05/2015 12:03:43 radius,debug,packet 4fab
Aug/05/2015 12:03:43 radius,debug,packet NAS-Identifier = "SR-RB01"
Aug/05/2015 12:03:43 radius,debug,packet MT-Realm = 0x544c
Aug/05/2015 12:03:43 radius,debug,packet NAS-IP-Address = 192.168.0.1
Aug/05/2015 12:03:44 pptp,ppp,debug,packet <21>: rcvd CHAP Response id=0x1
Aug/05/2015 12:03:44 pptp,ppp,debug,packet <response len=49>
Aug/05/2015 12:03:44 pptp,ppp,debug,packet <name SR\testuser>
Aug/05/2015 12:03:44 pptp,ppp,debug <21>: CHAP received response, but auth. in progress: dropping
Aug/05/2015 12:03:44 radius,debug resending 1b:20
Aug/05/2015 12:03:44 radius,debug,packet sending Access-Request with id 31 to 192.168.3.1:1812
Aug/05/2015 12:03:44 radius,debug,packet Signature = 0xf72841221cc5ec47bcfc7199c3c353f4
Aug/05/2015 12:03:44 radius,debug,packet Service-Type = 2
Aug/05/2015 12:03:44 radius,debug,packet Framed-Protocol = 1
Aug/05/2015 12:03:44 radius,debug,packet NAS-Port = 15728661
Aug/05/2015 12:03:44 radius,debug,packet NAS-Port-Type = 5
Aug/05/2015 12:03:44 radius,debug,packet User-Name = "testuser"
Aug/05/2015 12:03:44 radius,debug,packet Calling-Station-Id = "192.168.12.6"
Aug/05/2015 12:03:44 radius,debug,packet Called-Station-Id = "27.052.214.11"
Aug/05/2015 12:03:44 radius,debug,packet MS-CHAP-Domain = "SR"
Aug/05/2015 12:03:44 radius,debug,packet MS-CHAP-Challenge = 0x40426eb223543809c83246cbd44928a3
Aug/05/2015 12:03:44 radius,debug,packet MS-CHAP2-Response = 0x01007ea556cc68df433cef5a87c4a168
Aug/05/2015 12:03:44 radius,debug,packet b2650000000000000000b1b2f8dd0c8d
Aug/05/2015 12:03:44 radius,debug,packet 6adf6435fe69543870a4331fe2b98c43
Aug/05/2015 12:03:44 radius,debug,packet 4fab
Aug/05/2015 12:03:44 radius,debug,packet NAS-Identifier = "SR-RB01"
Aug/05/2015 12:03:44 radius,debug,packet MT-Realm = 0x544c
Aug/05/2015 12:03:44 radius,debug,packet NAS-IP-Address = 192.168.0.1
Aug/05/2015 12:03:45 pptp,ppp,debug,packet <21>: sent CHAP Failure id=0x1
Aug/05/2015 12:03:45 pptp,ppp,debug,packet E=691 R=0 C=40426EB223543809C83246CBD44928A3 V=3 M=bad username or password
Aug/05/2015 12:03:45 pptp,ppp,error <21>: user testuser authentication failed - radius timeout
Aug/05/2015 12:03:45 pptp,ppp,debug <21>: LCP close
Aug/05/2015 12:03:45 pptp,ppp,debug <21>: LCP closed
Aug/05/2015 12:03:45 pptp,ppp,debug,packet <21>: sent LCP TermReq id=0x2
Aug/05/2015 12:03:45 pptp,ppp,debug,packet user testuser authentication failed - radius timeout
Aug/05/2015 12:03:45 radius,debug timeout for 1b:20
Aug/05/2015 12:03:45 pptp,ppp,debug,packet <21>: rcvd LCP TermAck id=0x2
Aug/05/2015 12:03:45 pptp,ppp,debug,packet user testuser authentication failed - radius timeout
Aug/05/2015 12:03:45 pptp,ppp,debug <21>: LCP lowerdown
Aug/05/2015 12:03:45 pptp,ppp,debug <21>: LCP lowerdown
Aug/05/2015 12:03:45 pptp,ppp,debug <21>: LCP down event in initial state