Requests being rejected with "Invalid user"

[Alan DeKok]

On Dec 2, 2020, at 5:33 PM, Dan M <dan.red.beard at gmail.com> wrote:
> 
> We have been running FreeRadius for about 18 months with very light traffic
> and no issues.
> Recently, within the last month, some requests are rejected and a message
> appears in the log 
> Invalid user: [the actual user id] (from client <the actual client id> port
> 0)

  That message comes out when the user is rejected.

> It seems completely random.
> The end user just hits enter again which runs thru the client system and
> generates a new request that succeeds.
> (Well it seems that none of the second requests have failed.  I have no
> reports otherwise)
> The user id seems to me to be identical (at least in the log) for both the
> failure and the success. 

  Sure.  Sounds like a DB connection issue, TBH.

  i.e. if FreeRADIUS can't talk to the database, it can't get the user credentials.  So to be safe, it has to reject the user.

  Are there *other* error messages in the logs, around the same time that user is rejected?

> This happened on multiple instances in multiple locations.
> Restarting the instances seemed to clear the issue for a while, but it's
> resurfaced (after about 12 days).
> 
> I do not think that the request is getting to the "authorize" phase because
> there is no message from the python plug-in indicating that it started.

  What "python plugin?"

  i.e. we don't have access to your system.  So you shouldn't assume that we know what you're talking about, when you refer to custom changes you made.

> So maybe this comes from some pre-authorize step?

  Maybe.  It depends on how you configured it.  If the configuration says to reject the user in the "authorize" stage, then it rejects the user.

> I scanned all the configuration and don't find that string "Invalid user"
> anywhere, 
> so I'm thinking it's generated internally when something else fails.

  It's in the source.

> Unfortunately, this is in a locked-down, production environment and I can't
> just "start it up in debug mode"
> Is this something you have seen before?
> Is there something I might do to increase the log level?  Where, how, and of
> what?

  see raddb/sites-enabled/control-socket, and "radmin".

> We are running version 3.0.17.

  Probably upgrade to 3.0.21.  It might not help this issue, but it's not a bad idea.

  Alan DeKok.