| *** WiKIDLogBot (~WiKIDLogB@ec2-174-129-6-100.compute-1.amazonaws.com) has joined #wikid | 13:33 | |
| morgan.freenode.net | Topic for #wikid is: #wikid WiKID's IRC support channel. Logs are here: http://www.wikidsystems.com/webdemo/irclogs/index.html. If no one is here use the forums: http://www.wikidsystems.com/support/support/wikid-forums | 13:33 |
|---|---|---|
| morgan.freenode.net | Users on #wikid: WiKIDLogBot @nowen coolacid mitzip joevano | 13:33 |
| *** datawire (42f18379@gateway/web/freenode/ip.66.241.131.121) has joined #wikid | 13:40 | |
| *** datawire has quit (Quit: Page closed) | 16:55 | |
| *** datawire (42f18379@gateway/web/freenode/ip.66.241.131.121) has joined #wikid | 16:55 | |
| datawire | nick you around today? | 17:07 |
| nowen | yes | 17:07 |
| datawire | new fun issue, driving me batty | 17:07 |
| nowen | ok - what's going on? | 17:07 |
| datawire | Peer <name> failed CHAP authentication | 17:08 |
| nowen | is that from the WiKID logs? | 17:08 |
| datawire | from /var/log/messages | 17:08 |
| nowen | are you using pam radius? | 17:09 |
| datawire | hmm dont think so.. did see that as a requirement | 17:10 |
| datawire | didnt* | 17:10 |
| nowen | are you saying that that message is in /var/log/messages on the WiKID server? | 17:10 |
| datawire | yes | 17:10 |
| nowen | we don't write to that file | 17:11 |
| datawire | if I disable wikid and just use the ultra secure secret file I auth, obviously not what I'm after :) | 17:11 |
| nowen | what are you trying to login into? | 17:12 |
| datawire | simple ppp | 17:12 |
| nowen | but you're not trying to login to the WiKID server, correct? | 17:12 |
| datawire | I have created my token and it worked correctly, if I turn off wikid and just use poptop with the secret I am able to auth and grab my ip, once I enable the radius plugins again the above error is in messages | 17:14 |
| nowen | ok - is poptop running on the WiKID server? | 17:14 |
| datawire | yes | 17:15 |
| nowen | what error messages do you see in the WiKIDAdmin logs? | 17:15 |
| datawire | no "error" listed | 17:19 |
| nowen | do you see the rejection? | 17:19 |
| datawire | no this is what I have for the last 2 entries | 17:19 |
| datawire | 2013-07-16 17:14:50.637DEBUGcom.mchange.v2.resourcepool.BasicResourcePooltrace com.mchange.v2.resourcepool.BasicResourcePool@3804dd1b [managed: 3, unused: 2, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@42143753) 2013-07-16 17:14:50.636INFOcom.wikidsystems.server.DeviceTransactionExecIssued passcode to device -6005780771593678145 | 17:19 |
| nowen | ok | 17:20 |
| nowen | if the last thing you see is the passcode being issued, the radius request is not getting to WiKID | 17:20 |
| nowen | what is the IP address of the network client you created? | 17:20 |
| datawire | the private lan? | 17:20 |
| nowen | it should be listed under the Network Client tab | 17:21 |
| datawire | ahh 127.0.0.1 | 17:21 |
| nowen | ok - you need to delete that and use the private ip of the WiKID server. | 17:22 |
| nowen | the radius listener is using the localhost, so you can't use that | 17:22 |
| datawire | think I was already down this rouad but I'm willing to play :) | 17:22 |
| nowen | after you make the change, you need to restart wikdi | 17:23 |
| datawire | pppd[15180]: Peer <name> failed CHAP authentication | 17:28 |
| nowen | ok - what is the wikidadmin log message? | 17:29 |
| datawire | 2013-07-16 17:28:01.179DEBUGcom.mchange.v2.resourcepool.BasicResourcePooltrace com.mchange.v2.resourcepool.BasicResourcePool@4d3af084 [managed: 3, unused: 2, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@5675b3ee) 2013-07-16 17:28:01.177INFOcom.wikidsystems.server.DeviceTransactionExecIssued passcode to device -6005780771593678145 | 17:29 |
| nowen | still no radius request getting to wikid. what IP are you using to point ppp to wikid? | 17:30 |
| datawire | from my radiusclient conf -> authserver 10.7.1.14:1812 | 17:32 |
| datawire | acctserver 10.7.1.14:1812 | 17:32 |
| nowen | is that private ip of the WiKID server? | 17:33 |
| datawire | correct | 17:34 |
| nowen | is this the latest version that you just setup? | 17:34 |
| datawire | wikid-server-enterprise-3.5.0.b1438-1.noarch.rpm | 17:35 |
| datawire | ya its been a bit of a learning curve from the last version I setup a year or so ago | 17:36 |
| nowen | will stop wikid and then run 'netstat -anp | grep 1812' and make sure radius has stopped | 17:36 |
| nowen | it is much easier and more secure to do ppp on a different box. | 17:36 |
| nowen | we highly recommend you not run anything else on the box | 17:36 |
| datawire | :) noted I needed a cheap and fast "DR" vpn portal to satisfy certain powers that dont agree things take time :) | 17:38 |
| nowen | lol | 17:40 |
| datawire | stopped and radius server down | 17:40 |
| nowen | you can see the radius transactions by running 'tcpdump -i lo port radius' | 17:41 |
| datawire | sorry about that, thought I was onto something and tried a couple of things. still nothing over radius from tcpdump | 17:50 |
| nowen | so you don't see ppp making a radius request to WiKID? | 17:53 |
| datawire | not at all | 17:56 |
| nowen | well, that would be a problem | 17:57 |
| datawire | I'm still seeing this in my message logs | 17:58 |
| datawire | Jul 16 17:56:33 servername pptpd[20090]: CTRL: Starting call (launching pppd, opening GRE) Jul 16 17:56:33 servername pppd[20091]: Plugin radius.so loaded. Jul 16 17:56:33 servername pppd[20091]: RADIUS plugin initialized. Jul 16 17:56:33 servername pppd[20091]: Plugin radattr.so loaded. Jul 16 17:56:33 servername pppd[20091]: RADATTR plugin initialized. Jul 16 17:56:33 servername pppd[20091]: Plugin /usr/lib64/pptpd/pptpd-logwtmp.s | 17:58 |
| datawire | Jul 16 17:56:33 servername pppd[20091]: pppd 2.4.5 started by user, uid 0 Jul 16 17:56:33 servername pppd[20091]: Using interface ppp0 Jul 16 17:56:33 servername pppd[20091]: Connect: ppp0 <--> /dev/pts/4 Jul 16 17:56:36 servername pptpd[20090]: CTRL: Ignored a SET LINK INFO packet with real ACCMs! Jul 16 17:56:36 servername pppd[20091]: rc_avpair_new: unknown attribute 6 Jul 16 17:56:36 servername pppd[20091]: rc_avpair_new: unknow | 17:59 |
| nowen | it's been a while since I did anything with poptop | 17:59 |
| datawire | i'm wondering if the radisu plugins are bad in this version.. scratching my head | 18:00 |
| nowen | I don't know. | 18:00 |
| nowen | is there a changelog for it? | 18:00 |
| datawire | Nothing about radius in the readme since 2.4.3 I'm using 2.4.5 | 18:04 |
| nowen | are you following this doc: http://www.howtoforge.com/security-issues-and-poptop-pptp | 18:05 |
| datawire | I pretty much copied from the working host (different versions and ips) to this one I'll take a gander give me a moment | 18:10 |
| nowen | biab, phone call | 18:47 |
| *** nowen has quit (Read error: Connection reset by peer) | 18:51 | |
| *** nowen (~nowen@99-174-93-102.lightspeed.tukrga.sbcglobal.net) has joined #wikid | 18:51 | |
| *** nowen has quit (Quit: Leaving.) | 19:01 | |
| *** nowen (~nowen@99-174-93-102.lightspeed.tukrga.sbcglobal.net) has joined #wikid | 19:02 | |
| *** nowen has quit (Client Quit) | 19:04 | |
| *** nowen (~nowen@99-174-93-102.lightspeed.tukrga.sbcglobal.net) has joined #wikid | 19:05 | |
| datawire | ok progress maybe.. | 19:05 |
| datawire | 2013-07-16 19:03:11.233 INFO com.wikidsystems.radius.access.WikidAccess4 Access denied for USER, domain code: 069046100092 client: /10.7.1.14 2013-07-16 19:03:11.233 INFO com.wikidsystems.radius.log.DBSvrLogImpl <238> Access-Request(1) LEN=69 10.7.1.14:28610 Access-Request by USER Failed: AccessRejectException: Access Denied | 19:05 |
| nowen | there we go | 19:11 |
| nowen | is the user enabled? check the user tab | 19:12 |
| datawire | he is, I also just removed and recreated the user again | 19:13 |
| datawire | same thing | 19:13 |
| nowen | http://www.wikidsystems.com/support/wikid-support-center/troubleshooting-faq/how-can-i-set-radius-logging-to-debug-how-can-i-see-if-wikid-is-getting-the-radius-requests | 19:13 |
| nowen | set logging to debug and you will get more info on why | 19:13 |
| datawire | nothing jumping off the page as to the failure cause | 19:22 |
| nowen | did you set the logging to debug? | 19:27 |
| datawire | I did | 19:31 |
| datawire | 013-07-16 19:28:17.808 DEBUG com.wikidsystems.radius.log.DBDbgLogImpl <247> Access-Request(1) LEN=66 10.7.1.14:25954 Access-Request by USER Failed: AccessRejectException: Access Denied 2013-07-16 19:28:17.807 DEBUG com.wikidsystems.radius.access.WikidAccess4 PAP Request 2013-07-16 19:28:17.807 DEBUG com.wikidsystems.radius.access.WikidAccess4 NASip is '10.7.1.14 | 19:31 |
| nowen | there should be a lot more messages, including one on the reason, if you have debugging setup as per that page | 19:38 |
| datawire | com.wikidsystems.wauth isnt in my drop down however com.wikidsystems.server.wAuth was populated I set it to debug the other I already had at debug | 19:43 |
| datawire | here is the full spam error | 19:43 |
| nowen | you might need to post it to pastebin | 19:44 |
| datawire | was going to email it but can find your address | 19:48 |
| datawire | also your http://www.wikidsystems.com/contact-us/contact has some "interesting" budget-priced ed pills stuff on it | 19:50 |
| nowen | damn | 19:51 |
| nowen | post it to pastebin.com. then, post the url back here | 19:51 |
| datawire | http://pastebin.com/s4u1AVGa | 19:52 |
| nowen | all that has is the packet arriving | 19:57 |
| datawire | thats all the log has in it | 19:58 |
| nowen | you're looking at the WiKIDAdmin logs? | 19:59 |
| datawire | correct | 19:59 |
| nowen | hmm | 20:00 |
| nowen | you have com.wikidsystems.radius.log.DBSvrLogImpl set to debug? | 20:00 |
| datawire | bad install maybe? Also the radius "fix" was a tab between server name and secret | 20:00 |
| nowen | what do you mean radius fix? | 20:00 |
| datawire | I was running back though all my changes and the ppp talking to radius came down to the server file not being tab delimited | 20:01 |
| nowen | all | 20:02 |
| nowen | ahh | 20:02 |
| datawire | like I said very odd, the server is all but a copy of the one I set up last year just newer binaries | 20:02 |
| datawire | think I'm just going to scrap it and start clean, we're both spending way too much time on this :) | 20:19 |
| nowen | let's run through some things first | 20:19 |
| datawire | sure | 20:19 |
| nowen | ok | 20:20 |
| nowen | on the configure loggers page, do you have 4 loggers set to debug? | 20:21 |
| datawire | I have the following set to debug | 20:21 |
| datawire | HTTP Access Logger com.wikidsystems com.wikidsystems.client.wClient com.wikidsystems.radius.access.WikidAccess4 com.wikidsystems.radius.log.DBSvrLogImpl com.wikidsystems.server.wAuth org.apache | 20:21 |
| nowen | ok - set http access and org.apache to warn. | 20:22 |
| nowen | then get an OTP and try to login again | 20:24 |
| datawire | http://pastebin.com/FxBV2i87 | 20:26 |
| nowen | there's only one domain on this box? | 20:28 |
| datawire | split horizon datawire.net external .dw internal | 20:29 |
| datawire | but they are on different interfaces | 20:29 |
| nowen | wikid domain, that is.069046100092 | 20:29 |
| nowen | and iber is listed as enabled on the user page currently? | 20:30 |
| datawire | yes | 20:33 |
| nowen | something a bit odd about that request | 20:35 |
| nowen | I'm testing | 20:40 |
| datawire | ok | 20:44 |
| nowen | do you now see the otp in the logs? | 20:45 |
| nowen | s/now/not | 20:46 |
| datawire | New device7028543067963798156 added to server. | 20:47 |
| nowen | that was probably me | 20:47 |
| datawire | there is a cert payload etc | 20:48 |
| nowen | i didn't set the pin, just checking that the domain worked | 20:48 |
| datawire | ok | 20:48 |
| nowen | and this is a supposed to be a pap request? | 20:49 |
| datawire | no chap-v2 | 20:50 |
| nowen | well, the logs show it as a pap | 20:50 |
| datawire | thats one of the things that struck me as odd | 20:50 |
| nowen | I think your ppp is misconfigured | 20:50 |
| nowen | you should see: RADIUS client supplied passcode is `?y?L?O?ICT44i1q?^?,h?P?aB??L? | 20:51 |
| nowen | and:This is a CHAP Request | 20:51 |
| datawire | the config has the following refuse-pap refuse-eap refuse-chap refuse-mschap require-mschap-v2 | 20:51 |
| nowen | i don't know | 20:54 |
| datawire | Hence why I finally came loking for help, this is just odd | 20:55 |
| nowen | does the other server use chapv2? | 20:58 |
| datawire | yes | 20:58 |
| nowen | hmm - i seem to recall an issue with the dictionaries | 21:05 |
| nowen | can you check your dictionary.microsoft on both servers - maybe run a diff on them | 21:05 |
| datawire | thats where I was leaning | 21:08 |
| nowen | does you dictionary have the word octet in it? | 21:16 |
| datawire | good lord... fixed | 21:19 |
| nowen | what was it? | 21:19 |
| datawire | added to the end of the following file /usr/share/radiusclient-ng/dictionary | 21:19 |
| datawire | INCLUDE /usr/share/radiusclient-ng/dictionary.microsoft | 21:20 |
| datawire | moved my ms dict to that folder... all problems went away | 21:20 |
| datawire | serious /facepalm I even made a note in the dictionary folder on the other vpn server because the http://www.howtoforge.com/security-issues-and-poptop-pptp ln-s symlink didnt work for me last time | 21:22 |
| nowen | that makes sense | 21:22 |
| datawire | only after you suggested the ms dict file that I started diffing everything.. and sure enough my note was there | 21:22 |
| nowen | lol | 21:22 |
| datawire | ahem... you can update your doc :) | 21:23 |
| nowen | maybe. we're not exactly encouraging people to use chap-v2 ;-) | 21:23 |
| datawire | I hear that, baby steps around here. Much thanks for the assist over the couple of sessions | 21:25 |
| nowen | np | 21:25 |
| datawire | maybe I'll give ya my "people kept locking their accounts out so I made a auto unlock and notify account unlock" script :) | 21:26 |
| nowen | we created a new parameter called :reEnableHours | 21:27 |
| nowen | create a New Parameter called 'reEnableHours'. Set the number of hours in the Value field and give it a description such as 'Renable users after X hours'. Leave Class empty. | 21:27 |
| datawire | but wheres the notification? :) | 21:28 |
| nowen | true, true! | 21:28 |
| datawire | http://pastebin.com/csVqXj9j keep use destroy as you see fit, I need a way to audit the users obviously it hasnt been tested with the newest versions | 21:30 |
| nowen | thx | 21:38 |
| datawire | anytime | 21:39 |
| nowen | ok - later guys | 22:00 |
| *** nowen has quit (Quit: Leaving.) | 22:00 | |
| *** joevano has quit (*.net *.split) | 22:43 | |
| *** coolacid has quit (*.net *.split) | 22:43 | |
| *** mitzip has quit (*.net *.split) | 22:43 | |
| *** datawire has quit (*.net *.split) | 22:43 | |
| *** datawire (42f18379@gateway/web/freenode/ip.66.241.131.121) has joined #wikid | 22:44 | |
| *** joevano (~joevano@bzflag/developer/JoeVano) has joined #wikid | 22:44 | |
| *** mitzip (~mitzip@96-8-190-240.block0.gvtc.com) has joined #wikid | 22:44 | |
| *** coolacid (~CoolAcid@unaffiliated/coolacid) has joined #wikid | 22:44 | |
Generated by irclog2html.py 2.11.0 by Marius Gedminas - find it at mg.pov.lt!