Skip to content

Commit

Permalink
Server: Further logging improvements
Browse files Browse the repository at this point in the history 
1. When possible, prefix log entries related to a specific viewer with
   the viewer's ID.

2. Do not report the IP address from which the viewer connection
   originated, except at connection time.  (1) makes it unnecessary to
   report that information at any other time.

3. At connection time, report the port from which the viewer connection
   originated.  (This information might be useful in conjunction with
   netstat, lsof, or other tools.)

4. Assign a unique ID to every viewer connection, regardless of whether
   the connection is successfully authenticated and initialized.  This
   makes it easier to distinguish failed connections from successful
   ones.
  • Loading branch information
@dcommander
dcommander committed Jul 2, 2024
1 parent 5ae86b0 commit 1ef8e0b
Show file tree
Hide file tree
Showing 15 changed files with 348 additions and 365 deletions.
12 changes: 4 additions & 8 deletions ChangeLog.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -43,14 +43,10 @@ until F10, left Alt, or Esc was pressed to dismiss the menu.
running in a TurboVNC session attempted to display to a local Wayland session
if one was active.

8. The TurboVNC Server now assigns an ordinal ID to every VNC viewer after the
viewer successfully connects, and the viewer's ID is reported in the TurboVNC
session log along with the IP address from which the viewer connection
originated. This makes it easier to distinguish log entries related to a
specific viewer, especially when using SSH tunneling (which makes it appear as
if all viewer connections originate from the loopback IP address.) The
TurboVNC Server now also logs the total number of simultaneously connected
viewers.
8. The TurboVNC Server now assigns an ordinal ID to every VNC viewer when the
viewer connects, and when possible, log entries related to a specific viewer
are prefixed by the viewer's ID. The TurboVNC Server now also logs the total
number of simultaneously connected viewers.

9. The TurboVNC Viewer now sends horizontal scroll wheel events to the VNC
server. (These events can be generated with horizontal scroll gestures on a
Expand Down
69 changes: 33 additions & 36 deletions unix/Xvnc/programs/Xserver/hw/vnc/auth.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -199,7 +199,7 @@ static void AuthPAMUserPwdRspFunc(rfbClientPtr cl)
UserList *p = userACL;

if (p == NULL)
rfbLog("WARNING: User ACL is empty. No users will be allowed to log in with Unix Login authentication.\n");
RFBLOGID("WARNING: User ACL is empty. No users will be allowed to log in with Unix Login authentication.\n");

while (p != NULL) {
if (!strcmp(p->name, userBuf))
Expand All @@ -208,8 +208,8 @@ static void AuthPAMUserPwdRspFunc(rfbClientPtr cl)
}

if (p == NULL) {
rfbLog("User '%s' is not in the ACL and has been denied access\n",
userBuf);
RFBLOGID("User '%s' is not in the ACL and has been denied access\n",
userBuf);
rfbClientAuthFailed(cl, "User denied access");
return;
}
Expand All @@ -225,18 +225,18 @@ static void AuthPAMUserPwdRspFunc(rfbClientPtr cl)
strerror(errno));

if (strcmp(pbuf.pw_name, userBuf)) {
rfbLog("User '%s' denied access (not the session owner)\n", userBuf);
rfbLog(" Enable user ACL to grant access to other users.\n");
RFBLOGID("User '%s' denied access (not the session owner)\n", userBuf);
RFBLOGID(" Enable user ACL to grant access to other users.\n");
rfbClientAuthFailed(cl, "User denied access");
return;
}
}

if (rfbPAMAuthenticate(cl, pamServiceName, userBuf, pwdBuf, &emsg)) {
rfbClientAuthSucceeded(cl, rfbAuthUnixLogin);
rfbLog("PAM authentication succeeded for user '%s'\n", userBuf);
RFBLOGID("PAM authentication succeeded for user '%s'\n", userBuf);
} else {
rfbLog("PAM authentication failed for user '%s'\n", userBuf);
RFBLOGID("PAM authentication failed for user '%s'\n", userBuf);
rfbClientAuthFailed(cl, (char *)emsg);
}
}
Expand Down Expand Up @@ -797,7 +797,7 @@ void rfbAuthProcessResponse(rfbClientPtr cl)
}
}

rfbLog("rfbAuthProcessResponse: authType assertion failed\n");
RFBLOGID("rfbAuthProcessResponse: authType assertion failed\n");
rfbCloseClient(cl);
}

