|
1
|
START 7:47:58
|
|
2
|
|
|
3
|
prad_recv: Access-Request packet from host 172.16.1.1 port 42731, id=136, length=127
|
|
4
|
NAS-IP-Address = 172.16.1.1
|
|
5
|
NAS-Identifier = "pfsense.localdomain"
|
|
6
|
User-Name = "alice"
|
|
7
|
User-Password = "test"
|
|
8
|
Service-Type = Login-User
|
|
9
|
NAS-Port-Type = Ethernet
|
|
10
|
NAS-Port = 2
|
|
11
|
Framed-IP-Address = 172.16.1.102
|
|
12
|
Called-Station-Id = "172.16.1.1"
|
|
13
|
Calling-Station-Id = "54:04:a6:01:cd:07"
|
|
14
|
# Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
|
|
15
|
+- entering group authorize {...}
|
|
16
|
++[preprocess] returns ok
|
|
17
|
++[chap] returns noop
|
|
18
|
++[mschap] returns noop
|
|
19
|
++[digest] returns noop
|
|
20
|
[suffix] No '@' in User-Name = "alice", skipping NULL due to config.
|
|
21
|
++[suffix] returns noop
|
|
22
|
[ntdomain] No '\' in User-Name = "alice", skipping NULL due to config.
|
|
23
|
++[ntdomain] returns noop
|
|
24
|
[eap] No EAP-Message, not doing EAP
|
|
25
|
++[eap] returns noop
|
|
26
|
[files] users: Matched entry alice at line 4
|
|
27
|
++[files] returns ok
|
|
28
|
rlm_counter: Entering module authorize code
|
|
29
|
rlm_counter: Searching the database for key 'alice'
|
|
30
|
rlm_counter: Could not find the requested key in the database.
|
|
31
|
rlm_counter: Check item = 420, Count = 0
|
|
32
|
rlm_counter: res is greater than zero
|
|
33
|
rlm_counter: (Check item - counter) is greater than zero
|
|
34
|
rlm_counter: Authorized user alice, check_item=420, counter=0
|
|
35
|
rlm_counter: Sent Reply-Item for user alice, Type=Session-Timeout, value=420
|
|
36
|
++[daily] returns ok
|
|
37
|
rlm_counter: Entering module authorize code
|
|
38
|
rlm_counter: Could not find Check item value pair
|
|
39
|
++[weekly] returns noop
|
|
40
|
rlm_counter: Entering module authorize code
|
|
41
|
rlm_counter: Could not find Check item value pair
|
|
42
|
++[monthly] returns noop
|
|
43
|
rlm_counter: Entering module authorize code
|
|
44
|
rlm_counter: Could not find Check item value pair
|
|
45
|
++[forever] returns noop
|
|
46
|
rlm_checkval: Item Name: Calling-Station-Id, Value: 54:04:a6:01:cd:07
|
|
47
|
rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
|
|
48
|
++[checkval] returns notfound
|
|
49
|
++[expiration] returns noop
|
|
50
|
++[logintime] returns noop
|
|
51
|
++[pap] returns updated
|
|
52
|
Found Auth-Type = PAP
|
|
53
|
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
|
|
54
|
+- entering group PAP {...}
|
|
55
|
[pap] login attempt with password "test"
|
|
56
|
[pap] Using clear text password "test"
|
|
57
|
[pap] User authenticated successfully
|
|
58
|
++[pap] returns ok
|
|
59
|
expand: ->
|
|
60
|
Login OK: [alice] (from client cp port 2 cli 54:04:a6:01:cd:07)
|
|
61
|
# Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default
|
|
62
|
+- entering group post-auth {...}
|
|
63
|
++[exec] returns noop
|
|
64
|
Sending Access-Accept of id 136 to 172.16.1.1 port 42731
|
|
65
|
Session-Timeout = 420
|
|
66
|
Finished request 0.
|
|
67
|
Going to the next request
|
|
68
|
Waking up in 4.9 seconds.
|
|
69
|
rad_recv: Accounting-Request packet from host 172.16.1.1 port 15993, id=23, length=139
|
|
70
|
NAS-IP-Address = 172.16.1.1
|
|
71
|
NAS-Identifier = "pfsense.localdomain"
|
|
72
|
User-Name = "alice"
|
|
73
|
Acct-Status-Type = Start
|
|
74
|
Acct-Authentic = RADIUS
|
|
75
|
Service-Type = Login-User
|
|
76
|
NAS-Port-Type = Ethernet
|
|
77
|
NAS-Port = 2
|
|
78
|
Acct-Session-Id = "d2cce1a73a657a14"
|
|
79
|
Framed-IP-Address = 172.16.1.102
|
|
80
|
Called-Station-Id = "172.16.1.1"
|
|
81
|
Calling-Station-Id = "54:04:a6:01:cd:07"
|
|
82
|
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
|
|
83
|
+- entering group preacct {...}
|
|
84
|
++[preprocess] returns ok
|
|
85
|
expand: %{Acct-Session-Time} ->
|
|
86
|
... expanding second conditional
|
|
87
|
expand: %{Acct-Delay-Time} ->
|
|
88
|
... expanding second conditional
|
|
89
|
expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0} -> 1354117679 - 0 - 0
|
|
90
|
expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1354117679
|
|
91
|
++[request] returns ok
|
|
92
|
[suffix] No '@' in User-Name = "alice", skipping NULL due to config.
|
|
93
|
++[suffix] returns noop
|
|
94
|
[ntdomain] No '\' in User-Name = "alice", skipping NULL due to config.
|
|
95
|
++[ntdomain] returns noop
|
|
96
|
++[files] returns noop
|
|
97
|
# Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
|
|
98
|
+- entering group accounting {...}
|
|
99
|
[detail] expand: %{Packet-Src-IP-Address} -> 172.16.1.1
|
|
100
|
[detail] expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/172.16.1.1/detail-20121128
|
|
101
|
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/172.16.1.1/detail-20121128
|
|
102
|
[detail] expand: %t -> Wed Nov 28 07:47:59 2012
|
|
103
|
++[detail] returns ok
|
|
104
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
105
|
++[daily] returns noop
|
|
106
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
107
|
++[weekly] returns noop
|
|
108
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
109
|
++[monthly] returns noop
|
|
110
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
111
|
++[forever] returns noop
|
|
112
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update))
|
|
113
|
?? Evaluating (request:Acct-Status-Type == Stop) -> FALSE
|
|
114
|
?? Evaluating (request:Acct-Status-Type == Interim-Update) -> FALSE
|
|
115
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) -> FALSE
|
|
116
|
++[unix] returns ok
|
|
117
|
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
|
|
118
|
[radutmp] expand: %{User-Name} -> alice
|
|
119
|
++[radutmp] returns ok
|
|
120
|
++[exec] returns noop
|
|
121
|
[attr_filter.accounting_response] expand: %{User-Name} -> alice
|
|
122
|
attr_filter: Matched entry DEFAULT at line 12
|
|
123
|
++[attr_filter.accounting_response] returns updated
|
|
124
|
Sending Accounting-Response of id 23 to 172.16.1.1 port 15993
|
|
125
|
Finished request 1.
|
|
126
|
Cleaning up request 1 ID 23 with timestamp +147
|
|
127
|
Going to the next request
|
|
128
|
Waking up in 4.8 seconds.
|
|
129
|
Cleaning up request 0 ID 136 with timestamp +146
|
|
130
|
Ready to process requests.
|
|
131
|
#####################
|
|
132
|
rad_recv: Accounting-Request packet from host 172.16.1.1 port 37368, id=127, length=198
|
|
133
|
NAS-IP-Address = 172.16.1.1
|
|
134
|
NAS-Identifier = "pfsense.localdomain"
|
|
135
|
User-Name = "alice"
|
|
136
|
Acct-Status-Type = Stop
|
|
137
|
Acct-Session-Time = 52
|
|
138
|
Acct-Authentic = RADIUS
|
|
139
|
Service-Type = Login-User
|
|
140
|
NAS-Port-Type = Ethernet
|
|
141
|
NAS-Port = 2
|
|
142
|
Acct-Session-Id = "d2cce1a73a657a14"
|
|
143
|
Framed-IP-Address = 172.16.1.102
|
|
144
|
Called-Station-Id = "187.184.128.194"
|
|
145
|
Calling-Station-Id = "54:04:a6:01:cd:07"
|
|
146
|
Acct-Input-Packets = 1342
|
|
147
|
Acct-Input-Octets = 273335
|
|
148
|
Acct-Input-Gigawords = 0
|
|
149
|
Acct-Output-Packets = 1216
|
|
150
|
Acct-Output-Octets = 2371271
|
|
151
|
Acct-Output-Gigawords = 0
|
|
152
|
Acct-Session-Time = 52
|
|
153
|
Acct-Terminate-Cause = NAS-Request
|
|
154
|
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
|
|
155
|
+- entering group preacct {...}
|
|
156
|
++[preprocess] returns ok
|
|
157
|
expand: %{Acct-Session-Time} -> 52
|
|
158
|
expand: %{Acct-Delay-Time} ->
|
|
159
|
... expanding second conditional
|
|
160
|
expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0} -> 1354117730 - 52 - 0
|
|
161
|
expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1354117678
|
|
162
|
++[request] returns ok
|
|
163
|
[suffix] No '@' in User-Name = "alice", skipping NULL due to config.
|
|
164
|
++[suffix] returns noop
|
|
165
|
[ntdomain] No '\' in User-Name = "alice", skipping NULL due to config.
|
|
166
|
++[ntdomain] returns noop
|
|
167
|
++[files] returns noop
|
|
168
|
# Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
|
|
169
|
+- entering group accounting {...}
|
|
170
|
[detail] expand: %{Packet-Src-IP-Address} -> 172.16.1.1
|
|
171
|
[detail] expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/172.16.1.1/detail-20121128
|
|
172
|
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/172.16.1.1/detail-20121128
|
|
173
|
[detail] expand: %t -> Wed Nov 28 07:48:50 2012
|
|
174
|
++[detail] returns ok
|
|
175
|
rlm_counter: Searching the database for key 'alice'
|
|
176
|
rlm_counter: Could not find the requested key in the database.
|
|
177
|
rlm_counter: User=alice, New Counter=52.
|
|
178
|
rlm_counter: Storing new value in database.
|
|
179
|
rlm_counter: New value stored successfully.
|
|
180
|
++[daily] returns ok
|
|
181
|
rlm_counter: Searching the database for key 'alice'
|
|
182
|
rlm_counter: Could not find the requested key in the database.
|
|
183
|
rlm_counter: User=alice, New Counter=52.
|
|
184
|
rlm_counter: Storing new value in database.
|
|
185
|
rlm_counter: New value stored successfully.
|
|
186
|
++[weekly] returns ok
|
|
187
|
rlm_counter: Searching the database for key 'alice'
|
|
188
|
rlm_counter: Could not find the requested key in the database.
|
|
189
|
rlm_counter: User=alice, New Counter=52.
|
|
190
|
rlm_counter: Storing new value in database.
|
|
191
|
rlm_counter: New value stored successfully.
|
|
192
|
++[monthly] returns ok
|
|
193
|
rlm_counter: Searching the database for key 'alice'
|
|
194
|
rlm_counter: Could not find the requested key in the database.
|
|
195
|
rlm_counter: User=alice, New Counter=52.
|
|
196
|
rlm_counter: Storing new value in database.
|
|
197
|
rlm_counter: New value stored successfully.
|
|
198
|
++[forever] returns ok
|
|
199
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update))
|
|
200
|
?? Evaluating (request:Acct-Status-Type == Stop) -> TRUE
|
|
201
|
?? Skipping (request:Acct-Status-Type == Interim-Update)
|
|
202
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) -> TRUE
|
|
203
|
++- entering if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) {...}
|
|
204
|
[datacounterdaily] expand: %{request:User-Name} -> alice
|
|
205
|
[datacounterdaily] expand: %{request:Acct-Input-Octets} -> 273335
|
|
206
|
[datacounterdaily] expand: %{request:Acct-Output-Octets} -> 2371271
|
|
207
|
Exec-Program output:
|
|
208
|
Exec-Program: returned: 0
|
|
209
|
+++[datacounterdaily] returns ok
|
|
210
|
[datacounterweekly] expand: %{request:User-Name} -> alice
|
|
211
|
[datacounterweekly] expand: %{request:Acct-Input-Octets} -> 273335
|
|
212
|
[datacounterweekly] expand: %{request:Acct-Output-Octets} -> 2371271
|
|
213
|
Exec-Program output:
|
|
214
|
Exec-Program: returned: 0
|
|
215
|
+++[datacounterweekly] returns ok
|
|
216
|
[datacountermonthly] expand: %{request:User-Name} -> alice
|
|
217
|
[datacountermonthly] expand: %{request:Acct-Input-Octets} -> 273335
|
|
218
|
[datacountermonthly] expand: %{request:Acct-Output-Octets} -> 2371271
|
|
219
|
Exec-Program output:
|
|
220
|
Exec-Program: returned: 0
|
|
221
|
+++[datacountermonthly] returns ok
|
|
222
|
[datacounterforever] expand: %{request:User-Name} -> alice
|
|
223
|
[datacounterforever] expand: %{request:Acct-Input-Octets} -> 273335
|
|
224
|
[datacounterforever] expand: %{request:Acct-Output-Octets} -> 2371271
|
|
225
|
Exec-Program output:
|
|
226
|
Exec-Program: returned: 0
|
|
227
|
+++[datacounterforever] returns ok
|
|
228
|
++- if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) returns ok
|
|
229
|
++[unix] returns ok
|
|
230
|
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
|
|
231
|
[radutmp] expand: %{User-Name} -> alice
|
|
232
|
++[radutmp] returns ok
|
|
233
|
++[exec] returns noop
|
|
234
|
[attr_filter.accounting_response] expand: %{User-Name} -> alice
|
|
235
|
attr_filter: Matched entry DEFAULT at line 12
|
|
236
|
++[attr_filter.accounting_response] returns updated
|
|
237
|
Sending Accounting-Response of id 127 to 172.16.1.1 port 37368
|
|
238
|
Finished request 2.
|
|
239
|
Cleaning up request 2 ID 127 with timestamp +198
|
|
240
|
Going to the next request
|
|
241
|
Ready to process requests.
|
|
242
|
rad_recv: Accounting-Request packet from host 172.16.1.1 port 14214, id=104, length=139
|
|
243
|
NAS-IP-Address = 172.16.1.1
|
|
244
|
NAS-Identifier = "pfsense.localdomain"
|
|
245
|
User-Name = "alice"
|
|
246
|
Acct-Status-Type = Start
|
|
247
|
Acct-Authentic = RADIUS
|
|
248
|
Service-Type = Login-User
|
|
249
|
NAS-Port-Type = Ethernet
|
|
250
|
NAS-Port = 2
|
|
251
|
Acct-Session-Id = "d2cce1a73a657a14"
|
|
252
|
Framed-IP-Address = 172.16.1.102
|
|
253
|
Called-Station-Id = "172.16.1.1"
|
|
254
|
Calling-Station-Id = "54:04:a6:01:cd:07"
|
|
255
|
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
|
|
256
|
+- entering group preacct {...}
|
|
257
|
++[preprocess] returns ok
|
|
258
|
expand: %{Acct-Session-Time} ->
|
|
259
|
... expanding second conditional
|
|
260
|
expand: %{Acct-Delay-Time} ->
|
|
261
|
... expanding second conditional
|
|
262
|
expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0} -> 1354117730 - 0 - 0
|
|
263
|
expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1354117730
|
|
264
|
++[request] returns ok
|
|
265
|
[suffix] No '@' in User-Name = "alice", skipping NULL due to config.
|
|
266
|
++[suffix] returns noop
|
|
267
|
[ntdomain] No '\' in User-Name = "alice", skipping NULL due to config.
|
|
268
|
++[ntdomain] returns noop
|
|
269
|
++[files] returns noop
|
|
270
|
# Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
|
|
271
|
+- entering group accounting {...}
|
|
272
|
[detail] expand: %{Packet-Src-IP-Address} -> 172.16.1.1
|
|
273
|
[detail] expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/172.16.1.1/detail-20121128
|
|
274
|
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/172.16.1.1/detail-20121128
|
|
275
|
[detail] expand: %t -> Wed Nov 28 07:48:50 2012
|
|
276
|
++[detail] returns ok
|
|
277
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
278
|
++[daily] returns noop
|
|
279
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
280
|
++[weekly] returns noop
|
|
281
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
282
|
++[monthly] returns noop
|
|
283
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
284
|
++[forever] returns noop
|
|
285
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update))
|
|
286
|
?? Evaluating (request:Acct-Status-Type == Stop) -> FALSE
|
|
287
|
?? Evaluating (request:Acct-Status-Type == Interim-Update) -> FALSE
|
|
288
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) -> FALSE
|
|
289
|
++[unix] returns ok
|
|
290
|
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
|
|
291
|
[radutmp] expand: %{User-Name} -> alice
|
|
292
|
rlm_radutmp: Login entry for NAS cp port 2 wrong order
|
|
293
|
++[radutmp] returns ok
|
|
294
|
++[exec] returns noop
|
|
295
|
[attr_filter.accounting_response] expand: %{User-Name} -> alice
|
|
296
|
attr_filter: Matched entry DEFAULT at line 12
|
|
297
|
++[attr_filter.accounting_response] returns updated
|
|
298
|
Sending Accounting-Response of id 104 to 172.16.1.1 port 14214
|
|
299
|
Finished request 3.
|
|
300
|
Cleaning up request 3 ID 104 with timestamp +198
|
|
301
|
Going to the next request
|
|
302
|
Ready to process requests.
|
|
303
|
rad_recv: Access-Request packet from host 172.16.1.1 port 43631, id=11, length=127
|
|
304
|
NAS-IP-Address = 172.16.1.1
|
|
305
|
NAS-Identifier = "pfsense.localdomain"
|
|
306
|
User-Name = "alice"
|
|
307
|
User-Password = "test"
|
|
308
|
Service-Type = Login-User
|
|
309
|
NAS-Port-Type = Ethernet
|
|
310
|
NAS-Port = 2
|
|
311
|
Framed-IP-Address = 172.16.1.102
|
|
312
|
Called-Station-Id = "172.16.1.1"
|
|
313
|
Calling-Station-Id = "54:04:a6:01:cd:07"
|
|
314
|
# Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
|
|
315
|
+- entering group authorize {...}
|
|
316
|
++[preprocess] returns ok
|
|
317
|
++[chap] returns noop
|
|
318
|
++[mschap] returns noop
|
|
319
|
++[digest] returns noop
|
|
320
|
[suffix] No '@' in User-Name = "alice", skipping NULL due to config.
|
|
321
|
++[suffix] returns noop
|
|
322
|
[ntdomain] No '\' in User-Name = "alice", skipping NULL due to config.
|
|
323
|
++[ntdomain] returns noop
|
|
324
|
[eap] No EAP-Message, not doing EAP
|
|
325
|
++[eap] returns noop
|
|
326
|
[files] users: Matched entry alice at line 4
|
|
327
|
++[files] returns ok
|
|
328
|
rlm_counter: Entering module authorize code
|
|
329
|
rlm_counter: Searching the database for key 'alice'
|
|
330
|
rlm_counter: Key Found.
|
|
331
|
rlm_counter: Check item = 420, Count = 52
|
|
332
|
rlm_counter: res is greater than zero
|
|
333
|
rlm_counter: (Check item - counter) is greater than zero
|
|
334
|
rlm_counter: Authorized user alice, check_item=420, counter=52
|
|
335
|
rlm_counter: Sent Reply-Item for user alice, Type=Session-Timeout, value=368
|
|
336
|
++[daily] returns ok
|
|
337
|
rlm_counter: Entering module authorize code
|
|
338
|
rlm_counter: Could not find Check item value pair
|
|
339
|
++[weekly] returns noop
|
|
340
|
rlm_counter: Entering module authorize code
|
|
341
|
rlm_counter: Could not find Check item value pair
|
|
342
|
++[monthly] returns noop
|
|
343
|
rlm_counter: Entering module authorize code
|
|
344
|
rlm_counter: Could not find Check item value pair
|
|
345
|
++[forever] returns noop
|
|
346
|
rlm_checkval: Item Name: Calling-Station-Id, Value: 54:04:a6:01:cd:07
|
|
347
|
rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
|
|
348
|
++[checkval] returns notfound
|
|
349
|
++[expiration] returns noop
|
|
350
|
++[logintime] returns noop
|
|
351
|
++[pap] returns updated
|
|
352
|
Found Auth-Type = PAP
|
|
353
|
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
|
|
354
|
+- entering group PAP {...}
|
|
355
|
[pap] login attempt with password "test"
|
|
356
|
[pap] Using clear text password "test"
|
|
357
|
[pap] User authenticated successfully
|
|
358
|
++[pap] returns ok
|
|
359
|
expand: ->
|
|
360
|
Login OK: [alice] (from client cp port 2 cli 54:04:a6:01:cd:07)
|
|
361
|
# Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default
|
|
362
|
+- entering group post-auth {...}
|
|
363
|
++[exec] returns noop
|
|
364
|
Sending Access-Accept of id 11 to 172.16.1.1 port 43631
|
|
365
|
Session-Timeout = 368
|
|
366
|
Finished request 4.
|
|
367
|
Going to the next request
|
|
368
|
Waking up in 4.9 seconds.
|
|
369
|
Cleaning up request 4 ID 11 with timestamp +198
|
|
370
|
Ready to process requests.
|
|
371
|
###
|
|
372
|
###
|
|
373
|
rad_recv: Accounting-Request packet from host 172.16.1.1 port 2329, id=143, length=198
|
|
374
|
NAS-IP-Address = 172.16.1.1
|
|
375
|
NAS-Identifier = "pfsense.localdomain"
|
|
376
|
User-Name = "alice"
|
|
377
|
Acct-Status-Type = Stop
|
|
378
|
Acct-Session-Time = 114
|
|
379
|
Acct-Authentic = RADIUS
|
|
380
|
Service-Type = Login-User
|
|
381
|
NAS-Port-Type = Ethernet
|
|
382
|
NAS-Port = 2
|
|
383
|
Acct-Session-Id = "d2cce1a73a657a14"
|
|
384
|
Framed-IP-Address = 172.16.1.102
|
|
385
|
Called-Station-Id = "187.184.128.194"
|
|
386
|
Calling-Station-Id = "54:04:a6:01:cd:07"
|
|
387
|
Acct-Input-Packets = 3232
|
|
388
|
Acct-Input-Octets = 643222
|
|
389
|
Acct-Input-Gigawords = 0
|
|
390
|
Acct-Output-Packets = 2746
|
|
391
|
Acct-Output-Octets = 6104043
|
|
392
|
Acct-Output-Gigawords = 0
|
|
393
|
Acct-Session-Time = 114
|
|
394
|
Acct-Terminate-Cause = NAS-Request
|
|
395
|
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
|
|
396
|
+- entering group preacct {...}
|
|
397
|
++[preprocess] returns ok
|
|
398
|
expand: %{Acct-Session-Time} -> 114
|
|
399
|
expand: %{Acct-Delay-Time} ->
|
|
400
|
... expanding second conditional
|
|
401
|
expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0} -> 1354117792 - 114 - 0
|
|
402
|
expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1354117678
|
|
403
|
++[request] returns ok
|
|
404
|
[suffix] No '@' in User-Name = "alice", skipping NULL due to config.
|
|
405
|
++[suffix] returns noop
|
|
406
|
[ntdomain] No '\' in User-Name = "alice", skipping NULL due to config.
|
|
407
|
++[ntdomain] returns noop
|
|
408
|
++[files] returns noop
|
|
409
|
# Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
|
|
410
|
+- entering group accounting {...}
|
|
411
|
[detail] expand: %{Packet-Src-IP-Address} -> 172.16.1.1
|
|
412
|
[detail] expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/172.16.1.1/detail-20121128
|
|
413
|
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/172.16.1.1/detail-20121128
|
|
414
|
[detail] expand: %t -> Wed Nov 28 07:49:52 2012
|
|
415
|
++[detail] returns ok
|
|
416
|
rlm_counter: Searching the database for key 'alice'
|
|
417
|
rlm_counter: Key found.
|
|
418
|
rlm_counter: Counter Unique ID = ''
|
|
419
|
rlm_counter: User=alice, Counter=52.
|
|
420
|
rlm_counter: User=alice, New Counter=166.
|
|
421
|
rlm_counter: Storing new value in database.
|
|
422
|
rlm_counter: New value stored successfully.
|
|
423
|
++[daily] returns ok
|
|
424
|
rlm_counter: Searching the database for key 'alice'
|
|
425
|
rlm_counter: Key found.
|
|
426
|
rlm_counter: Counter Unique ID = ''
|
|
427
|
rlm_counter: User=alice, Counter=52.
|
|
428
|
rlm_counter: User=alice, New Counter=166.
|
|
429
|
rlm_counter: Storing new value in database.
|
|
430
|
rlm_counter: New value stored successfully.
|
|
431
|
++[weekly] returns ok
|
|
432
|
rlm_counter: Searching the database for key 'alice'
|
|
433
|
rlm_counter: Key found.
|
|
434
|
rlm_counter: Counter Unique ID = ''
|
|
435
|
rlm_counter: User=alice, Counter=52.
|
|
436
|
rlm_counter: User=alice, New Counter=166.
|
|
437
|
rlm_counter: Storing new value in database.
|
|
438
|
rlm_counter: New value stored successfully.
|
|
439
|
++[monthly] returns ok
|
|
440
|
rlm_counter: Searching the database for key 'alice'
|
|
441
|
rlm_counter: Key found.
|
|
442
|
rlm_counter: Counter Unique ID = ''
|
|
443
|
rlm_counter: User=alice, Counter=52.
|
|
444
|
rlm_counter: User=alice, New Counter=166.
|
|
445
|
rlm_counter: Storing new value in database.
|
|
446
|
rlm_counter: New value stored successfully.
|
|
447
|
++[forever] returns ok
|
|
448
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update))
|
|
449
|
?? Evaluating (request:Acct-Status-Type == Stop) -> TRUE
|
|
450
|
?? Skipping (request:Acct-Status-Type == Interim-Update)
|
|
451
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) -> TRUE
|
|
452
|
++- entering if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) {...}
|
|
453
|
[datacounterdaily] expand: %{request:User-Name} -> alice
|
|
454
|
[datacounterdaily] expand: %{request:Acct-Input-Octets} -> 643222
|
|
455
|
[datacounterdaily] expand: %{request:Acct-Output-Octets} -> 6104043
|
|
456
|
Exec-Program output:
|
|
457
|
Exec-Program: returned: 0
|
|
458
|
+++[datacounterdaily] returns ok
|
|
459
|
[datacounterweekly] expand: %{request:User-Name} -> alice
|
|
460
|
[datacounterweekly] expand: %{request:Acct-Input-Octets} -> 643222
|
|
461
|
[datacounterweekly] expand: %{request:Acct-Output-Octets} -> 6104043
|
|
462
|
Exec-Program output:
|
|
463
|
Exec-Program: returned: 0
|
|
464
|
+++[datacounterweekly] returns ok
|
|
465
|
[datacountermonthly] expand: %{request:User-Name} -> alice
|
|
466
|
[datacountermonthly] expand: %{request:Acct-Input-Octets} -> 643222
|
|
467
|
[datacountermonthly] expand: %{request:Acct-Output-Octets} -> 6104043
|
|
468
|
Exec-Program output:
|
|
469
|
Exec-Program: returned: 0
|
|
470
|
+++[datacountermonthly] returns ok
|
|
471
|
[datacounterforever] expand: %{request:User-Name} -> alice
|
|
472
|
[datacounterforever] expand: %{request:Acct-Input-Octets} -> 643222
|
|
473
|
[datacounterforever] expand: %{request:Acct-Output-Octets} -> 6104043
|
|
474
|
Exec-Program output:
|
|
475
|
Exec-Program: returned: 0
|
|
476
|
+++[datacounterforever] returns ok
|
|
477
|
++- if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) returns ok
|
|
478
|
++[unix] returns ok
|
|
479
|
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
|
|
480
|
[radutmp] expand: %{User-Name} -> alice
|
|
481
|
rlm_radutmp: Logout for NAS cp port 2, but no Login record
|
|
482
|
++[radutmp] returns ok
|
|
483
|
++[exec] returns noop
|
|
484
|
[attr_filter.accounting_response] expand: %{User-Name} -> alice
|
|
485
|
attr_filter: Matched entry DEFAULT at line 12
|
|
486
|
++[attr_filter.accounting_response] returns updated
|
|
487
|
Sending Accounting-Response of id 143 to 172.16.1.1 port 2329
|
|
488
|
Finished request 5.
|
|
489
|
Cleaning up request 5 ID 143 with timestamp +260
|
|
490
|
Going to the next request
|
|
491
|
Ready to process requests.
|
|
492
|
rad_recv: Accounting-Request packet from host 172.16.1.1 port 28171, id=131, length=139
|
|
493
|
NAS-IP-Address = 172.16.1.1
|
|
494
|
NAS-Identifier = "pfsense.localdomain"
|
|
495
|
User-Name = "alice"
|
|
496
|
Acct-Status-Type = Start
|
|
497
|
Acct-Authentic = RADIUS
|
|
498
|
Service-Type = Login-User
|
|
499
|
NAS-Port-Type = Ethernet
|
|
500
|
NAS-Port = 2
|
|
501
|
Acct-Session-Id = "d2cce1a73a657a14"
|
|
502
|
Framed-IP-Address = 172.16.1.102
|
|
503
|
Called-Station-Id = "172.16.1.1"
|
|
504
|
Calling-Station-Id = "54:04:a6:01:cd:07"
|
|
505
|
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
|
|
506
|
+- entering group preacct {...}
|
|
507
|
++[preprocess] returns ok
|
|
508
|
expand: %{Acct-Session-Time} ->
|
|
509
|
... expanding second conditional
|
|
510
|
expand: %{Acct-Delay-Time} ->
|
|
511
|
... expanding second conditional
|
|
512
|
expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0} -> 1354117792 - 0 - 0
|
|
513
|
expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1354117792
|
|
514
|
++[request] returns ok
|
|
515
|
[suffix] No '@' in User-Name = "alice", skipping NULL due to config.
|
|
516
|
++[suffix] returns noop
|
|
517
|
[ntdomain] No '\' in User-Name = "alice", skipping NULL due to config.
|
|
518
|
++[ntdomain] returns noop
|
|
519
|
++[files] returns noop
|
|
520
|
# Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
|
|
521
|
+- entering group accounting {...}
|
|
522
|
[detail] expand: %{Packet-Src-IP-Address} -> 172.16.1.1
|
|
523
|
[detail] expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/172.16.1.1/detail-20121128
|
|
524
|
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/172.16.1.1/detail-20121128
|
|
525
|
[detail] expand: %t -> Wed Nov 28 07:49:52 2012
|
|
526
|
++[detail] returns ok
|
|
527
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
528
|
++[daily] returns noop
|
|
529
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
530
|
++[weekly] returns noop
|
|
531
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
532
|
++[monthly] returns noop
|
|
533
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
534
|
++[forever] returns noop
|
|
535
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update))
|
|
536
|
?? Evaluating (request:Acct-Status-Type == Stop) -> FALSE
|
|
537
|
?? Evaluating (request:Acct-Status-Type == Interim-Update) -> FALSE
|
|
538
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) -> FALSE
|
|
539
|
++[unix] returns ok
|
|
540
|
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
|
|
541
|
[radutmp] expand: %{User-Name} -> alice
|
|
542
|
++[radutmp] returns ok
|
|
543
|
++[exec] returns noop
|
|
544
|
[attr_filter.accounting_response] expand: %{User-Name} -> alice
|
|
545
|
attr_filter: Matched entry DEFAULT at line 12
|
|
546
|
++[attr_filter.accounting_response] returns updated
|
|
547
|
Sending Accounting-Response of id 131 to 172.16.1.1 port 28171
|
|
548
|
Finished request 6.
|
|
549
|
Cleaning up request 6 ID 131 with timestamp +260
|
|
550
|
Going to the next request
|
|
551
|
Ready to process requests.
|
|
552
|
rad_recv: Access-Request packet from host 172.16.1.1 port 13405, id=75, length=127
|
|
553
|
NAS-IP-Address = 172.16.1.1
|
|
554
|
NAS-Identifier = "pfsense.localdomain"
|
|
555
|
User-Name = "alice"
|
|
556
|
User-Password = "test"
|
|
557
|
Service-Type = Login-User
|
|
558
|
NAS-Port-Type = Ethernet
|
|
559
|
NAS-Port = 2
|
|
560
|
Framed-IP-Address = 172.16.1.102
|
|
561
|
Called-Station-Id = "172.16.1.1"
|
|
562
|
Calling-Station-Id = "54:04:a6:01:cd:07"
|
|
563
|
# Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
|
|
564
|
+- entering group authorize {...}
|
|
565
|
++[preprocess] returns ok
|
|
566
|
++[chap] returns noop
|
|
567
|
++[mschap] returns noop
|
|
568
|
++[digest] returns noop
|
|
569
|
[suffix] No '@' in User-Name = "alice", skipping NULL due to config.
|
|
570
|
++[suffix] returns noop
|
|
571
|
[ntdomain] No '\' in User-Name = "alice", skipping NULL due to config.
|
|
572
|
++[ntdomain] returns noop
|
|
573
|
[eap] No EAP-Message, not doing EAP
|
|
574
|
++[eap] returns noop
|
|
575
|
[files] users: Matched entry alice at line 4
|
|
576
|
++[files] returns ok
|
|
577
|
rlm_counter: Entering module authorize code
|
|
578
|
rlm_counter: Searching the database for key 'alice'
|
|
579
|
rlm_counter: Key Found.
|
|
580
|
rlm_counter: Check item = 420, Count = 166
|
|
581
|
rlm_counter: res is greater than zero
|
|
582
|
rlm_counter: (Check item - counter) is greater than zero
|
|
583
|
rlm_counter: Authorized user alice, check_item=420, counter=166
|
|
584
|
rlm_counter: Sent Reply-Item for user alice, Type=Session-Timeout, value=254
|
|
585
|
++[daily] returns ok
|
|
586
|
rlm_counter: Entering module authorize code
|
|
587
|
rlm_counter: Could not find Check item value pair
|
|
588
|
++[weekly] returns noop
|
|
589
|
rlm_counter: Entering module authorize code
|
|
590
|
rlm_counter: Could not find Check item value pair
|
|
591
|
++[monthly] returns noop
|
|
592
|
rlm_counter: Entering module authorize code
|
|
593
|
rlm_counter: Could not find Check item value pair
|
|
594
|
++[forever] returns noop
|
|
595
|
rlm_checkval: Item Name: Calling-Station-Id, Value: 54:04:a6:01:cd:07
|
|
596
|
rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
|
|
597
|
++[checkval] returns notfound
|
|
598
|
++[expiration] returns noop
|
|
599
|
++[logintime] returns noop
|
|
600
|
++[pap] returns updated
|
|
601
|
Found Auth-Type = PAP
|
|
602
|
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
|
|
603
|
+- entering group PAP {...}
|
|
604
|
[pap] login attempt with password "test"
|
|
605
|
[pap] Using clear text password "test"
|
|
606
|
[pap] User authenticated successfully
|
|
607
|
++[pap] returns ok
|
|
608
|
expand: ->
|
|
609
|
Login OK: [alice] (from client cp port 2 cli 54:04:a6:01:cd:07)
|
|
610
|
# Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default
|
|
611
|
+- entering group post-auth {...}
|
|
612
|
++[exec] returns noop
|
|
613
|
Sending Access-Accept of id 75 to 172.16.1.1 port 13405
|
|
614
|
Session-Timeout = 254
|
|
615
|
Finished request 7.
|
|
616
|
Going to the next request
|
|
617
|
Waking up in 4.9 seconds.
|
|
618
|
###Cleaning up request 7 ID 75 with timestamp +260
|
|
619
|
Ready to process requests.
|
|
620
|
####
|
|
621
|
###
|
|
622
|
###
|
|
623
|
rad_recv: Accounting-Request packet from host 172.16.1.1 port 37634, id=111, length=198
|
|
624
|
NAS-IP-Address = 172.16.1.1
|
|
625
|
NAS-Identifier = "pfsense.localdomain"
|
|
626
|
User-Name = "alice"
|
|
627
|
Acct-Status-Type = Stop
|
|
628
|
Acct-Session-Time = 175
|
|
629
|
Acct-Authentic = RADIUS
|
|
630
|
Service-Type = Login-User
|
|
631
|
NAS-Port-Type = Ethernet
|
|
632
|
NAS-Port = 2
|
|
633
|
Acct-Session-Id = "d2cce1a73a657a14"
|
|
634
|
Framed-IP-Address = 172.16.1.102
|
|
635
|
Called-Station-Id = "187.184.128.194"
|
|
636
|
Calling-Station-Id = "54:04:a6:01:cd:07"
|
|
637
|
Acct-Input-Packets = 4321
|
|
638
|
Acct-Input-Octets = 1067655
|
|
639
|
Acct-Input-Gigawords = 0
|
|
640
|
Acct-Output-Packets = 3753
|
|
641
|
Acct-Output-Octets = 10303302
|
|
642
|
Acct-Output-Gigawords = 0
|
|
643
|
Acct-Session-Time = 175
|
|
644
|
Acct-Terminate-Cause = NAS-Request
|
|
645
|
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
|
|
646
|
+- entering group preacct {...}
|
|
647
|
++[preprocess] returns ok
|
|
648
|
expand: %{Acct-Session-Time} -> 175
|
|
649
|
expand: %{Acct-Delay-Time} ->
|
|
650
|
... expanding second conditional
|
|
651
|
expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0} -> 1354117853 - 175 - 0
|
|
652
|
expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1354117678
|
|
653
|
++[request] returns ok
|
|
654
|
[suffix] No '@' in User-Name = "alice", skipping NULL due to config.
|
|
655
|
++[suffix] returns noop
|
|
656
|
[ntdomain] No '\' in User-Name = "alice", skipping NULL due to config.
|
|
657
|
++[ntdomain] returns noop
|
|
658
|
++[files] returns noop
|
|
659
|
# Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
|
|
660
|
+- entering group accounting {...}
|
|
661
|
[detail] expand: %{Packet-Src-IP-Address} -> 172.16.1.1
|
|
662
|
[detail] expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/172.16.1.1/detail-20121128
|
|
663
|
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/172.16.1.1/detail-20121128
|
|
664
|
[detail] expand: %t -> Wed Nov 28 07:50:53 2012
|
|
665
|
++[detail] returns ok
|
|
666
|
rlm_counter: Searching the database for key 'alice'
|
|
667
|
rlm_counter: Key found.
|
|
668
|
rlm_counter: Counter Unique ID = ''
|
|
669
|
rlm_counter: User=alice, Counter=166.
|
|
670
|
rlm_counter: User=alice, New Counter=341.
|
|
671
|
rlm_counter: Storing new value in database.
|
|
672
|
rlm_counter: New value stored successfully.
|
|
673
|
++[daily] returns ok
|
|
674
|
rlm_counter: Searching the database for key 'alice'
|
|
675
|
rlm_counter: Key found.
|
|
676
|
rlm_counter: Counter Unique ID = ''
|
|
677
|
rlm_counter: User=alice, Counter=166.
|
|
678
|
rlm_counter: User=alice, New Counter=341.
|
|
679
|
rlm_counter: Storing new value in database.
|
|
680
|
rlm_counter: New value stored successfully.
|
|
681
|
++[weekly] returns ok
|
|
682
|
rlm_counter: Searching the database for key 'alice'
|
|
683
|
rlm_counter: Key found.
|
|
684
|
rlm_counter: Counter Unique ID = ''
|
|
685
|
rlm_counter: User=alice, Counter=166.
|
|
686
|
rlm_counter: User=alice, New Counter=341.
|
|
687
|
rlm_counter: Storing new value in database.
|
|
688
|
rlm_counter: New value stored successfully.
|
|
689
|
++[monthly] returns ok
|
|
690
|
rlm_counter: Searching the database for key 'alice'
|
|
691
|
rlm_counter: Key found.
|
|
692
|
rlm_counter: Counter Unique ID = ''
|
|
693
|
rlm_counter: User=alice, Counter=166.
|
|
694
|
rlm_counter: User=alice, New Counter=341.
|
|
695
|
rlm_counter: Storing new value in database.
|
|
696
|
rlm_counter: New value stored successfully.
|
|
697
|
++[forever] returns ok
|
|
698
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update))
|
|
699
|
?? Evaluating (request:Acct-Status-Type == Stop) -> TRUE
|
|
700
|
?? Skipping (request:Acct-Status-Type == Interim-Update)
|
|
701
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) -> TRUE
|
|
702
|
++- entering if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) {...}
|
|
703
|
[datacounterdaily] expand: %{request:User-Name} -> alice
|
|
704
|
[datacounterdaily] expand: %{request:Acct-Input-Octets} -> 1067655
|
|
705
|
[datacounterdaily] expand: %{request:Acct-Output-Octets} -> 10303302
|
|
706
|
Exec-Program output:
|
|
707
|
Exec-Program: returned: 0
|
|
708
|
+++[datacounterdaily] returns ok
|
|
709
|
[datacounterweekly] expand: %{request:User-Name} -> alice
|
|
710
|
[datacounterweekly] expand: %{request:Acct-Input-Octets} -> 1067655
|
|
711
|
[datacounterweekly] expand: %{request:Acct-Output-Octets} -> 10303302
|
|
712
|
Exec-Program output:
|
|
713
|
Exec-Program: returned: 0
|
|
714
|
+++[datacounterweekly] returns ok
|
|
715
|
[datacountermonthly] expand: %{request:User-Name} -> alice
|
|
716
|
[datacountermonthly] expand: %{request:Acct-Input-Octets} -> 1067655
|
|
717
|
[datacountermonthly] expand: %{request:Acct-Output-Octets} -> 10303302
|
|
718
|
Exec-Program output:
|
|
719
|
Exec-Program: returned: 0
|
|
720
|
+++[datacountermonthly] returns ok
|
|
721
|
[datacounterforever] expand: %{request:User-Name} -> alice
|
|
722
|
[datacounterforever] expand: %{request:Acct-Input-Octets} -> 1067655
|
|
723
|
[datacounterforever] expand: %{request:Acct-Output-Octets} -> 10303302
|
|
724
|
Exec-Program output:
|
|
725
|
Exec-Program: returned: 0
|
|
726
|
+++[datacounterforever] returns ok
|
|
727
|
++- if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) returns ok
|
|
728
|
++[unix] returns ok
|
|
729
|
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
|
|
730
|
[radutmp] expand: %{User-Name} -> alice
|
|
731
|
++[radutmp] returns ok
|
|
732
|
++[exec] returns noop
|
|
733
|
[attr_filter.accounting_response] expand: %{User-Name} -> alice
|
|
734
|
attr_filter: Matched entry DEFAULT at line 12
|
|
735
|
++[attr_filter.accounting_response] returns updated
|
|
736
|
Sending Accounting-Response of id 111 to 172.16.1.1 port 37634
|
|
737
|
Finished request 8.
|
|
738
|
Cleaning up request 8 ID 111 with timestamp +321
|
|
739
|
Going to the next request
|
|
740
|
Ready to process requests.
|
|
741
|
rad_recv: Accounting-Request packet from host 172.16.1.1 port 28985, id=104, length=139
|
|
742
|
NAS-IP-Address = 172.16.1.1
|
|
743
|
NAS-Identifier = "pfsense.localdomain"
|
|
744
|
User-Name = "alice"
|
|
745
|
Acct-Status-Type = Start
|
|
746
|
Acct-Authentic = RADIUS
|
|
747
|
Service-Type = Login-User
|
|
748
|
NAS-Port-Type = Ethernet
|
|
749
|
NAS-Port = 2
|
|
750
|
Acct-Session-Id = "d2cce1a73a657a14"
|
|
751
|
Framed-IP-Address = 172.16.1.102
|
|
752
|
Called-Station-Id = "172.16.1.1"
|
|
753
|
Calling-Station-Id = "54:04:a6:01:cd:07"
|
|
754
|
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
|
|
755
|
+- entering group preacct {...}
|
|
756
|
++[preprocess] returns ok
|
|
757
|
expand: %{Acct-Session-Time} ->
|
|
758
|
... expanding second conditional
|
|
759
|
expand: %{Acct-Delay-Time} ->
|
|
760
|
... expanding second conditional
|
|
761
|
expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0} -> 1354117854 - 0 - 0
|
|
762
|
expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1354117854
|
|
763
|
++[request] returns ok
|
|
764
|
[suffix] No '@' in User-Name = "alice", skipping NULL due to config.
|
|
765
|
++[suffix] returns noop
|
|
766
|
[ntdomain] No '\' in User-Name = "alice", skipping NULL due to config.
|
|
767
|
++[ntdomain] returns noop
|
|
768
|
++[files] returns noop
|
|
769
|
# Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
|
|
770
|
+- entering group accounting {...}
|
|
771
|
[detail] expand: %{Packet-Src-IP-Address} -> 172.16.1.1
|
|
772
|
[detail] expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/172.16.1.1/detail-20121128
|
|
773
|
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/172.16.1.1/detail-20121128
|
|
774
|
[detail] expand: %t -> Wed Nov 28 07:50:54 2012
|
|
775
|
++[detail] returns ok
|
|
776
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
777
|
++[daily] returns noop
|
|
778
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
779
|
++[weekly] returns noop
|
|
780
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
781
|
++[monthly] returns noop
|
|
782
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
783
|
++[forever] returns noop
|
|
784
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update))
|
|
785
|
?? Evaluating (request:Acct-Status-Type == Stop) -> FALSE
|
|
786
|
?? Evaluating (request:Acct-Status-Type == Interim-Update) -> FALSE
|
|
787
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) -> FALSE
|
|
788
|
++[unix] returns ok
|
|
789
|
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
|
|
790
|
[radutmp] expand: %{User-Name} -> alice
|
|
791
|
rlm_radutmp: Login entry for NAS cp port 2 wrong order
|
|
792
|
++[radutmp] returns ok
|
|
793
|
++[exec] returns noop
|
|
794
|
[attr_filter.accounting_response] expand: %{User-Name} -> alice
|
|
795
|
attr_filter: Matched entry DEFAULT at line 12
|
|
796
|
++[attr_filter.accounting_response] returns updated
|
|
797
|
Sending Accounting-Response of id 104 to 172.16.1.1 port 28985
|
|
798
|
Finished request 9.
|
|
799
|
Cleaning up request 9 ID 104 with timestamp +322
|
|
800
|
Going to the next request
|
|
801
|
Ready to process requests.
|
|
802
|
rad_recv: Access-Request packet from host 172.16.1.1 port 23549, id=172, length=127
|
|
803
|
NAS-IP-Address = 172.16.1.1
|
|
804
|
NAS-Identifier = "pfsense.localdomain"
|
|
805
|
User-Name = "alice"
|
|
806
|
User-Password = "test"
|
|
807
|
Service-Type = Login-User
|
|
808
|
NAS-Port-Type = Ethernet
|
|
809
|
NAS-Port = 2
|
|
810
|
Framed-IP-Address = 172.16.1.102
|
|
811
|
Called-Station-Id = "172.16.1.1"
|
|
812
|
Calling-Station-Id = "54:04:a6:01:cd:07"
|
|
813
|
# Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
|
|
814
|
+- entering group authorize {...}
|
|
815
|
++[preprocess] returns ok
|
|
816
|
++[chap] returns noop
|
|
817
|
++[mschap] returns noop
|
|
818
|
++[digest] returns noop
|
|
819
|
[suffix] No '@' in User-Name = "alice", skipping NULL due to config.
|
|
820
|
++[suffix] returns noop
|
|
821
|
[ntdomain] No '\' in User-Name = "alice", skipping NULL due to config.
|
|
822
|
++[ntdomain] returns noop
|
|
823
|
[eap] No EAP-Message, not doing EAP
|
|
824
|
++[eap] returns noop
|
|
825
|
[files] users: Matched entry alice at line 4
|
|
826
|
++[files] returns ok
|
|
827
|
rlm_counter: Entering module authorize code
|
|
828
|
rlm_counter: Searching the database for key 'alice'
|
|
829
|
rlm_counter: Key Found.
|
|
830
|
rlm_counter: Check item = 420, Count = 341
|
|
831
|
rlm_counter: res is greater than zero
|
|
832
|
rlm_counter: (Check item - counter) is greater than zero
|
|
833
|
rlm_counter: Authorized user alice, check_item=420, counter=341
|
|
834
|
rlm_counter: Sent Reply-Item for user alice, Type=Session-Timeout, value=79
|
|
835
|
++[daily] returns ok
|
|
836
|
rlm_counter: Entering module authorize code
|
|
837
|
rlm_counter: Could not find Check item value pair
|
|
838
|
++[weekly] returns noop
|
|
839
|
rlm_counter: Entering module authorize code
|
|
840
|
rlm_counter: Could not find Check item value pair
|
|
841
|
++[monthly] returns noop
|
|
842
|
rlm_counter: Entering module authorize code
|
|
843
|
rlm_counter: Could not find Check item value pair
|
|
844
|
++[forever] returns noop
|
|
845
|
rlm_checkval: Item Name: Calling-Station-Id, Value: 54:04:a6:01:cd:07
|
|
846
|
rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
|
|
847
|
++[checkval] returns notfound
|
|
848
|
++[expiration] returns noop
|
|
849
|
++[logintime] returns noop
|
|
850
|
++[pap] returns updated
|
|
851
|
Found Auth-Type = PAP
|
|
852
|
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
|
|
853
|
+- entering group PAP {...}
|
|
854
|
[pap] login attempt with password "test"
|
|
855
|
[pap] Using clear text password "test"
|
|
856
|
[pap] User authenticated successfully
|
|
857
|
++[pap] returns ok
|
|
858
|
expand: ->
|
|
859
|
Login OK: [alice] (from client cp port 2 cli 54:04:a6:01:cd:07)
|
|
860
|
# Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default
|
|
861
|
+- entering group post-auth {...}
|
|
862
|
++[exec] returns noop
|
|
863
|
Sending Access-Accept of id 172 to 172.16.1.1 port 23549
|
|
864
|
Session-Timeout = 79
|
|
865
|
Finished request 10.
|
|
866
|
Going to the next request
|
|
867
|
Waking up in 4.9 seconds.
|
|
868
|
Cleaning up request 10 ID 172 with timestamp +322
|
|
869
|
Ready to process requests.
|
|
870
|
###4
|
|
871
|
[datacountermonthly] expand: %{request:Acct-Input-Octets} -> 1417004
|
|
872
|
[datacountermonthly] expand: %{request:Acct-Output-Octets} -> 12553245
|
|
873
|
Exec-Program output:
|
|
874
|
Exec-Program: returned: 0
|
|
875
|
+++[datacountermonthly] returns ok
|
|
876
|
[datacounterforever] expand: %{request:User-Name} -> alice
|
|
877
|
[datacounterforever] expand: %{request:Acct-Input-Octets} -> 1417004
|
|
878
|
[datacounterforever] expand: %{request:Acct-Output-Octets} -> 12553245
|
|
879
|
Exec-Program output:
|
|
880
|
Exec-Program: returned: 0
|
|
881
|
+++[datacounterforever] returns ok
|
|
882
|
++- if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) returns ok
|
|
883
|
++[unix] returns ok
|
|
884
|
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
|
|
885
|
[radutmp] expand: %{User-Name} -> alice
|
|
886
|
rlm_radutmp: Logout for NAS cp port 2, but no Login record
|
|
887
|
++[radutmp] returns ok
|
|
888
|
++[exec] returns noop
|
|
889
|
[attr_filter.accounting_response] expand: %{User-Name} -> alice
|
|
890
|
attr_filter: Matched entry DEFAULT at line 12
|
|
891
|
++[attr_filter.accounting_response] returns updated
|
|
892
|
Sending Accounting-Response of id 227 to 172.16.1.1 port 11781
|
|
893
|
Finished request 11.
|
|
894
|
Cleaning up request 11 ID 227 with timestamp +383
|
|
895
|
Going to the next request
|
|
896
|
Ready to process requests.
|
|
897
|
rad_recv: Accounting-Request packet from host 172.16.1.1 port 59486, id=109, length=139
|
|
898
|
NAS-IP-Address = 172.16.1.1
|
|
899
|
NAS-Identifier = "pfsense.localdomain"
|
|
900
|
User-Name = "alice"
|
|
901
|
Acct-Status-Type = Start
|
|
902
|
Acct-Authentic = RADIUS
|
|
903
|
Service-Type = Login-User
|
|
904
|
NAS-Port-Type = Ethernet
|
|
905
|
NAS-Port = 2
|
|
906
|
Acct-Session-Id = "d2cce1a73a657a14"
|
|
907
|
Framed-IP-Address = 172.16.1.102
|
|
908
|
Called-Station-Id = "172.16.1.1"
|
|
909
|
Calling-Station-Id = "54:04:a6:01:cd:07"
|
|
910
|
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
|
|
911
|
+- entering group preacct {...}
|
|
912
|
++[preprocess] returns ok
|
|
913
|
expand: %{Acct-Session-Time} ->
|
|
914
|
... expanding second conditional
|
|
915
|
expand: %{Acct-Delay-Time} ->
|
|
916
|
... expanding second conditional
|
|
917
|
expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0} -> 1354117915 - 0 - 0
|
|
918
|
expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1354117915
|
|
919
|
++[request] returns ok
|
|
920
|
[suffix] No '@' in User-Name = "alice", skipping NULL due to config.
|
|
921
|
++[suffix] returns noop
|
|
922
|
[ntdomain] No '\' in User-Name = "alice", skipping NULL due to config.
|
|
923
|
++[ntdomain] returns noop
|
|
924
|
++[files] returns noop
|
|
925
|
# Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
|
|
926
|
+- entering group accounting {...}
|
|
927
|
[detail] expand: %{Packet-Src-IP-Address} -> 172.16.1.1
|
|
928
|
[detail] expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/172.16.1.1/detail-20121128
|
|
929
|
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/172.16.1.1/detail-20121128
|
|
930
|
[detail] expand: %t -> Wed Nov 28 07:51:55 2012
|
|
931
|
++[detail] returns ok
|
|
932
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
933
|
++[daily] returns noop
|
|
934
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
935
|
++[weekly] returns noop
|
|
936
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
937
|
++[monthly] returns noop
|
|
938
|
rlm_counter: We only run on Accounting-Stop packets.
|
|
939
|
++[forever] returns noop
|
|
940
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update))
|
|
941
|
?? Evaluating (request:Acct-Status-Type == Stop) -> FALSE
|
|
942
|
?? Evaluating (request:Acct-Status-Type == Interim-Update) -> FALSE
|
|
943
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) -> FALSE
|
|
944
|
++[unix] returns ok
|
|
945
|
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
|
|
946
|
[radutmp] expand: %{User-Name} -> alice
|
|
947
|
++[radutmp] returns ok
|
|
948
|
++[exec] returns noop
|
|
949
|
[attr_filter.accounting_response] expand: %{User-Name} -> alice
|
|
950
|
attr_filter: Matched entry DEFAULT at line 12
|
|
951
|
++[attr_filter.accounting_response] returns updated
|
|
952
|
Sending Accounting-Response of id 109 to 172.16.1.1 port 59486
|
|
953
|
Finished request 12.
|
|
954
|
Cleaning up request 12 ID 109 with timestamp +383
|
|
955
|
Going to the next request
|
|
956
|
Ready to process requests.
|
|
957
|
rad_recv: Access-Request packet from host 172.16.1.1 port 13183, id=21, length=127
|
|
958
|
NAS-IP-Address = 172.16.1.1
|
|
959
|
NAS-Identifier = "pfsense.localdomain"
|
|
960
|
User-Name = "alice"
|
|
961
|
User-Password = "test"
|
|
962
|
Service-Type = Login-User
|
|
963
|
NAS-Port-Type = Ethernet
|
|
964
|
NAS-Port = 2
|
|
965
|
Framed-IP-Address = 172.16.1.102
|
|
966
|
Called-Station-Id = "172.16.1.1"
|
|
967
|
Calling-Station-Id = "54:04:a6:01:cd:07"
|
|
968
|
# Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
|
|
969
|
+- entering group authorize {...}
|
|
970
|
++[preprocess] returns ok
|
|
971
|
++[chap] returns noop
|
|
972
|
++[mschap] returns noop
|
|
973
|
++[digest] returns noop
|
|
974
|
[suffix] No '@' in User-Name = "alice", skipping NULL due to config.
|
|
975
|
++[suffix] returns noop
|
|
976
|
[ntdomain] No '\' in User-Name = "alice", skipping NULL due to config.
|
|
977
|
++[ntdomain] returns noop
|
|
978
|
[eap] No EAP-Message, not doing EAP
|
|
979
|
++[eap] returns noop
|
|
980
|
[files] users: Matched entry alice at line 4
|
|
981
|
++[files] returns ok
|
|
982
|
rlm_counter: Entering module authorize code
|
|
983
|
rlm_counter: Searching the database for key 'alice'
|
|
984
|
rlm_counter: Key Found.
|
|
985
|
rlm_counter: Check item = 420, Count = 578
|
|
986
|
rlm_counter: Rejected user alice, check_item=420, counter=578
|
|
987
|
++[daily] returns reject
|
|
988
|
expand: ->
|
|
989
|
Invalid user (rlm_counter: Maximum daily usage time reached): [alice] (from client cp port 2 cli 54:04:a6:01:cd:07)
|
|
990
|
Using Post-Auth-Type Reject
|
|
991
|
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
|
|
992
|
+- entering group REJECT {...}
|
|
993
|
[attr_filter.access_reject] expand: %{User-Name} -> alice
|
|
994
|
attr_filter: Matched entry DEFAULT at line 11
|
|
995
|
++[attr_filter.access_reject] returns updated
|
|
996
|
Delaying reject of request 13 for 1 seconds
|
|
997
|
Going to the next request
|
|
998
|
Waking up in 0.9 seconds.
|
|
999
|
Sending delayed reject for request 13
|
|
1000
|
Sending Access-Reject of id 21 to 172.16.1.1 port 13183
|
|
1001
|
Reply-Message = "Your maximum daily usage time has been reached"
|
|
1002
|
Waking up in 4.9 seconds.
|
|
1003
|
rad_recv: Accounting-Request packet from host 172.16.1.1 port 60198, id=142, length=198
|
|
1004
|
NAS-IP-Address = 172.16.1.1
|
|
1005
|
NAS-Identifier = "pfsense.localdomain"
|
|
1006
|
User-Name = "alice"
|
|
1007
|
Acct-Status-Type = Stop
|
|
1008
|
Acct-Session-Time = 238
|
|
1009
|
Acct-Authentic = RADIUS
|
|
1010
|
Service-Type = Login-User
|
|
1011
|
NAS-Port-Type = Ethernet
|
|
1012
|
NAS-Port = 2
|
|
1013
|
Acct-Session-Id = "d2cce1a73a657a14"
|
|
1014
|
Framed-IP-Address = 172.16.1.102
|
|
1015
|
Called-Station-Id = "187.184.128.194"
|
|
1016
|
Calling-Station-Id = "54:04:a6:01:cd:07"
|
|
1017
|
Acct-Input-Packets = 6066
|
|
1018
|
Acct-Input-Octets = 1430176
|
|
1019
|
Acct-Input-Gigawords = 0
|
|
1020
|
Acct-Output-Packets = 5303
|
|
1021
|
Acct-Output-Octets = 12642623
|
|
1022
|
Acct-Output-Gigawords = 0
|
|
1023
|
Acct-Session-Time = 238
|
|
1024
|
Acct-Terminate-Cause = User-Error
|
|
1025
|
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
|
|
1026
|
+- entering group preacct {...}
|
|
1027
|
++[preprocess] returns ok
|
|
1028
|
expand: %{Acct-Session-Time} -> 238
|
|
1029
|
expand: %{Acct-Delay-Time} ->
|
|
1030
|
... expanding second conditional
|
|
1031
|
expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0} -> 1354117916 - 238 - 0
|
|
1032
|
expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1354117678
|
|
1033
|
++[request] returns ok
|
|
1034
|
[suffix] No '@' in User-Name = "alice", skipping NULL due to config.
|
|
1035
|
++[suffix] returns noop
|
|
1036
|
[ntdomain] No '\' in User-Name = "alice", skipping NULL due to config.
|
|
1037
|
++[ntdomain] returns noop
|
|
1038
|
++[files] returns noop
|
|
1039
|
# Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
|
|
1040
|
+- entering group accounting {...}
|
|
1041
|
[detail] expand: %{Packet-Src-IP-Address} -> 172.16.1.1
|
|
1042
|
[detail] expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/172.16.1.1/detail-20121128
|
|
1043
|
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/172.16.1.1/detail-20121128
|
|
1044
|
[detail] expand: %t -> Wed Nov 28 07:51:56 2012
|
|
1045
|
++[detail] returns ok
|
|
1046
|
rlm_counter: Searching the database for key 'alice'
|
|
1047
|
rlm_counter: Key found.
|
|
1048
|
rlm_counter: Counter Unique ID = ''
|
|
1049
|
rlm_counter: User=alice, Counter=578.
|
|
1050
|
rlm_counter: User=alice, New Counter=816.
|
|
1051
|
rlm_counter: Storing new value in database.
|
|
1052
|
rlm_counter: New value stored successfully.
|
|
1053
|
++[daily] returns ok
|
|
1054
|
rlm_counter: Searching the database for key 'alice'
|
|
1055
|
rlm_counter: Key found.
|
|
1056
|
rlm_counter: Counter Unique ID = ''
|
|
1057
|
rlm_counter: User=alice, Counter=578.
|
|
1058
|
rlm_counter: User=alice, New Counter=816.
|
|
1059
|
rlm_counter: Storing new value in database.
|
|
1060
|
rlm_counter: New value stored successfully.
|
|
1061
|
++[weekly] returns ok
|
|
1062
|
rlm_counter: Searching the database for key 'alice'
|
|
1063
|
rlm_counter: Key found.
|
|
1064
|
rlm_counter: Counter Unique ID = ''
|
|
1065
|
rlm_counter: User=alice, Counter=578.
|
|
1066
|
rlm_counter: User=alice, New Counter=816.
|
|
1067
|
rlm_counter: Storing new value in database.
|
|
1068
|
rlm_counter: New value stored successfully.
|
|
1069
|
++[monthly] returns ok
|
|
1070
|
rlm_counter: Searching the database for key 'alice'
|
|
1071
|
rlm_counter: Key found.
|
|
1072
|
rlm_counter: Counter Unique ID = ''
|
|
1073
|
rlm_counter: User=alice, Counter=578.
|
|
1074
|
rlm_counter: User=alice, New Counter=816.
|
|
1075
|
rlm_counter: Storing new value in database.
|
|
1076
|
rlm_counter: New value stored successfully.
|
|
1077
|
++[forever] returns ok
|
|
1078
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update))
|
|
1079
|
?? Evaluating (request:Acct-Status-Type == Stop) -> TRUE
|
|
1080
|
?? Skipping (request:Acct-Status-Type == Interim-Update)
|
|
1081
|
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) -> TRUE
|
|
1082
|
++- entering if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) {...}
|
|
1083
|
[datacounterdaily] expand: %{request:User-Name} -> alice
|
|
1084
|
[datacounterdaily] expand: %{request:Acct-Input-Octets} -> 1430176
|
|
1085
|
[datacounterdaily] expand: %{request:Acct-Output-Octets} -> 12642623
|
|
1086
|
Exec-Program output:
|
|
1087
|
Exec-Program: returned: 0
|
|
1088
|
+++[datacounterdaily] returns ok
|
|
1089
|
[datacounterweekly] expand: %{request:User-Name} -> alice
|
|
1090
|
[datacounterweekly] expand: %{request:Acct-Input-Octets} -> 1430176
|
|
1091
|
[datacounterweekly] expand: %{request:Acct-Output-Octets} -> 12642623
|
|
1092
|
Exec-Program output:
|
|
1093
|
Exec-Program: returned: 0
|
|
1094
|
+++[datacounterweekly] returns ok
|
|
1095
|
[datacountermonthly] expand: %{request:User-Name} -> alice
|
|
1096
|
[datacountermonthly] expand: %{request:Acct-Input-Octets} -> 1430176
|
|
1097
|
[datacountermonthly] expand: %{request:Acct-Output-Octets} -> 12642623
|
|
1098
|
Exec-Program output:
|
|
1099
|
Exec-Program: returned: 0
|
|
1100
|
+++[datacountermonthly] returns ok
|
|
1101
|
[datacounterforever] expand: %{request:User-Name} -> alice
|
|
1102
|
[datacounterforever] expand: %{request:Acct-Input-Octets} -> 1430176
|
|
1103
|
[datacounterforever] expand: %{request:Acct-Output-Octets} -> 12642623
|
|
1104
|
Exec-Program output:
|
|
1105
|
Exec-Program: returned: 0
|
|
1106
|
+++[datacounterforever] returns ok
|
|
1107
|
++- if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) returns ok
|
|
1108
|
++[unix] returns ok
|
|
1109
|
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
|
|
1110
|
[radutmp] expand: %{User-Name} -> alice
|
|
1111
|
++[radutmp] returns ok
|
|
1112
|
++[exec] returns noop
|
|
1113
|
[attr_filter.accounting_response] expand: %{User-Name} -> alice
|
|
1114
|
attr_filter: Matched entry DEFAULT at line 12
|
|
1115
|
++[attr_filter.accounting_response] returns updated
|
|
1116
|
Sending Accounting-Response of id 142 to 172.16.1.1 port 60198
|
|
1117
|
Finished request 14.
|
|
1118
|
Cleaning up request 14 ID 142 with timestamp +384
|
|
1119
|
Going to the next request
|
|
1120
|
Waking up in 4.5 seconds.
|
|
1121
|
Cleaning up request 13 ID 21 with timestamp +383
|
|
1122
|
Ready to process requests.
|
|
1123
|
end date 7:53AM
|
|
1124
|
|
|
1125
|
User data:
|
|
1126
|
|
|
1127
|
"alice" Cleartext-Password := "test", Max-Daily-Session := 420
|