18.02.2010 10:05:44
 adaptive Posts: 2
|
Hi! TekRADIUS stop when we try to authenticate.
18.02.2010 08:20:28 - TekRADIUS Service 3.4.0.0 is being started (Microsoft Windows NT 5.2.3790 Service Pack 2). 18.02.2010 08:20:29 - TekRADIUS Service is listening on : 10.99.10.17 (3 client(s))
Event Type: Error Event Source: .NET Runtime 2.0 Error Reporting Event Category: None Event ID: 5000 Date: 18.02.2010 Time: 08:23:43 User: N/A Computer: ADAPCRM Description: EventType clr20r3, P1 tekradius.exe, P2 3.4.0.0, P3 4b587657, P4 tekradius, P5 3.4.0.0, P6 4b587657, P7 5b, P8 0, P9 system.indexoutofrangeexception, P10 NIL. For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp. Data: 0000: 63 00 6c 00 72 00 32 00 c.l.r.2. 0008: 30 00 72 00 33 00 2c 00 0.r.3.,. 0010: 20 00 74 00 65 00 6b 00 .t.e.k. 0018: 72 00 61 00 64 00 69 00 r.a.d.i. 0020: 75 00 73 00 2e 00 65 00 u.s...e. 0028: 78 00 65 00 2c 00 20 00 x.e.,. . 0030: 33 00 2e 00 34 00 2e 00 3...4... 0038: 30 00 2e 00 30 00 2c 00 0...0.,. 0040: 20 00 34 00 62 00 35 00 .4.b.5. 0048: 38 00 37 00 36 00 35 00 8.7.6.5. 0050: 37 00 2c 00 20 00 74 00 7.,. .t. 0058: 65 00 6b 00 72 00 61 00 e.k.r.a. 0060: 64 00 69 00 75 00 73 00 d.i.u.s. 0068: 2c 00 20 00 33 00 2e 00 ,. .3... 0070: 34 00 2e 00 30 00 2e 00 4...0... 0078: 30 00 2c 00 20 00 34 00 0.,. .4. 0080: 62 00 35 00 38 00 37 00 b.5.8.7. 0088: 36 00 35 00 37 00 2c 00 6.5.7.,. 0090: 20 00 35 00 62 00 2c 00 .5.b.,. 0098: 20 00 30 00 2c 00 20 00 .0.,. . 00a0: 73 00 79 00 73 00 74 00 s.y.s.t. 00a8: 65 00 6d 00 2e 00 69 00 e.m...i. 00b0: 6e 00 64 00 65 00 78 00 n.d.e.x. 00b8: 6f 00 75 00 74 00 6f 00 o.u.t.o. 00c0: 66 00 72 00 61 00 6e 00 f.r.a.n. 00c8: 67 00 65 00 65 00 78 00 g.e.e.x. 00d0: 63 00 65 00 70 00 74 00 c.e.p.t. 00d8: 69 00 6f 00 6e 00 20 00 i.o.n. . 00e0: 4e 00 49 00 4c 00 0d 00 N.I.L... 00e8: 0a 00 ..
|
|
• permalink
• reply with quote
|
19.02.2010 12:02:26
 admin Administrator Posts: 881
|
Hi,
Can you send me TekRADIUS.ini, user and group profile configured?
Best regards,
Yasin KAPLAN
|
|
• permalink
• reply with quote
|
19.02.2010 16:25:39
 admin Administrator Posts: 881
|
Please also send a Wireshark trace for the incoming RADIUS Authentication request if possible.
|
|
• permalink
• reply with quote
|
02.03.2010 21:33:45
 adaptive Posts: 2
|
Hi and thanks! Sorry for the late reply! We don't have this problem anymore. Adaptive
|
|
• permalink
• reply with quote
|
02.03.2010 21:35:17
 admin Administrator Posts: 881
|
You welcome
|
|
• permalink
• reply with quote
|
16.04.2010 17:34:21
 rjl Posts: 8