Expand All @@ -815,7 +815,7 @@ void rfbAuthNewClient(rfbClientPtr cl)
RFBSecTypeData *r;

if (rfbAuthIsBlocked(cl->host)) {
rfbLog("Too many authentication failures - client rejected\n");
RFBLOGID("Too many authentication failures - client rejected\n");
rfbClientConnFailed(cl, "Too many authentication failures. Client temporarily blocked");
return;
}
Expand All @@ -833,7 +833,7 @@ void rfbAuthNewClient(rfbClientPtr cl)
}

if (*p == NULL) {
rfbLog("VNC authentication disabled - RFB 3.3 client rejected\n");
RFBLOGID("VNC authentication disabled - RFB 3.3 client rejected\n");
rfbClientConnFailed(cl, "Your viewer cannot handle required security types");
return;
}
Expand Down Expand Up @@ -898,8 +898,8 @@ static void rfbSendSecurityTypeList(rfbClientPtr cl)
continue;

if (cl->reverseConnection && !strncmp(s->name, "x509", 4)) {
rfbLog("Security type \'%s\' disabled for reverse connections\n",
s->name);
RFBLOGID("Security type \'%s\' disabled for reverse connections\n",
s->name);
continue;
}

Expand Down Expand Up @@ -939,7 +939,7 @@ static void rfbSendSecurityTypeList(rfbClientPtr cl)
if (n > MAX_SECURITY_TYPES)
FatalError("rfbSendSecurityTypeList: # enabled security types > MAX_SECURITY_TYPES");

rfbLog("rfbSendSecurityTypeList: advertise sectype tight\n");
RFBLOGID("rfbSendSecurityTypeList: advertise sectype tight\n");
cl->securityTypes[++n] = rfbSecTypeTight;
}

Expand Down Expand Up @@ -986,7 +986,7 @@ static void rfbSendSecurityTypeList(rfbClientPtr cl)
rfbCloseClient(cl); \
return; \
} else if (ret == 1) { \
rfbLog("Deferring TLS handshake\n"); \
RFBLOGID("Deferring TLS handshake\n"); \
cl->state = RFB_TLS_HANDSHAKE; \
return; \
}
Expand Down Expand Up @@ -1091,9 +1091,9 @@ void rfbVeNCryptAuthenticate(rfbClientPtr cl)
if (chosenType == subTypes[i])
break;
}
rfbLog("Client requested VeNCrypt sub-type %d\n", chosenType);
RFBLOGID("Client requested VeNCrypt sub-type %d\n", chosenType);
if (chosenType == 0 || chosenType == rfbSecTypeVeNCrypt || i >= count) {
rfbLog("Requested VeNCrypt sub-type not supported\n");
RFBLOGID("Requested VeNCrypt sub-type not supported\n");
rfbCloseClient(cl);
return;
}
Expand Down Expand Up @@ -1166,7 +1166,7 @@ void rfbProcessClientSecurityType(rfbClientPtr cl)
n = ReadExact(cl, (char *)&chosenType, 1);
if (n <= 0) {
if (n == 0)
rfbLog("rfbProcessClientSecurityType: client gone\n");
RFBLOGID("rfbProcessClientSecurityType: client gone\n");
else
rfbLogPerror("rfbProcessClientSecurityType: read");
rfbCloseClient(cl);
Expand All @@ -1180,7 +1180,7 @@ void rfbProcessClientSecurityType(rfbClientPtr cl)
break;
}
if (i > count) {
rfbLog("rfbProcessClientSecurityType: wrong security type requested\n");
RFBLOGID("rfbProcessClientSecurityType: wrong security type requested\n");
rfbCloseClient(cl);
return;
}
Expand All @@ -1197,19 +1197,19 @@ void rfbProcessClientSecurityType(rfbClientPtr cl)
break;
case rfbSecTypeTight:
/* The viewer supports TightVNC extensions */
rfbLog("Enabling TightVNC protocol extensions\n");
RFBLOGID("Enabling TightVNC protocol extensions\n");
/* Switch to protocol 3.7t/3.8t */
cl->protocol_tightvnc = TRUE;
/* Advertise our tunneling capabilities */
rfbSendTunnelingCaps(cl);
break;
case rfbSecTypeVeNCrypt:
/* The viewer supports VeNCrypt extensions */
rfbLog("Enabling VeNCrypt protocol extensions\n");
RFBLOGID("Enabling VeNCrypt protocol extensions\n");
rfbVeNCryptAuthenticate(cl);
break;
default:
rfbLog("rfbProcessClientSecurityType: unknown authentication scheme\n");
RFBLOGID("rfbProcessClientSecurityType: unknown authentication scheme\n");
rfbCloseClient(cl);
break;
}
Expand Down Expand Up @@ -1250,7 +1250,7 @@ static void rfbSendTunnelingCaps(rfbClientPtr cl)
void rfbProcessClientTunnelingType(rfbClientPtr cl)
{
/* If we were called, then something's really wrong. */
rfbLog("rfbProcessClientTunnelingType: not implemented\n");
RFBLOGID("rfbProcessClientTunnelingType: not implemented\n");
rfbCloseClient(cl);
}

