ftp: add tracing support
- add `Curl_trc_feat_ftp` for tracing via trace config - add macro CURL_TRC_FTP(data, fmt, ...) - replace DEBUGF(infof()) statements in ftp.c by CURL_TRC_FTP() - always trace FTP connection state Closes #13580
This commit is contained in:
Stefan Eissing
Daniel Stenberg
Родитель
7b5bacdd0a
Коммит
b7c7dffe35
|
|
@ -74,6 +74,10 @@ Tracing of TCP socket handling: connect, sends, receives.
|
|||
|
||||
Tracing of SSL/TLS operations, whichever SSL backend is used in your build.
|
||||
|
||||
## `ftp`
|
||||
|
||||
Tracing of FTP operations when this protocol is enabled in your build.
|
||||
|
||||
## `http/2`
|
||||
|
||||
Details about HTTP/2 handling: frames, events, I/O, etc.
|
||||
|
|
|
|||
|
|
@ -194,9 +194,30 @@ void Curl_trc_write(struct Curl_easy *data, const char *fmt, ...)
|
|||
}
|
||||
}
|
||||
|
||||
#ifndef CURL_DISABLE_FTP
|
||||
struct curl_trc_feat Curl_trc_feat_ftp = {
|
||||
"FTP",
|
||||
CURL_LOG_LVL_NONE,
|
||||
};
|
||||
|
||||
void Curl_trc_ftp(struct Curl_easy *data, const char *fmt, ...)
|
||||
{
|
||||
DEBUGASSERT(!strchr(fmt, '\n'));
|
||||
if(Curl_trc_ft_is_verbose(data, &Curl_trc_feat_ftp)) {
|
||||
va_list ap;
|
||||
va_start(ap, fmt);
|
||||
trc_infof(data, &Curl_trc_feat_ftp, fmt, ap);
|
||||
va_end(ap);
|
||||
}
|
||||
}
|
||||
#endif /* !CURL_DISABLE_FTP */
|
||||
|
||||
static struct curl_trc_feat *trc_feats[] = {
|
||||
&Curl_trc_feat_read,
|
||||
&Curl_trc_feat_write,
|
||||
#ifndef CURL_DISABLE_FTP
|
||||
&Curl_trc_feat_ftp,
|
||||
#endif
|
||||
#ifndef CURL_DISABLE_DOH
|
||||
&Curl_doh_trc,
|
||||
#endif
|
||||
|
|
|
|||
|
|
@ -84,13 +84,25 @@ void Curl_failf(struct Curl_easy *data,
|
|||
do { if(Curl_trc_ft_is_verbose(data, &Curl_trc_feat_read)) \
|
||||
Curl_trc_read(data, __VA_ARGS__); } while(0)
|
||||
|
||||
#else
|
||||
#ifndef CURL_DISABLE_FTP
|
||||
#define CURL_TRC_FTP(data, ...) \
|
||||
do { if(Curl_trc_ft_is_verbose(data, &Curl_trc_feat_ftp)) \
|
||||
Curl_trc_ftp(data, __VA_ARGS__); } while(0)
|
||||
#endif /* !CURL_DISABLE_FTP */
|
||||
|
||||
#else /* CURL_HAVE_C99 */
|
||||
|
||||
#define infof Curl_infof
|
||||
#define CURL_TRC_CF Curl_trc_cf_infof
|
||||
#define CURL_TRC_WRITE Curl_trc_write
|
||||
#define CURL_TRC_READ Curl_trc_read
|
||||
|
||||
#ifndef CURL_DISABLE_FTP
|
||||
#define CURL_TRC_FTP Curl_trc_ftp
|
||||
#endif
|
||||
|
||||
#endif /* !CURL_HAVE_C99 */
|
||||
|
||||
#ifndef CURL_DISABLE_VERBOSE_STRINGS
|
||||
/* informational messages enabled */
|
||||
|
||||
|
|
@ -131,8 +143,11 @@ void Curl_trc_write(struct Curl_easy *data,
|
|||
void Curl_trc_read(struct Curl_easy *data,
|
||||
const char *fmt, ...) CURL_PRINTF(2, 3);
|
||||
|
||||
|
||||
|
||||
#ifndef CURL_DISABLE_FTP
|
||||
extern struct curl_trc_feat Curl_trc_feat_ftp;
|
||||
void Curl_trc_ftp(struct Curl_easy *data,
|
||||
const char *fmt, ...) CURL_PRINTF(2, 3);
|
||||
#endif
|
||||
|
||||
|
||||
#else /* defined(CURL_DISABLE_VERBOSE_STRINGS) */
|
||||
|
|
@ -173,6 +188,13 @@ static void Curl_trc_read(struct Curl_easy *data, const char *fmt, ...)
|
|||
(void)data; (void)fmt;
|
||||
}
|
||||
|
||||
#ifndef CURL_DISABLE_FTP
|
||||
static void Curl_trc_ftp(struct Curl_easy *data, const char *fmt, ...)
|
||||
{
|
||||
(void)data; (void)fmt;
|
||||
}
|
||||
#endif
|
||||
|
||||
#endif /* !defined(CURL_DISABLE_VERBOSE_STRINGS) */
|
||||
|
||||
#endif /* HEADER_CURL_TRC_H */
|
||||
|
|
|
|||
193
lib/ftp.c
193
lib/ftp.c
|
|
@ -95,19 +95,87 @@
|
|||
|
||||
#ifdef CURL_DISABLE_VERBOSE_STRINGS
|
||||
#define ftp_pasv_verbose(a,b,c,d) Curl_nop_stmt
|
||||
#define FTP_CSTATE(c) ""
|
||||
#define FTP_DSTATE(d) ""
|
||||
#else /* CURL_DISABLE_VERBOSE_STRINGS */
|
||||
/* for tracing purposes */
|
||||
static const char * const ftp_state_names[]={
|
||||
"STOP",
|
||||
"WAIT220",
|
||||
"AUTH",
|
||||
"USER",
|
||||
"PASS",
|
||||
"ACCT",
|
||||
"PBSZ",
|
||||
"PROT",
|
||||
"CCC",
|
||||
"PWD",
|
||||
"SYST",
|
||||
"NAMEFMT",
|
||||
"QUOTE",
|
||||
"RETR_PREQUOTE",
|
||||
"STOR_PREQUOTE",
|
||||
"POSTQUOTE",
|
||||
"CWD",
|
||||
"MKD",
|
||||
"MDTM",
|
||||
"TYPE",
|
||||
"LIST_TYPE",
|
||||
"RETR_TYPE",
|
||||
"STOR_TYPE",
|
||||
"SIZE",
|
||||
"RETR_SIZE",
|
||||
"STOR_SIZE",
|
||||
"REST",
|
||||
"RETR_REST",
|
||||
"PORT",
|
||||
"PRET",
|
||||
"PASV",
|
||||
"LIST",
|
||||
"RETR",
|
||||
"STOR",
|
||||
"QUIT"
|
||||
};
|
||||
#define FTP_CSTATE(c) ((c)? ftp_state_names[(c)->proto.ftpc.state] : "???")
|
||||
#define FTP_DSTATE(d) (((d) && (d)->conn)? \
|
||||
ftp_state_names[(d)->conn->proto.ftpc.state] : "???")
|
||||
|
||||
#endif /* !CURL_DISABLE_VERBOSE_STRINGS */
|
||||
|
||||
/* This is the ONLY way to change FTP state! */
|
||||
static void _ftp_state(struct Curl_easy *data,
|
||||
ftpstate newstate
|
||||
#ifdef DEBUGBUILD
|
||||
, int lineno
|
||||
#endif
|
||||
)
|
||||
{
|
||||
struct connectdata *conn = data->conn;
|
||||
struct ftp_conn *ftpc = &conn->proto.ftpc;
|
||||
|
||||
#if defined(CURL_DISABLE_VERBOSE_STRINGS)
|
||||
(void) lineno;
|
||||
#else /* CURL_DISABLE_VERBOSE_STRINGS */
|
||||
if(ftpc->state != newstate)
|
||||
#ifdef DEBUGBUILD
|
||||
CURL_TRC_FTP(data, "[%s] -> [%s] (line %d)", FTP_DSTATE(data),
|
||||
ftp_state_names[newstate], lineno);
|
||||
#else
|
||||
CURL_TRC_FTP(data, "[%s] -> [%s]", FTP_DSTATE(data),
|
||||
ftp_state_names[newstate]);
|
||||
#endif
|
||||
#endif /* !CURL_DISABLE_VERBOSE_STRINGS */
|
||||
|
||||
ftpc->state = newstate;
|
||||
}
|
||||
|
||||
|
||||
/* Local API functions */
|
||||
#ifndef DEBUGBUILD
|
||||
static void _ftp_state(struct Curl_easy *data,
|
||||
ftpstate newstate);
|
||||
#define ftp_state(x,y) _ftp_state(x,y)
|
||||
#else
|
||||
static void _ftp_state(struct Curl_easy *data,
|
||||
ftpstate newstate,
|
||||
int lineno);
|
||||
#else /* !DEBUGBUILD */
|
||||
#define ftp_state(x,y) _ftp_state(x,y,__LINE__)
|
||||
#endif
|
||||
#endif /* DEBUGBUILD */
|
||||
|
||||
static CURLcode ftp_sendquote(struct Curl_easy *data,
|
||||
struct connectdata *conn,
|
||||
|
|
@ -223,6 +291,7 @@ const struct Curl_handler Curl_handler_ftps = {
|
|||
static void close_secondarysocket(struct Curl_easy *data,
|
||||
struct connectdata *conn)
|
||||
{
|
||||
CURL_TRC_FTP(data, "[%s] closing DATA connection", FTP_DSTATE(data));
|
||||
Curl_conn_close(data, SECONDARYSOCKET);
|
||||
Curl_conn_cf_discard_all(data, conn, SECONDARYSOCKET);
|
||||
}
|
||||
|
|
@ -566,7 +635,7 @@ static CURLcode InitiateTransfer(struct Curl_easy *data)
|
|||
struct connectdata *conn = data->conn;
|
||||
bool connected;
|
||||
|
||||
DEBUGF(infof(data, "ftp InitiateTransfer()"));
|
||||
CURL_TRC_FTP(data, "InitiateTransfer()");
|
||||
if(conn->bits.ftp_use_data_ssl && data->set.ftp_use_port &&
|
||||
!Curl_conn_is_ssl(conn, SECONDARYSOCKET)) {
|
||||
result = Curl_ssl_cfilter_add(data, conn, SECONDARYSOCKET);
|
||||
|
|
@ -649,7 +718,7 @@ static CURLcode AllowServerConnect(struct Curl_easy *data, bool *connected)
|
|||
}
|
||||
|
||||
out:
|
||||
DEBUGF(infof(data, "ftp AllowServerConnect() -> %d", result));
|
||||
CURL_TRC_FTP(data, "AllowServerConnect() -> %d", result);
|
||||
return result;
|
||||
}
|
||||
|
||||
|
|
@ -831,73 +900,6 @@ CURLcode Curl_GetFTPResponse(struct Curl_easy *data,
|
|||
return result;
|
||||
}
|
||||
|
||||
#if defined(DEBUGBUILD) && !defined(CURL_DISABLE_VERBOSE_STRINGS)
|
||||
/* for debug purposes */
|
||||
static const char * const ftp_state_names[]={
|
||||
"STOP",
|
||||
"WAIT220",
|
||||
"AUTH",
|
||||
"USER",
|
||||
"PASS",
|
||||
"ACCT",
|
||||
"PBSZ",
|
||||
"PROT",
|
||||
"CCC",
|
||||
"PWD",
|
||||
"SYST",
|
||||
"NAMEFMT",
|
||||
"QUOTE",
|
||||
"RETR_PREQUOTE",
|
||||
"STOR_PREQUOTE",
|
||||
"POSTQUOTE",
|
||||
"CWD",
|
||||
"MKD",
|
||||
"MDTM",
|
||||
"TYPE",
|
||||
"LIST_TYPE",
|
||||
"RETR_TYPE",
|
||||
"STOR_TYPE",
|
||||
"SIZE",
|
||||
"RETR_SIZE",
|
||||
"STOR_SIZE",
|
||||
"REST",
|
||||
"RETR_REST",
|
||||
"PORT",
|
||||
"PRET",
|
||||
"PASV",
|
||||
"LIST",
|
||||
"RETR",
|
||||
"STOR",
|
||||
"QUIT"
|
||||
};
|
||||
#endif
|
||||
|
||||
/* This is the ONLY way to change FTP state! */
|
||||
static void _ftp_state(struct Curl_easy *data,
|
||||
ftpstate newstate
|
||||
#ifdef DEBUGBUILD
|
||||
, int lineno
|
||||
#endif
|
||||
)
|
||||
{
|
||||
struct connectdata *conn = data->conn;
|
||||
struct ftp_conn *ftpc = &conn->proto.ftpc;
|
||||
|
||||
#if defined(DEBUGBUILD)
|
||||
|
||||
#if defined(CURL_DISABLE_VERBOSE_STRINGS)
|
||||
(void) lineno;
|
||||
#else
|
||||
if(ftpc->state != newstate)
|
||||
infof(data, "FTP %p (line %d) state change from %s to %s",
|
||||
(void *)ftpc, lineno, ftp_state_names[ftpc->state],
|
||||
ftp_state_names[newstate]);
|
||||
#endif
|
||||
#endif
|
||||
|
||||
ftpc->state = newstate;
|
||||
}
|
||||
|
||||
static CURLcode ftp_state_user(struct Curl_easy *data,
|
||||
struct connectdata *conn)
|
||||
{
|
||||
|
|
@ -941,7 +943,7 @@ static int ftp_domore_getsock(struct Curl_easy *data,
|
|||
* remote site, or we could wait for that site to connect to us. Or just
|
||||
* handle ordinary commands.
|
||||
*/
|
||||
DEBUGF(infof(data, "ftp_domore_getsock()"));
|
||||
CURL_TRC_FTP(data, "[%s] ftp_domore_getsock()", FTP_DSTATE(data));
|
||||
|
||||
if(FTP_STOP == ftpc->state) {
|
||||
/* if stopped and still in this state, then we're also waiting for a
|
||||
|
|
@ -1208,7 +1210,8 @@ static CURLcode ftp_state_use_port(struct Curl_easy *data,
|
|||
Curl_strerror(error, buffer, sizeof(buffer)));
|
||||
goto out;
|
||||
}
|
||||
DEBUGF(infof(data, "ftp_state_use_port(), opened socket"));
|
||||
CURL_TRC_FTP(data, "[%s] ftp_state_use_port(), opened socket",
|
||||
FTP_DSTATE(data));
|
||||
|
||||
/* step 3, bind to a suitable local address */
|
||||
|
||||
|
|
@ -1269,7 +1272,8 @@ static CURLcode ftp_state_use_port(struct Curl_easy *data,
|
|||
Curl_strerror(SOCKERRNO, buffer, sizeof(buffer)));
|
||||
goto out;
|
||||
}
|
||||
DEBUGF(infof(data, "ftp_state_use_port(), socket bound to port %d", port));
|
||||
CURL_TRC_FTP(data, "[%s] ftp_state_use_port(), socket bound to port %d",
|
||||
FTP_DSTATE(data), port);
|
||||
|
||||
/* step 4, listen on the socket */
|
||||
|
||||
|
|
@ -1278,7 +1282,8 @@ static CURLcode ftp_state_use_port(struct Curl_easy *data,
|
|||
Curl_strerror(SOCKERRNO, buffer, sizeof(buffer)));
|
||||
goto out;
|
||||
}
|
||||
DEBUGF(infof(data, "ftp_state_use_port(), listening on %d", port));
|
||||
CURL_TRC_FTP(data, "[%s] ftp_state_use_port(), listening on %d",
|
||||
FTP_DSTATE(data), port);
|
||||
|
||||
/* step 5, send the proper FTP command */
|
||||
|
||||
|
|
@ -2353,7 +2358,7 @@ static CURLcode ftp_state_retr(struct Curl_easy *data,
|
|||
struct connectdata *conn = data->conn;
|
||||
struct ftp_conn *ftpc = &conn->proto.ftpc;
|
||||
|
||||
DEBUGF(infof(data, "ftp_state_retr()"));
|
||||
CURL_TRC_FTP(data, "[%s] ftp_state_retr()", FTP_DSTATE(data));
|
||||
if(data->set.max_filesize && (filesize > data->set.max_filesize)) {
|
||||
failf(data, "Maximum file size exceeded");
|
||||
return CURLE_FILESIZE_EXCEEDED;
|
||||
|
|
@ -3068,7 +3073,7 @@ static CURLcode ftp_statemachine(struct Curl_easy *data,
|
|||
}
|
||||
}
|
||||
ftp_state(data, FTP_STOP); /* we are done with the CONNECT phase! */
|
||||
DEBUGF(infof(data, "protocol connect phase DONE"));
|
||||
CURL_TRC_FTP(data, "[%s] protocol connect phase DONE", FTP_DSTATE(data));
|
||||
break;
|
||||
|
||||
case FTP_SYST:
|
||||
|
|
@ -3113,7 +3118,7 @@ static CURLcode ftp_statemachine(struct Curl_easy *data,
|
|||
}
|
||||
|
||||
ftp_state(data, FTP_STOP); /* we are done with the CONNECT phase! */
|
||||
DEBUGF(infof(data, "protocol connect phase DONE"));
|
||||
CURL_TRC_FTP(data, "[%s] protocol connect phase DONE", FTP_DSTATE(data));
|
||||
break;
|
||||
|
||||
case FTP_NAMEFMT:
|
||||
|
|
@ -3124,7 +3129,7 @@ static CURLcode ftp_statemachine(struct Curl_easy *data,
|
|||
}
|
||||
|
||||
ftp_state(data, FTP_STOP); /* we are done with the CONNECT phase! */
|
||||
DEBUGF(infof(data, "protocol connect phase DONE"));
|
||||
CURL_TRC_FTP(data, "[%s] protocol connect phase DONE", FTP_DSTATE(data));
|
||||
break;
|
||||
|
||||
case FTP_QUOTE:
|
||||
|
|
@ -3553,6 +3558,7 @@ static CURLcode ftp_done(struct Curl_easy *data, CURLcode status,
|
|||
/* Send any post-transfer QUOTE strings? */
|
||||
if(!status && !result && !premature && data->set.postquote)
|
||||
result = ftp_sendquote(data, conn, data->set.postquote);
|
||||
CURL_TRC_FTP(data, "[%s] done, result=%d", FTP_DSTATE(data), result);
|
||||
Curl_safefree(ftp->pathalloc);
|
||||
return result;
|
||||
}
|
||||
|
|
@ -3821,7 +3827,8 @@ static CURLcode ftp_do_more(struct Curl_easy *data, int *completep)
|
|||
if(!ftpc->wait_data_conn) {
|
||||
/* no waiting for the data connection so this is now complete */
|
||||
*completep = 1;
|
||||
DEBUGF(infof(data, "DO-MORE phase ends with %d", (int)result));
|
||||
CURL_TRC_FTP(data, "[%s] DO-MORE phase ends with %d", FTP_DSTATE(data),
|
||||
(int)result);
|
||||
}
|
||||
|
||||
return result;
|
||||
|
|
@ -3845,7 +3852,7 @@ CURLcode ftp_perform(struct Curl_easy *data,
|
|||
/* this is FTP and no proxy */
|
||||
CURLcode result = CURLE_OK;
|
||||
|
||||
DEBUGF(infof(data, "DO phase starts"));
|
||||
CURL_TRC_FTP(data, "[%s] DO phase starts", FTP_DSTATE(data));
|
||||
|
||||
if(data->req.no_body) {
|
||||
/* requested no body means no transfer... */
|
||||
|
|
@ -3865,10 +3872,15 @@ CURLcode ftp_perform(struct Curl_easy *data,
|
|||
|
||||
*connected = Curl_conn_is_connected(data->conn, SECONDARYSOCKET);
|
||||
|
||||
infof(data, "ftp_perform ends with SECONDARY: %d", *connected);
|
||||
if(*connected)
|
||||
infof(data, "[FTP] [%s] perform, DATA connection established",
|
||||
FTP_DSTATE(data));
|
||||
else
|
||||
CURL_TRC_FTP(data, "[%s] perform, awaiting DATA connect",
|
||||
FTP_DSTATE(data));
|
||||
|
||||
if(*dophase_done)
|
||||
DEBUGF(infof(data, "DO phase is complete1"));
|
||||
CURL_TRC_FTP(data, "[%s] DO phase is complete1", FTP_DSTATE(data));
|
||||
|
||||
return result;
|
||||
}
|
||||
|
|
@ -4435,11 +4447,11 @@ static CURLcode ftp_doing(struct Curl_easy *data,
|
|||
CURLcode result = ftp_multi_statemach(data, dophase_done);
|
||||
|
||||
if(result)
|
||||
DEBUGF(infof(data, "DO phase failed"));
|
||||
CURL_TRC_FTP(data, "[%s] DO phase failed", FTP_DSTATE(data));
|
||||
else if(*dophase_done) {
|
||||
result = ftp_dophase_done(data, FALSE /* not connected */);
|
||||
|
||||
DEBUGF(infof(data, "DO phase is complete2"));
|
||||
CURL_TRC_FTP(data, "[%s] DO phase is complete2", FTP_DSTATE(data));
|
||||
}
|
||||
return result;
|
||||
}
|
||||
|
|
@ -4563,6 +4575,7 @@ static CURLcode ftp_setup_connection(struct Curl_easy *data,
|
|||
ftpc->use_ssl = data->set.use_ssl;
|
||||
ftpc->ccc = data->set.ftp_ccc;
|
||||
|
||||
CURL_TRC_FTP(data, "[%s] setup connection -> %d", FTP_CSTATE(conn), result);
|
||||
return result;
|
||||
}
|
||||
|
||||
|
|
|
|||
Загрузка…
Ссылка в новой задаче