|
Hi,
I'm running into a similar issue. From the look of it, the TekRadius svc. (running on Windows 2k3) is crashing every 3 or 4 minutes. Here is the Windows Event:
Event Type: Error Event Source: .NET Runtime 2.0 Error Reporting Event Category: None Event ID: 5000 Date: 4/16/2010 Time: 10:14:04 AM User: N/A Computer: DC1 Description: EventType clr20r3, P1 tekradius.exe, P2 3.0.0.0, P3 49ba5add, P4 mscorlib, P5 2.0.0.0, P6 4889dc80, P7 36e3, P8 8c, P9 system.indexoutofrangeexception, P10 NIL.
For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp. Data: 0000: 63 00 6c 00 72 00 32 00 c.l.r.2. 0008: 30 00 72 00 33 00 2c 00 0.r.3.,. 0010: 20 00 74 00 65 00 6b 00 .t.e.k. 0018: 72 00 61 00 64 00 69 00 r.a.d.i. 0020: 75 00 73 00 2e 00 65 00 u.s...e. 0028: 78 00 65 00 2c 00 20 00 x.e.,. . 0030: 33 00 2e 00 30 00 2e 00 3...0... 0038: 30 00 2e 00 30 00 2c 00 0...0.,. 0040: 20 00 34 00 39 00 62 00 .4.9.b. 0048: 61 00 35 00 61 00 64 00 a.5.a.d. 0050: 64 00 2c 00 20 00 6d 00 d.,. .m. 0058: 73 00 63 00 6f 00 72 00 s.c.o.r. 0060: 6c 00 69 00 62 00 2c 00 l.i.b.,. 0068: 20 00 32 00 2e 00 30 00 .2...0. 0070: 2e 00 30 00 2e 00 30 00 ..0...0. 0078: 2c 00 20 00 34 00 38 00 ,. .4.8. 0080: 38 00 39 00 64 00 63 00 8.9.d.c. 0088: 38 00 30 00 2c 00 20 00 8.0.,. . 0090: 33 00 36 00 65 00 33 00 3.6.e.3. 0098: 2c 00 20 00 38 00 63 00 ,. .8.c. 00a0: 2c 00 20 00 73 00 79 00 ,. .s.y. 00a8: 73 00 74 00 65 00 6d 00 s.t.e.m. 00b0: 2e 00 69 00 6e 00 64 00 ..i.n.d. 00b8: 65 00 78 00 6f 00 75 00 e.x.o.u. 00c0: 74 00 6f 00 66 00 72 00 t.o.f.r. 00c8: 61 00 6e 00 67 00 65 00 a.n.g.e. 00d0: 65 00 78 00 63 00 65 00 e.x.c.e. 00d8: 70 00 74 00 69 00 6f 00 p.t.i.o. 00e0: 6e 00 20 00 4e 00 49 00 n. .N.I. 00e8: 4c 00 0d 00 0a 00 L.....
Also, in the TR logs, the following errors are logged fairly consistently:
4/14/2010 1:00:47 PM - Debug Message : (Radius Accounting)
System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding. at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection) at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj) at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj) at System.Data.SqlClient.SqlDataReader.ConsumeMetaData() at System.Data.SqlClient.SqlDataReader.get_MetaData() at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method) at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method) at System.Data.SqlClient.SqlCommand.ExecuteReader() at t.c.a()
and
4/14/2010 1:00:27 PM - Debug Message : (Radius Accounting)
System.Data.SqlClient.SqlException: Violation of PRIMARY KEY constraint 'PK_Sessions'. Cannot insert duplicate key in object 'dbo.Sessions'. The statement has been terminated. at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection) at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj) at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj) at System.Data.SqlClient.SqlCommand.RunExecuteNonQueryTds(String methodName, Boolean async) at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(DbAsyncResult result, String methodName, Boolean sendToPipe) at System.Data.SqlClient.SqlCommand.ExecuteNonQuery() at t.c.a()
Also, sometimes prior to a crash, the end of the log files appear garbled.
In regard to the first logged error (SQL timeout), the SQL connection tests fine, both from the TekRadius Manager and from setting up a test ODBC connection in Windows. The database is fairly large, however the tables seems pretty well indexed, as queries against the Accounting table return results rather quickly.
All in all the service is working, it just consistently dies every 3 minutes (and restarts, due to the service recovery option to restart on failure), resulting in some intermittent unavailability.
Anyone run into this or have any ideas?
|
|
• permalink
• reply with quote
|
16.04.2010 18:58:14
 rjl Posts: 8