Expand Down Expand Up @@ -1311,7 +1311,7 @@ static void rfbSendAuthCaps(rfbClientPtr cl)
cl->authCaps[count] = c->authType;
strncpy(tempstr, (char *)pcap->nameSignature, 8);
tempstr[8] = 0;
rfbLog("Advertising Tight auth cap '%s'\n", tempstr);
RFBLOGID("Advertising Tight auth cap '%s'\n", tempstr);
count++;
}
}
Expand Down Expand Up @@ -1358,7 +1358,7 @@ void rfbProcessClientAuthType(rfbClientPtr cl)
n = ReadExact(cl, (char *)&auth_type, sizeof(auth_type));
if (n <= 0) {
if (n == 0)
rfbLog("rfbProcessClientAuthType: client gone\n");
RFBLOGID("rfbProcessClientAuthType: client gone\n");
else
rfbLogPerror("rfbProcessClientAuthType: read");
rfbCloseClient(cl);
Expand All @@ -1372,7 +1372,7 @@ void rfbProcessClientAuthType(rfbClientPtr cl)
break;
}
if (i >= cl->nAuthCaps) {
rfbLog("rfbProcessClientAuthType: wrong authentication type requested\n");
RFBLOGID("rfbProcessClientAuthType: wrong authentication type requested\n");
rfbCloseClient(cl);
return;
}
Expand All @@ -1386,7 +1386,7 @@ void rfbProcessClientAuthType(rfbClientPtr cl)
}
}

rfbLog("rfbProcessClientAuthType: unknown authentication scheme\n");
RFBLOGID("rfbProcessClientAuthType: unknown authentication scheme\n");
rfbCloseClient(cl);
}

