On 07/12/2013 08:06 PM, Amos Jeffries wrote:
> On 13/07/2013 2:05 a.m., Tsantilas Christos wrote:
>> This patch add new logformat codes to log TOS/DSCP values and netfilter
>> marks for client and server connections. If multiple outgoing
>> connections were used, the last used connection value logged.
>> The values printed in hexadecimal form.
>>
>> The logformat codes are:
>> %>tos Client connection tos mark set by Squid
>> %<tos Server connection tos mark set by Squid
>
> Can you call the code "qos" please? And document it exactly as you wrote
> above as "the TOS/DSCP value" removing the word "mark" from those lines
> to avoid confusion.
OK.
>
>
>> %>nfmark Client connection netfilter mark set by Squid
>> %<nfmark Server connection netfilter mark set by Squid
>>
>> I must note that the setsockopt(...,IPPROTO_IP, IP_TOS...) system call
>> we are using to set tos value may not set the configured value. It can
>> set only values which are multiple of 4. In this case we log wrong
>> value, the configured not the value is set.
>>
>> To get the real value we must modify the Ip::Qos::setSockTos method to
>> set the TOS and then read it again from socket to see which value is
>> used. However this is means one more system call to set the tos value.
>
> We should be auto-adjusting the configured value to make it a multiple
> of 4 before setting. So no set,read cycle required.
>
> Please rename these:
>
> + LFT_PEER_INCOMING_TOS,
> + LFT_PEER_OUTGOING_TOS,
> + LFT_PEER_INCOMING_NFMARK,
> + LFT_PEER_OUTGOING_NFMARK,
>
> We already have the naming scheme LFT_CLIENT_LOCAL_* and
> LFT_SERVER_LOCAL_* for the relevant TCP connections local-end details
> (ie. "set by Squid").
Done. it is match better now...
>
> Although I am not certain what you are calling the Client connection
> details set by Squid are in fact set by Squid and not the received ones
> set by the client. Please check that. If so the LFT_CLIENT_LOCAL_ part
> of the naming scheme should be LFT_CLIENT_*
Yes the values set by squid, not by client or web server.
The LFT_CLIENT_LOCAL and LFT_SERVER_LOCAL_ looks good options.
>
> Amos
>
Log TOS and Netfilter marks set by Squid
This patch add new logformat codes to log TOS/DSCP values and netfilter marks
for client and server connections. If multiple outgoing connections were used,
the last used connection value logged.
The values printed in hexadecimal form.
The logformat codes are:
%>qos Client connection TOS/DSCP value set by Squid
%<qos Server connection TOS/DSCP value set by Squid
%>nfmark Client connection netfilter mark set by Squid
%<nfmark Server connection netfilter mark set by Squid
This patch also modify qos related code to set Comm::Connection::nfmark and
Comm::Connection::tos members in Ip::Qos::setSockNfmark and Ip::Qos::setSockTos
methods. The Comm::Connection members are now set only if the tos and nfmark
set successfuly.
This is a Measurement Factory project
=== modified file 'src/FwdState.cc'
--- src/FwdState.cc 2013-06-18 22:30:39 +0000
+++ src/FwdState.cc 2013-07-15 07:14:08 +0000
@@ -1147,47 +1147,47 @@
// Avoid pconns after races so that the same client does not suffer twice.
// This does not increase the total number of connections because we just
// closed the connection that failed the race. And re-pinning assumes this.
if (pconnRace != raceHappened)
temp = fwdPconnPool->pop(serverDestinations[0], host, checkRetriable());
const bool openedPconn = Comm::IsConnOpen(temp);
pconnRace = openedPconn ? racePossible : raceImpossible;
// if we found an open persistent connection to use. use it.
if (openedPconn) {
serverConn = temp;
flags.connected_okay = true;
debugs(17, 3, HERE << "reusing pconn " << serverConnection());
++n_tries;
comm_add_close_handler(serverConnection()->fd, fwdServerClosedWrapper, this);
/* Update server side TOS and Netfilter mark on the connection. */
if (Ip::Qos::TheConfig.isAclTosActive()) {
- temp->tos = GetTosToServer(request);
- Ip::Qos::setSockTos(temp, temp->tos);
+ const tos_t tos = GetTosToServer(request);
+ Ip::Qos::setSockTos(temp, tos);
}
#if SO_MARK
if (Ip::Qos::TheConfig.isAclNfmarkActive()) {
- temp->nfmark = GetNfmarkToServer(request);
- Ip::Qos::setSockNfmark(temp, temp->nfmark);
+ const nfmark_t nfmark = GetNfmarkToServer(request);
+ Ip::Qos::setSockNfmark(temp, nfmark);
}
#endif
dispatch();
return;
}
// We will try to open a new connection, possibly to the same destination.
// We reset serverDestinations[0] in case we are using it again because
// ConnOpener modifies its destination argument.
serverDestinations[0]->local.port(0);
serverConn = NULL;
#if URL_CHECKSUM_DEBUG
entry->mem_obj->checkUrlChecksum();
#endif
/* Get the server side TOS and Netfilter mark to be set on the connection. */
if (Ip::Qos::TheConfig.isAclTosActive()) {
serverDestinations[0]->tos = GetTosToServer(request);
=== modified file 'src/cf.data.pre'
--- src/cf.data.pre 2013-06-18 06:22:13 +0000
+++ src/cf.data.pre 2013-07-15 07:18:27 +0000
@@ -3670,40 +3670,44 @@
adaptation_meta configuration parameter.
If no argument given all meta headers logged.
Connection related format codes:
>a Client source IP address
>A Client FQDN
>p Client source port
>eui Client source EUI (MAC address, EUI-48 or EUI-64 identifier)
>la Local IP address the client connected to
>lp Local port number the client connected to
la Local listening IP address the client connection was connected to.
lp Local listening port number the client connection was connected to.
<a Server IP address of the last server or peer connection
<A Server FQDN or peer name
<p Server port number of the last server or peer connection
<la Local IP address of the last server or peer connection
<lp Local port number of the last server or peer connection
+ >qos Client connection TOS/DSCP value set by Squid
+ <qos Server connection TOS/DSCP value set by Squid
+ >nfmark Client connection netfilter mark set by Squid
+ <nfmark Server connection netfilter mark set by Squid
Time related format codes:
ts Seconds since epoch
tu subsecond time (milliseconds)
tl Local time. Optional strftime format argument
default %d/%b/%Y:%H:%M:%S %z
tg GMT time. Optional strftime format argument
default %d/%b/%Y:%H:%M:%S %z
tr Response time (milliseconds)
dt Total time spent making DNS lookups (milliseconds)
Access Control related format codes:
et Tag returned by external acl
ea Log string returned by external acl
un User name (any available)
ul User name from authentication
ue User name from external acl helper
ui User name from ident
=== modified file 'src/comm/Connection.cc'
--- src/comm/Connection.cc 2013-05-05 01:19:46 +0000
+++ src/comm/Connection.cc 2013-07-15 07:14:08 +0000
@@ -30,40 +30,41 @@
Comm::Connection::~Connection()
{
if (fd >= 0) {
debugs(5, 4, "BUG #3329: Orphan Comm::Connection: " << *this);
debugs(5, 4, "NOTE: " << ++lost_conn << " Orphans since last started.");
close();
}
cbdataReferenceDone(peer_);
}
Comm::ConnectionPointer
Comm::Connection::copyDetails() const
{
ConnectionPointer c = new Comm::Connection;
c->local = local;
c->remote = remote;
c->peerType = peerType;
c->tos = tos;
+ c->nfmark = nfmark;
c->flags = flags;
// ensure FD is not open in the new copy.
c->fd = -1;
// ensure we have a cbdata reference to peer_ not a straight ptr copy.
c->peer_ = cbdataReference(getPeer());
return c;
}
void
Comm::Connection::close()
{
if (isOpen()) {
comm_close(fd);
fd = -1;
if (CachePeer *p=getPeer())
-- p->stats.conn_open;
}
=== modified file 'src/format/ByteCode.h'
--- src/format/ByteCode.h 2013-02-11 23:11:12 +0000
+++ src/format/ByteCode.h 2013-07-15 07:26:42 +0000
@@ -180,35 +180,39 @@
LFT_ICAP_REQ_HEADER_ELEM,
LFT_ICAP_REQ_ALL_HEADERS,
LFT_ICAP_REP_HEADER,
LFT_ICAP_REP_HEADER_ELEM,
LFT_ICAP_REP_ALL_HEADERS,
LFT_ICAP_TR_RESPONSE_TIME,
LFT_ICAP_IO_TIME,
LFT_ICAP_OUTCOME,
LFT_ICAP_STATUS_CODE,
#endif
#if USE_SSL
LFT_SSL_BUMP_MODE,
LFT_SSL_USER_CERT_SUBJECT,
LFT_SSL_USER_CERT_ISSUER,
#endif
LFT_NOTE,
+ LFT_CLIENT_LOCAL_TOS,
+ LFT_SERVER_LOCAL_TOS,
+ LFT_CLIENT_LOCAL_NFMARK,
+ LFT_SERVER_LOCAL_NFMARK,
LFT_PERCENT /* special string cases for escaped chars */
} ByteCode_t;
/// Quoting style for a format output.
enum Quoting {
LOG_QUOTE_NONE = 0,
LOG_QUOTE_QUOTES,
LOG_QUOTE_MIMEBLOB,
LOG_QUOTE_URL,
LOG_QUOTE_RAW
};
} // namespace Format
#endif /* _SQUID_FMT_BYTECODE_H */
=== modified file 'src/format/Format.cc'
--- src/format/Format.cc 2013-06-11 09:25:07 +0000
+++ src/format/Format.cc 2013-07-15 07:28:57 +0000
@@ -1029,40 +1029,69 @@
}
case LFT_SSL_USER_CERT_SUBJECT:
if (X509 *cert = al->cache.sslClientCert.get()) {
if (X509_NAME *subject = X509_get_subject_name(cert)) {
X509_NAME_oneline(subject, tmp, sizeof(tmp));
out = tmp;
}
}
break;
case LFT_SSL_USER_CERT_ISSUER:
if (X509 *cert = al->cache.sslClientCert.get()) {
if (X509_NAME *issuer = X509_get_issuer_name(cert)) {
X509_NAME_oneline(issuer, tmp, sizeof(tmp));
out = tmp;
}
}
break;
#endif
+
+ case LFT_CLIENT_LOCAL_TOS:
+ if (al->tcpClient != NULL) {
+ snprintf(tmp, sizeof(tmp), "0x%x", (uint32_t)al->tcpClient->tos);
+ out = tmp;
+ }
+ break;
+
+ case LFT_SERVER_LOCAL_TOS:
+ if (al->hier.tcpServer != NULL) {
+ snprintf(tmp, sizeof(tmp), "0x%x", (uint32_t)al->hier.tcpServer->tos);
+ out = tmp;
+ }
+ break;
+
+ case LFT_CLIENT_LOCAL_NFMARK:
+ if (al->tcpClient != NULL) {
+ snprintf(tmp, sizeof(tmp), "0x%x", al->tcpClient->nfmark);
+ out = tmp;
+ }
+ break;
+
+ case LFT_SERVER_LOCAL_NFMARK:
+ if (al->hier.tcpServer != NULL) {
+ snprintf(tmp, sizeof(tmp), "0x%x", al->hier.tcpServer->nfmark);
+ out = tmp;
+ }
+ break;
+
case LFT_NOTE:
if (fmt->data.string) {
#if USE_ADAPTATION
Adaptation::History::Pointer ah = al->request ? al->request->adaptHistory() : Adaptation::History::Pointer();
if (ah != NULL && ah->metaHeaders != NULL) {
if (const char *meta = ah->metaHeaders->find(fmt->data.string))
sb.append(meta);
}
#endif
if (al->notes != NULL) {
if (const char *note = al->notes->find(fmt->data.string)) {
if (sb.size())
sb.append(", ");
sb.append(note);
}
}
out = sb.termedBuf();
quote = 1;
} else {
#if USE_ADAPTATION
=== modified file 'src/format/Token.cc'
--- src/format/Token.cc 2013-05-22 01:04:34 +0000
+++ src/format/Token.cc 2013-07-15 07:28:12 +0000
@@ -29,41 +29,40 @@
{">v", LFT_REQUEST_VERSION_OLD_2X},
{"%", LFT_PERCENT},
{NULL, LFT_NONE} /* this must be last */
};
/// 2-char tokens
static TokenTableEntry TokenTable2C[] = {
{">la", LFT_CLIENT_LOCAL_IP},
{"la", LFT_LOCAL_LISTENING_IP},
{">lp", LFT_CLIENT_LOCAL_PORT},
{"lp", LFT_LOCAL_LISTENING_PORT},
/*{ "lA", LFT_LOCAL_NAME }, */
{"<la", LFT_SERVER_LOCAL_IP},
{"oa", LFT_SERVER_LOCAL_IP_OLD_27},
{"<lp", LFT_SERVER_LOCAL_PORT},
- /* {"ot", LFT_PEER_OUTGOING_TOS}, */
{"ts", LFT_TIME_SECONDS_SINCE_EPOCH},
{"tu", LFT_TIME_SUBSECOND},
{"tl", LFT_TIME_LOCALTIME},
{"tg", LFT_TIME_GMT},
{"tr", LFT_TIME_TO_HANDLE_REQUEST},
{"<pt", LFT_PEER_RESPONSE_TIME},
{"<tt", LFT_TOTAL_SERVER_SIDE_RESPONSE_TIME},
{"dt", LFT_DNS_WAIT_TIME},
{">ha", LFT_ADAPTED_REQUEST_HEADER},
{">ha", LFT_ADAPTED_REQUEST_ALL_HEADERS},
{"un", LFT_USER_NAME},
{"ul", LFT_USER_LOGIN},
/*{ "ur", LFT_USER_REALM }, */
/*{ "us", LFT_USER_SCHEME }, */
{"ui", LFT_USER_IDENT},
{"ue", LFT_USER_EXTERNAL},
@@ -105,40 +104,44 @@
{"<st", LFT_REPLY_SIZE_TOTAL},
{"<sH", LFT_REPLY_HIGHOFFSET},
{"<sS", LFT_REPLY_OBJECTSIZE},
/*{ "<sl", LFT_REPLY_SIZE_LINE }, * / / * the reply line (protocol, code, text) */
{"<sh", LFT_REPLY_SIZE_HEADERS },
/*{ "<sb", LFT_REPLY_SIZE_BODY }, */
/*{ "<sB", LFT_REPLY_SIZE_BODY_NO_TE }, */
{"et", LFT_TAG},
{"st", LFT_IO_SIZE_TOTAL},
{"ea", LFT_EXT_LOG},
{"sn", LFT_SEQUENCE_NUMBER},
{NULL, LFT_NONE} /* this must be last */
};
/// Miscellaneous >2 byte tokens
static TokenTableEntry TokenTableMisc[] = {
{">eui", LFT_CLIENT_EUI},
+ {">qos", LFT_CLIENT_LOCAL_TOS},
+ {"<qos", LFT_SERVER_LOCAL_TOS},
+ {">nfmark", LFT_CLIENT_LOCAL_NFMARK},
+ {"<nfmark", LFT_SERVER_LOCAL_NFMARK},
{"err_code", LFT_SQUID_ERROR },
{"err_detail", LFT_SQUID_ERROR_DETAIL },
{"note", LFT_NOTE },
{NULL, LFT_NONE} /* this must be last */
};
#if USE_ADAPTATION
static TokenTableEntry TokenTableAdapt[] = {
{"all_trs", LFT_ADAPTATION_ALL_XACT_TIMES},
{"sum_trs", LFT_ADAPTATION_SUM_XACT_TIMES},
{"<last_h", LFT_ADAPTATION_LAST_HEADER},
{NULL, LFT_NONE} /* this must be last */
};
#endif
#if ICAP_CLIENT
/// ICAP (icap::) tokens
static TokenTableEntry TokenTableIcap[] = {
{"tt", LFT_ICAP_TOTAL_TIME},
{"<last_h", LFT_ADAPTATION_LAST_HEADER}, // deprecated
=== modified file 'src/ip/Qos.cci'
--- src/ip/Qos.cci 2013-01-08 23:51:02 +0000
+++ src/ip/Qos.cci 2013-07-15 07:14:08 +0000
@@ -1,50 +1,54 @@
/* Inline QOS functions */
#include "comm/Connection.h"
#include "Debug.h"
int
Ip::Qos::setSockTos(const Comm::ConnectionPointer &conn, tos_t tos)
{
#if defined(IP_TOS)
// Bug 3731: FreeBSD produces 'invalid option'
// unless we pass it a 32-bit variable storing 8-bits of data.
// NP: it is documented as 'int' for all systems, even those like Linux which accept 8-bit char
// so we convert to a int before setting.
int bTos = tos;
int x = setsockopt(conn->fd, IPPROTO_IP, IP_TOS, &bTos, sizeof(bTos));
if (x < 0)
debugs(50, 2, "Ip::Qos::setSockTos: setsockopt(IP_TOS) on " << conn << ": " << xstrerror());
+ else
+ conn->tos = tos;
return x;
#else
debugs(50, DBG_IMPORTANT, "WARNING: setsockopt(IP_TOS) not supported on this platform");
return -1;
#endif
}
int
Ip::Qos::setSockNfmark(const Comm::ConnectionPointer &conn, nfmark_t mark)
{
#if SO_MARK && USE_LIBCAP
int x = setsockopt(conn->fd, SOL_SOCKET, SO_MARK, &mark, sizeof(nfmark_t));
if (x < 0)
debugs(50, 2, "setSockNfmark: setsockopt(SO_MARK) on " << conn << ": " << xstrerror());
+ else
+ conn->nfmark = mark;
return x;
#elif USE_LIBCAP
debugs(50, DBG_IMPORTANT, "WARNING: setsockopt(SO_MARK) not supported on this platform");
return -1;
#else
debugs(50, DBG_IMPORTANT, "WARNING: Netfilter marking disabled (netfilter marking requires build with LIBCAP)");
return -1;
#endif
}
bool
Ip::Qos::Config::isHitTosActive() const
{
return (tosLocalHit || tosSiblingHit || tosParentHit || tosMiss || preserveMissTos);
}
bool
Ip::Qos::Config::isHitNfmarkActive() const
{
return (markLocalHit || markSiblingHit || markParentHit || markMiss || preserveMissMark);