|
A little more info.... this looks like it could be a SQL issue. At the time of a crash, the SQL server logs the following to the Windows App. Log:
Event Type: Error Event Source: MSSQLSERVER Event Category: Server Event ID: 18056 Date: 4/16/2010 Time: 11:45:10 AM User: N/A Computer: DC2 Description: The client was unable to reuse a session with SPID 68, which had been reset for connection pooling. The failure ID is 29. This error may have been caused by an earlier operation failing. Check the error logs for failed operations immediately before this error message.
For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp. Data: 0000: 88 46 00 00 14 00 00 00 F...... 0008: 04 00 00 00 44 00 43 00 ....D.C. 0010: 32 00 00 00 00 00 00 00 2.......
(Well, that's one sample SPID number, but there's always a few of these, which correspond to the SPIDs of SQL processes that start up/run with TekRadius.)
|
|
• permalink
• reply with quote
|
16.04.2010 19:30:28
 rjl Posts: 8
|
One more little tidbit of info: when I stop Accounting, which was logging the timeouts and key constraint errors, TR does not seem to crash. At least on the regular 3 minute schedule on which it seemed to crash/restart.
|
|
• permalink
• reply with quote
|
16.04.2010 22:45:16
 admin Administrator Posts: 881
|
Hi,
Is it possible you to check what kind of RADIUS accounting packets causes this error;
System.Data.SqlClient.SqlException: Violation of PRIMARY KEY constraint 'PK_Sessions'. Cannot insert duplicate key in object 'dbo.Sessions'. The statement has been terminated.
Best regards,
Yasin KAPLAN
|
|
• permalink
• reply with quote
|
16.04.2010 23:01:50
 rjl Posts: 8
|
What is the best way to go about doing that? Thanks...
|
|
• permalink
• reply with quote
|
18.04.2010 14:27:12
 admin Administrator Posts: 881
|
Hi,
Set Logging level to Debug at Settings / Service Parameters and examine incoming RADIUS accounting requests.
|
|
• permalink
• reply with quote
|
19.04.2010 18:12:21
 rjl Posts: 8
|
Hi,
Thanks for the reply.
I've set the logging to debug, and have captured a log file leading up to a crash. I won't post the entire thing, but here are some snippets.
1) There are plenty of entries such as this, starting from service startup (notice they get a little mangled at the end):
RadAcct req. from : 10.100.0.250 - 4/19/2010 11:01:13 AM Size : 191 / 191 Identifier : 187 Attributes :
RadAcct req. from : 10.100.0.250 - 4/19/2010 11:01:13 AM Size : 191 / 191 0 - 4/19/2010 11:01:13 AM RadAcct req. from : 10.100.0.250 - 4/19/2010 11:01:13 AM Size : 215 / 215 0 - 4/19/2010 11:01:13 AM RadAcct req. from : 10.100.0.250 - 4/19/2010 11:01:13 AM Size : 215 / 215 Identifier : 188 215 Identifier : 189 215 Identifier : 190 Attributes :
Attributes :
Attributes :
Attributes :
Attributes :
2) There are also some timeouts / problems related to pooling:
4/19/2010 11:01:18 AM - Debug Message : (Radius Accounting)
System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding. at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection) at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj) at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj) at System.Data.SqlClient.SqlDataReader.ConsumeMetaData() at System.Data.SqlClient.SqlDataReader.get_MetaData() at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method) at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method) at System.Data.SqlClient.SqlCommand.ExecuteReader() at t.c.a()
3) I also noticed these "invalid radius accounting requests":
Invalid RadAcct req. from : 10.100.0.250 - 4/19/2010 11:04:05 AM Size : 215 / 215 Code : 4 Identifier : 102
Invalid RadAcct req. from : 10.100.0.250 - 4/19/2010 11:04:05 AM Size : 191 / 191 Code : 4 Identifier : 104
Invalid RadAcct req. from : 10.100.0.250 - 4/19/2010 11:04:05 AM Size : 191 / 191 Code : 4 Identifier : 103
Is there anything telling in those snippets, else, what should I look for. I didn't see any packet types, but the invalid radacct req's all seemed to have a "code" of "4".
|
|
• permalink
• reply with quote
|
20.04.2010 08:41:11
 admin Administrator Posts: 881