Expand Down Expand Up @@ -1428,14 +1428,12 @@ static Bool CheckResponse(rfbClientPtr cl, int numPasswords,
memset(passwdViewOnly, 0, MAXPWLEN + 1);

if (memcmp(encryptedChallenge1, response, CHALLENGESIZE) == 0) {
rfbLog("Full-control authentication enabled for Client %d (%s)\n", cl->id,
cl->host);
RFBLOGID("Full-control authentication enabled\n");
ok = TRUE;
cl->viewOnly = FALSE;

} else if (memcmp(encryptedChallenge2, response, CHALLENGESIZE) == 0) {
rfbLog("View-only authentication enabled for Client %d (%s)\n", cl->id,
cl->host);
RFBLOGID("View-only authentication enabled\n");
ok = TRUE;
cl->viewOnly = TRUE;
}
Expand Down Expand Up @@ -1503,8 +1501,8 @@ void rfbVncAuthProcessResponse(rfbClientPtr cl)
passwdFullControl,
passwdViewOnly);
if (numPasswords == 0) {
rfbLog("rfbVncAuthProcessResponse: could not get password from %s\n",
rfbAuthPasswdFile);
RFBLOGID("rfbVncAuthProcessResponse: could not get password from %s\n",
rfbAuthPasswdFile);

if (nSecTypesEnabled == 1) {
rfbClientAuthFailed(cl, "The server could not read the VNC password file");
Expand All @@ -1523,17 +1521,16 @@ void rfbVncAuthProcessResponse(rfbClientPtr cl)
if (!cl->reverseConnection && rfbNeverShared && !rfbDisconnect) {
for (otherCl = rfbClientHead; otherCl; otherCl = otherCl->next) {
if ((otherCl != cl) && (otherCl->state == RFB_NORMAL)) {
rfbLog("-dontdisconnect: Not shared & existing client\n");
rfbLog(" refusing new client %d (%s)\n", cl->id, cl->host);
RFBLOGID("-dontdisconnect: Not shared & existing client\n");
RFBLOGID(" refusing new client\n");
rfbClientAuthFailed(cl, "Authentication failed. The server is already in use.");
return;
}
}
}
rfbClientAuthSucceeded(cl, rfbAuthVNC);
} else {
rfbLog("rfbVncAuthProcessResponse: authentication failed from Client %d (%s)\n",
cl->id, cl->host);
RFBLOGID("rfbVncAuthProcessResponse: authentication failed\n");
if (rfbAuthConsiderBlocking(cl->host))
rfbClientAuthFailed(cl, "Authentication failed. Client temporarily blocked");
else
Expand Down
30 changes: 15 additions & 15 deletions unix/Xvnc/programs/Xserver/hw/vnc/authpam.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -129,39 +129,39 @@ Bool rfbPAMAuthenticate(rfbClientPtr cl, const char *svc, const char *user,
pamConv.conv = conv;
pamConv.appdata_ptr = 0;
if ((r = pam_start(svc, user, &pamConv, &pamHandle)) != PAM_SUCCESS) {
rfbLog("PAMAuthenticate: pam_start: %s\n", pam_strerror(pamHandle, r));
RFBLOGID("PAMAuthenticate: pam_start: %s\n", pam_strerror(pamHandle, r));
return FALSE;
}

if ((r = pam_set_item(pamHandle, PAM_RHOST, cl->host)) != PAM_SUCCESS) {
rfbLog("PAMAuthenticate: pam_set_item PAM_RHOST: %s\n",
pam_strerror(pamHandle, r));
RFBLOGID("PAMAuthenticate: pam_set_item PAM_RHOST: %s\n",
pam_strerror(pamHandle, r));
return FALSE;
}

authStatus = pam_authenticate(pamHandle, PAM_DISALLOW_NULL_AUTHTOK);
if (authStatus != PAM_SUCCESS) {
rfbLog("PAMAuthenticate: pam_authenticate: %s\n",
pam_strerror(pamHandle, authStatus));
RFBLOGID("PAMAuthenticate: pam_authenticate: %s\n",
pam_strerror(pamHandle, authStatus));
} else {
/* Authentication was successful. Validate the user's account status. */
authStatus = pam_acct_mgmt(pamHandle, PAM_DISALLOW_NULL_AUTHTOK);
if (authStatus != PAM_SUCCESS) {
rfbLog("PAMAuthenticate: pam_acct_mgmt: %s\n",
pam_strerror(pamHandle, authStatus));
RFBLOGID("PAMAuthenticate: pam_acct_mgmt: %s\n",
pam_strerror(pamHandle, authStatus));
} else if (pamSession) {
if ((authStatus = pam_open_session(pamHandle, 0)) != PAM_SUCCESS) {
rfbLog("PAMAuthenticate: pam_open_session: %s\n",
pam_strerror(pamHandle, authStatus));
RFBLOGID("PAMAuthenticate: pam_open_session: %s\n",
pam_strerror(pamHandle, authStatus));
} else {
rfbLog("Opened PAM session for Client %d (%s)\n", cl->id, cl->host);
RFBLOGID("Opened PAM session\n");
}
}
}

if (authStatus != PAM_SUCCESS || !pamSession) {
if ((r = pam_end(pamHandle, authStatus)) != PAM_SUCCESS)
rfbLog("PAMAuthenticate: pam_end: %s\n", pam_strerror(pamHandle, r));
RFBLOGID("PAMAuthenticate: pam_end: %s\n", pam_strerror(pamHandle, r));
} else
cl->pamHandle = pamHandle;

Expand Down Expand Up @@ -207,13 +207,13 @@ void rfbPAMEnd(rfbClientPtr cl)

if (cl->pamHandle) {
if ((r = pam_close_session(cl->pamHandle, 0)) != PAM_SUCCESS)
rfbLog("PAMEnd: pam_close_session: %s\n",
pam_strerror(cl->pamHandle, r));
RFBLOGID("PAMEnd: pam_close_session: %s\n",
pam_strerror(cl->pamHandle, r));

if ((r = pam_end(cl->pamHandle, PAM_SUCCESS)) != PAM_SUCCESS)
rfbLog("PAMEnd: pam_end: %s\n", pam_strerror(cl->pamHandle, r));
RFBLOGID("PAMEnd: pam_end: %s\n", pam_strerror(cl->pamHandle, r));

rfbLog("Closed PAM session for Client %d (%s)\n", cl->id, cl->host);
RFBLOGID("Closed PAM session\n");
cl->pamHandle = 0;
}
}
Loading

0 comments on commit 1ef8e0b

Please sign in to comment.