ssh: tracing and better pollset handling

Remove connection member `waitfor` and keep it in the SSH connection
meta. Add `ssh` to supported tracing features, convert many DEBUGF
printgs to traces.

Closes #19745
This commit is contained in:
Stefan Eissing 2025-11-28 12:49:16 +01:00 committed by Daniel Stenberg
parent e25a3c6734
commit 12a3182fc3
No known key found for this signature in database
GPG key ID: 5CC908FDB71E12C2
7 changed files with 178 additions and 107 deletions

View file

@ -280,17 +280,10 @@ static LIBSSH2_FREE_FUNC(my_libssh2_free)
Curl_cfree(ptr);
}
/*
* SSH State machine related code
*/
/* This is the ONLY way to change SSH state! */
static void myssh_state(struct Curl_easy *data,
struct ssh_conn *sshc,
sshstate nowstate)
#if !defined(CURL_DISABLE_VERBOSE_STRINGS)
static const char *myssh_statename(sshstate state)
{
#if defined(DEBUGBUILD) && !defined(CURL_DISABLE_VERBOSE_STRINGS)
/* for debug purposes */
static const char * const names[] = {
static const char *const names[] = {
"SSH_STOP",
"SSH_INIT",
"SSH_S_STARTUP",
@ -352,16 +345,34 @@ static void myssh_state(struct Curl_easy *data,
"SSH_SESSION_FREE",
"QUIT"
};
/* a precaution to make sure the lists are in sync */
DEBUGASSERT(CURL_ARRAYSIZE(names) == SSH_LAST);
return ((size_t)state < CURL_ARRAYSIZE(names)) ? names[state] : "";
}
#else
#define myssh_statename(x) ""
#endif /* !CURL_DISABLE_VERBOSE_STRINGS */
#define myssh_state(x,y,z) myssh_set_state(x,y,z)
/*
* SSH State machine related code
*/
/* This is the ONLY way to change SSH state! */
static void myssh_set_state(struct Curl_easy *data,
struct ssh_conn *sshc,
sshstate nowstate)
{
#if !defined(CURL_DISABLE_VERBOSE_STRINGS)
if(sshc->state != nowstate) {
infof(data, "SFTP %p state change from %s to %s",
(void *)sshc, names[sshc->state], names[nowstate]);
CURL_TRC_SSH(data, "[%s] -> [%s]",
myssh_statename(sshc->state),
myssh_statename(nowstate));
}
#endif
#else
(void)data;
#endif
sshc->state = nowstate;
}
@ -1172,10 +1183,6 @@ sftp_upload_init(struct Curl_easy *data,
/* not set by Curl_xfer_setup to preserve keepon bits */
data->conn->recv_idx = FIRSTSOCKET;
/* store this original bitmask setup to use later on if we cannot
figure out a "real" bitmask */
sshc->orig_waitfor = data->req.keepon;
/* since we do not really wait for anything at this point, we want the
state machine to move on as soon as possible so mark this as dirty */
Curl_multi_mark_dirty(data);
@ -1951,8 +1958,7 @@ static CURLcode ssh_state_sftp_realpath(struct Curl_easy *data,
/* in this case, the error was not in the SFTP level but for example a
time-out or similar */
result = CURLE_SSH;
DEBUGF(infof(data, "error = %lu makes libcurl = %d",
sftperr, (int)result));
CURL_TRC_SSH(data, "error = %lu makes libcurl = %d", sftperr, (int)result);
return result;
}
@ -1960,7 +1966,7 @@ static CURLcode ssh_state_sftp_realpath(struct Curl_easy *data,
get the homedir here, we get the "workingpath" in the DO action since the
homedir will remain the same between request but the working path will
not. */
DEBUGF(infof(data, "SSH CONNECT phase done"));
CURL_TRC_SSH(data, "CONNECT phase done");
return CURLE_OK;
}
@ -2418,7 +2424,7 @@ static CURLcode ssh_state_sftp_close(struct Curl_easy *data,
Curl_safefree(sshp->path);
DEBUGF(infof(data, "SFTP DONE done"));
CURL_TRC_SSH(data, "SFTP DONE done");
/* Check if nextstate is set and move .nextstate could be POSTQUOTE_INIT
After nextstate is executed, the control should come back to
@ -2542,10 +2548,6 @@ static CURLcode ssh_state_scp_upload_init(struct Curl_easy *data,
/* not set by Curl_xfer_setup to preserve keepon bits */
data->conn->recv_idx = FIRSTSOCKET;
/* store this original bitmask setup to use later on if we cannot
figure out a "real" bitmask */
sshc->orig_waitfor = data->req.keepon;
myssh_state(data, sshc, SSH_STOP);
return CURLE_OK;
@ -3008,7 +3010,7 @@ static CURLcode ssh_statemachine(struct Curl_easy *data,
}
sshc->ssh_channel = NULL;
}
DEBUGF(infof(data, "SCP DONE phase complete"));
CURL_TRC_SSH(data, "SCP DONE phase complete");
myssh_state(data, sshc, SSH_STOP);
break;
@ -3042,6 +3044,8 @@ static CURLcode ssh_statemachine(struct Curl_easy *data,
*block = TRUE;
result = CURLE_OK;
}
CURL_TRC_SSH(data, "[%s] statemachine() -> %d, block=%d",
myssh_statename(sshc->state), result, *block);
return result;
}
@ -3051,15 +3055,29 @@ static CURLcode ssh_statemachine(struct Curl_easy *data,
static CURLcode ssh_pollset(struct Curl_easy *data,
struct easy_pollset *ps)
{
int flags = 0;
struct connectdata *conn = data->conn;
if(conn->waitfor & KEEP_RECV)
flags |= CURL_POLL_IN;
if(conn->waitfor & KEEP_SEND)
flags |= CURL_POLL_OUT;
return flags ?
Curl_pollset_change(data, ps, conn->sock[FIRSTSOCKET], flags, 0) :
CURLE_OK;
struct ssh_conn *sshc = Curl_conn_meta_get(conn, CURL_META_SSH_CONN);
curl_socket_t sock = conn->sock[FIRSTSOCKET];
int waitfor;
if(!sshc || (sock == CURL_SOCKET_BAD))
return CURLE_FAILED_INIT;
waitfor = sshc->waitfor ? sshc->waitfor : data->req.keepon;
if(waitfor) {
int flags = 0;
if(waitfor & KEEP_RECV)
flags |= CURL_POLL_IN;
if(waitfor & KEEP_SEND)
flags |= CURL_POLL_OUT;
DEBUGASSERT(flags);
CURL_TRC_SSH(data, "pollset, flags=%x", flags);
return Curl_pollset_change(data, ps, sock, flags, 0);
}
/* While we still have a session, we listen incoming data. */
if(sshc->ssh_session)
return Curl_pollset_change(data, ps, sock, CURL_POLL_IN, 0);
return CURLE_OK;
}
/*
@ -3073,20 +3091,18 @@ static void ssh_block2waitfor(struct Curl_easy *data,
struct ssh_conn *sshc,
bool block)
{
struct connectdata *conn = data->conn;
int dir = 0;
(void)data;
if(block) {
dir = libssh2_session_block_directions(sshc->ssh_session);
if(dir) {
/* translate the libssh2 define bits into our own bit defines */
conn->waitfor = ((dir&LIBSSH2_SESSION_BLOCK_INBOUND) ? KEEP_RECV : 0) |
sshc->waitfor = ((dir&LIBSSH2_SESSION_BLOCK_INBOUND) ? KEEP_RECV : 0) |
((dir&LIBSSH2_SESSION_BLOCK_OUTBOUND) ? KEEP_SEND : 0);
}
}
if(!dir)
/* It did not block or libssh2 did not reveal in which direction, put back
the original set */
conn->waitfor = sshc->orig_waitfor;
sshc->waitfor = 0;
}
/* called repeatedly until done from multi.c */
@ -3468,7 +3484,7 @@ CURLcode scp_perform(struct Curl_easy *data,
struct ssh_conn *sshc = Curl_conn_meta_get(data->conn, CURL_META_SSH_CONN);
CURLcode result = CURLE_OK;
DEBUGF(infof(data, "DO phase starts"));
CURL_TRC_SSH(data, "DO phase starts");
*dophase_done = FALSE; /* not done yet */
if(!sshc)
@ -3483,7 +3499,7 @@ CURLcode scp_perform(struct Curl_easy *data,
*connected = Curl_conn_is_connected(data->conn, FIRSTSOCKET);
if(*dophase_done) {
DEBUGF(infof(data, "DO phase is complete"));
CURL_TRC_SSH(data, "DO phase is complete");
}
return result;
@ -3497,7 +3513,7 @@ static CURLcode scp_doing(struct Curl_easy *data,
result = ssh_multi_statemach(data, dophase_done);
if(*dophase_done) {
DEBUGF(infof(data, "DO phase is complete"));
CURL_TRC_SSH(data, "DO phase is complete");
}
return result;
}
@ -3778,7 +3794,7 @@ CURLcode sftp_perform(struct Curl_easy *data,
struct ssh_conn *sshc = Curl_conn_meta_get(data->conn, CURL_META_SSH_CONN);
CURLcode result = CURLE_OK;
DEBUGF(infof(data, "DO phase starts"));
CURL_TRC_SSH(data, "DO phase starts");
*dophase_done = FALSE; /* not done yet */
if(!sshc)
@ -3793,7 +3809,7 @@ CURLcode sftp_perform(struct Curl_easy *data,
*connected = Curl_conn_is_connected(data->conn, FIRSTSOCKET);
if(*dophase_done) {
DEBUGF(infof(data, "DO phase is complete"));
CURL_TRC_SSH(data, "DO phase is complete");
}
return result;
@ -3806,7 +3822,7 @@ static CURLcode sftp_doing(struct Curl_easy *data,
CURLcode result = ssh_multi_statemach(data, dophase_done);
if(*dophase_done) {
DEBUGF(infof(data, "DO phase is complete"));
CURL_TRC_SSH(data, "DO phase is complete");
}
return result;
}
@ -3825,10 +3841,10 @@ static CURLcode sftp_disconnect(struct Curl_easy *data,
if(sshc) {
if(sshc->ssh_session) {
/* only if there is a session still around to use! */
DEBUGF(infof(data, "SSH DISCONNECT starts now"));
CURL_TRC_SSH(data, "DISCONNECT starts now");
myssh_state(data, sshc, SSH_SFTP_SHUTDOWN);
result = ssh_block_statemach(data, sshc, sshp, TRUE);
DEBUGF(infof(data, "SSH DISCONNECT is done -> %d", result));
CURL_TRC_SSH(data, "DISCONNECT is done -> %d", result);
}
sshc_cleanup(sshc, data, TRUE);
}