|
Hi,
There is no problem with code "4" which denotes incoming packet is a RADIUS Accounting-Request packet. Bu I think there is a shared secret mismatch between access server and TekRADIUS.
|
|
• permalink
• reply with quote
|
22.04.2010 02:31:08
 rjl Posts: 8
|
I will check that. That did not occur to me, as users could/still can authenticate... I will check that tomorrow. Thanks!
|
|
• permalink
• reply with quote
|
22.04.2010 09:09:35
 admin Administrator Posts: 881
|
Hi,
You sometimes need to configure shared secret seperatly for authentication and accounting in access server's RADIUS configuration.
|
|
• permalink
• reply with quote
|
27.04.2010 20:09:25
 rjl Posts: 8
|
Hi,
I checked and it seems as if the shared secrets are correct / match between TR and the Cisco ASA we are using with it. As far as I know in Cisco, you only specify the shared secret once. Here is an edited copy of our config:
aaa-server groupOfficeVPN protocol radius interim-accounting-update accounting-mode single aaa-server groupOfficeVPN (inside) host IP address of TR server key sharedsecret authentication-port 1812 accounting-port 1813
So it looks as if authentication and accounting use the same secret. And authentication does work.
|
|
• permalink
• reply with quote
|
28.04.2010 11:25:01
 admin Administrator Posts: 881
|
Hi,
In order to avoid Violation of PRIMARY KEY constraint errors you can disable interim-accounting-update. Can you send me TekRADIUS.log entries for failed authentication attempts?
|
|
• permalink
• reply with quote
|
07.05.2010 11:00:00
 daan56 Posts: 4
|
Hi, i have the same problem.
I can authenticate my user but when a PC (XP familial) connect in wififor the first time to NAS without having the certificate, my tekradiusservices stop.
whireshark information
8 17.830265 192.168.1.254 192.168.1.2 UDP Source port: blackjack Destination port:radius[Malformed Packet]
User Datagram Protocol, Src Port: blackjack (1025), Dst Port: radius (1812) Source port: blackjack (1025) Destination port: radius (1812) Length: 8 Checksum: 0x7078 [validation disabled] Good Checksum: False Bad Checksum: False
[Malformed Packet: RADIUS] Expert Info (Error/Malformed): Malformed Packet (Exception occurred) Message: Malformed Packet (Exception occurred) Severity level: Error Group: Malformed
this packet, send to my tekradius, appear only for the first connectionto the Nas and stop my tekradius. When i start my tekradius and connecta second time, the client saved the SSID of the wifi and this packetdoesn't appear yet in whireshark.
When i delete the SSID in the wireless card parameters client and reconnect like the fisrt time, my tekradius stop again.
My server is in debbug mode but there is nothing in log file.
Any idea please?
sincerely
|
|
• permalink
• reply with quote
|
07.05.2010 15:48:11
 admin Administrator Posts: 881
|
Hi,
Can you also send TekRADIUS.log after setting log level to debug at settings / service parameters?
Best regards,
Yasin KAPLAN
|
|
• permalink
• reply with quote
|
07.05.2010 17:50:34
 rjl Posts: 8
|
Sure, I will try that today (disable interim-accounting-update), and get the logs together. Thanks.
|
|
• permalink
• reply with quote
|