When debugging communication between ThinLinc components, it can be useful to see when a service is actively rejecting requests to determine where the problem is. Malicious or bogus requests would trigger such a logging, though, so it is probably not a good idea for it to log that by default, though. Right now (with debug logs) we log "Handling connection from ..." for each incoming request. But nothing more, except for any logging done by the handler. So it's difficult to see what happened to this request.
Should be fixed now. I found the following cases where a request fails: * Client isn't authorized * The wrong number of arguments were given * An unknown method was given * The handler crashed * The handler rejected the request The crash case is already handled as we propagate those crashes to the event loop and things get logged that way. The general code cannot determine if a handler rejected a request as doesn't know which return values are good and which are bad. As such, I'm ignoring that part for now and assume it is good enough for most cases. The other cases have got fixes for the three servers we have; vsmserver's main TCP server, vsmserver's Unix servers, and vsmagent's TCP server. All cases were also tested by writing a small Python script to call things in the right manner. > * If a request isn't completed, the log should show why I think so. Each failure case has its own string to show why things failed. > * Unauthenticated requests should not trigger any logging by default Indeed. Everything is logged at a debug log level, which isn't enabled by default. > * It should be possible to tell where the request is coming from Mostly. The TCP requests include an IP address and a port, which should be good enough. The Unix requests include which user's socket is being used, but it doesn't have much else to present. > * It should be possible to tell why the request is failing I think so. It includes some details relevant to the different types of failures. It includes the address for authorization issues, and the method name when the parameters are wrong or when the method is unknown.
Tested with server build 3453 on RHEL 9 by using a fake client to trigger the different paths in vsmserver. > MUST: > * If a request isn't completed, the log should show why Yes, tested the 5 scenarios described in comment 4 for vsmserver TCP. For scenarios 'Client isn't authorized', 'The wrong number of arguments were given' and 'An unknown method was given', the respective log line is shown below. When the handler crashes we get a traceback. We looked through the code for handler to see what happens when a request is rejected, and they either log why it was rejected, or sends an error code so the caller have the chance to log appropriately. > 2023-12-21 16:05:53 DEBUG vsmserver: Unauthorized request from (<client ip>, <port>) > 2023-12-21 16:14:12 DEBUG vsmserver: Incorrect parameters to method 'get_loadstatus' from (<client ip>, <port>) > 2023-12-21 16:02:28 DEBUG vsmserver: Unknown method 'shadow_session' from (<client ip>, <port>) > * Unauthenticated requests should not trigger any logging by default All new logging is done on DEBUG level, which is lower than our default level. > SHOULD: > * It should be possible to tell where the request is coming from Yes, the bugs show the client IP and the port. > * It should be possible to tell why the request is failing I think so. It gives a clear hint about what's going on without giving too much away to malicious users.
