]> git.ipfire.org Git - thirdparty/squid.git/blobdiff - src/client_side.cc
Fix logged request size (%http::>st) and other size-related %codes.
[thirdparty/squid.git] / src / client_side.cc
index 74ca44c8559dff6ef53265397ea99de50721b47c..772bad9f9a995295c69f61505a1055b75ea55e36 100644 (file)
@@ -362,8 +362,6 @@ prepareLogWithRequestDetails(HttpRequest * request, AccessLogEntry::Pointer &aLo
     aLogEntry->http.method = request->method;
     aLogEntry->http.version = request->http_ver;
     aLogEntry->hier = request->hier;
-    if (request->content_length > 0) // negative when no body or unknown length
-        aLogEntry->http.clientRequestSz.payloadData += request->content_length; // XXX: actually adaptedRequest payload size ??
     aLogEntry->cache.extuser = request->extacl_user.termedBuf();
 
     // Adapted request, if any, inherits and then collects all the stats, but
@@ -400,6 +398,9 @@ ClientHttpRequest::logRequest()
         al->cache.objectSize = loggingEntry()->contentLen(); // payload duplicate ?? with or without TE ?
 
     al->http.clientRequestSz.header = req_sz;
+    // the virgin request is saved to al->request
+    if (al->request && al->request->body_pipe)
+        al->http.clientRequestSz.payloadData = al->request->body_pipe->producedSize();
     al->http.clientReplySz.header = out.headers_sz;
     // XXX: calculate without payload encoding or headers !!
     al->http.clientReplySz.payloadData = out.size - out.headers_sz; // pretend its all un-encoded data for now.
@@ -584,8 +585,9 @@ void
 ConnStateData::swanSong()
 {
     debugs(33, 2, HERE << clientConnection);
+    checkLogging();
+
     flags.readMore = false;
-    DeregisterRunner(this);
     clientdbEstablished(clientConnection->remote, -1);  /* decrement */
     pipeline.terminateAll(0);
 
@@ -1041,10 +1043,6 @@ ConnStateData::endingShutdown()
     // swanSong() in the close handler will cleanup.
     if (Comm::IsConnOpen(clientConnection))
         clientConnection->close();
-
-    // deregister now to ensure finalShutdown() does not kill us prematurely.
-    // fd_table purge will cleanup if close handler was not fast enough.
-    DeregisterRunner(this);
 }
 
 char *
@@ -1219,7 +1217,8 @@ prepareAcceleratedURL(ConnStateData * conn, ClientHttpRequest *http, const Http1
         } // else nothing to alter port-wise.
         const int url_sz = hp->requestUri().length() + 32 + Config.appendDomainLen + strlen(host);
         http->uri = (char *)xcalloc(url_sz, 1);
-        snprintf(http->uri, url_sz, "%s://%s" SQUIDSBUFPH, AnyP::UriScheme(conn->transferProtocol.protocol).c_str(), host, SQUIDSBUFPRINT(url));
+        const SBuf &scheme = AnyP::UriScheme(conn->transferProtocol.protocol).image();
+        snprintf(http->uri, url_sz, SQUIDSBUFPH "://%s" SQUIDSBUFPH, SQUIDSBUFPRINT(scheme), host, SQUIDSBUFPRINT(url));
         debugs(33, 5, "ACCEL VHOST REWRITE: " << http->uri);
     } else if (conn->port->defaultsite /* && !vhost */) {
         debugs(33, 5, "ACCEL DEFAULTSITE REWRITE: defaultsite=" << conn->port->defaultsite << " + vport=" << vport);
@@ -1231,8 +1230,9 @@ prepareAcceleratedURL(ConnStateData * conn, ClientHttpRequest *http, const Http1
         if (vport > 0) {
             snprintf(vportStr, sizeof(vportStr),":%d",vport);
         }
-        snprintf(http->uri, url_sz, "%s://%s%s" SQUIDSBUFPH,
-                 AnyP::UriScheme(conn->transferProtocol.protocol).c_str(), conn->port->defaultsite, vportStr, SQUIDSBUFPRINT(url));
+        const SBuf &scheme = AnyP::UriScheme(conn->transferProtocol.protocol).image();
+        snprintf(http->uri, url_sz, SQUIDSBUFPH "://%s%s" SQUIDSBUFPH,
+                 SQUIDSBUFPRINT(scheme), conn->port->defaultsite, vportStr, SQUIDSBUFPRINT(url));
         debugs(33, 5, "ACCEL DEFAULTSITE REWRITE: " << http->uri);
     } else if (vport > 0 /* && (!vhost || no Host:) */) {
         debugs(33, 5, "ACCEL VPORT REWRITE: *_port IP + vport=" << vport);
@@ -1240,9 +1240,9 @@ prepareAcceleratedURL(ConnStateData * conn, ClientHttpRequest *http, const Http1
         const int url_sz = hp->requestUri().length() + 32 + Config.appendDomainLen;
         http->uri = (char *)xcalloc(url_sz, 1);
         http->getConn()->clientConnection->local.toHostStr(ipbuf,MAX_IPSTRLEN);
-        snprintf(http->uri, url_sz, "%s://%s:%d" SQUIDSBUFPH,
-                 AnyP::UriScheme(conn->transferProtocol.protocol).c_str(),
-                 ipbuf, vport, SQUIDSBUFPRINT(url));
+        const SBuf &scheme = AnyP::UriScheme(conn->transferProtocol.protocol).image();
+        snprintf(http->uri, url_sz, SQUIDSBUFPH "://%s:%d" SQUIDSBUFPH,
+                 SQUIDSBUFPRINT(scheme), ipbuf, vport, SQUIDSBUFPRINT(url));
         debugs(33, 5, "ACCEL VPORT REWRITE: " << http->uri);
     }
 }
@@ -1260,8 +1260,9 @@ prepareTransparentURL(ConnStateData * conn, ClientHttpRequest *http, const Http1
         const int url_sz = hp->requestUri().length() + 32 + Config.appendDomainLen +
                            strlen(host);
         http->uri = (char *)xcalloc(url_sz, 1);
-        snprintf(http->uri, url_sz, "%s://%s" SQUIDSBUFPH,
-                 AnyP::UriScheme(conn->transferProtocol.protocol).c_str(), host, SQUIDSBUFPRINT(hp->requestUri()));
+        const SBuf &scheme = AnyP::UriScheme(conn->transferProtocol.protocol).image();
+        snprintf(http->uri, url_sz, SQUIDSBUFPH "://%s" SQUIDSBUFPH,
+                 SQUIDSBUFPRINT(scheme), host, SQUIDSBUFPRINT(hp->requestUri()));
         debugs(33, 5, "TRANSPARENT HOST REWRITE: " << http->uri);
     } else {
         /* Put the local socket IP address as the hostname.  */
@@ -1269,8 +1270,9 @@ prepareTransparentURL(ConnStateData * conn, ClientHttpRequest *http, const Http1
         http->uri = (char *)xcalloc(url_sz, 1);
         static char ipbuf[MAX_IPSTRLEN];
         http->getConn()->clientConnection->local.toHostStr(ipbuf,MAX_IPSTRLEN);
-        snprintf(http->uri, url_sz, "%s://%s:%d" SQUIDSBUFPH,
-                 AnyP::UriScheme(http->getConn()->transferProtocol.protocol).c_str(),
+        const SBuf &scheme = AnyP::UriScheme(http->getConn()->transferProtocol.protocol).image();
+        snprintf(http->uri, url_sz, SQUIDSBUFPH "://%s:%d" SQUIDSBUFPH,
+                 SQUIDSBUFPRINT(scheme),
                  ipbuf, http->getConn()->clientConnection->local.port(), SQUIDSBUFPRINT(hp->requestUri()));
         debugs(33, 5, "TRANSPARENT REWRITE: " << http->uri);
     }
@@ -1307,10 +1309,14 @@ parseHttpRequest(ConnStateData *csd, const Http1::RequestParserPointer &hp)
         }
 
         if (!parsedOk) {
-            if (hp->parseStatusCode == Http::scRequestHeaderFieldsTooLarge || hp->parseStatusCode == Http::scUriTooLong)
-                return csd->abortRequestParsing("error:request-too-large");
-
-            return csd->abortRequestParsing("error:invalid-request");
+            const bool tooBig =
+                hp->parseStatusCode == Http::scRequestHeaderFieldsTooLarge ||
+                hp->parseStatusCode == Http::scUriTooLong;
+            auto result = csd->abortRequestParsing(
+                              tooBig ? "error:request-too-large" : "error:invalid-request");
+            // assume that remaining leftovers belong to this bad request
+            csd->consumeInput(csd->inBuf.length());
+            return result;
         }
     }
 
@@ -1503,16 +1509,16 @@ bool ConnStateData::serveDelayedError(Http::Stream *context)
     // In bump-server-first mode, we have not necessarily seen the intended
     // server name at certificate-peeking time. Check for domain mismatch now,
     // when we can extract the intended name from the bumped HTTP request.
-    if (X509 *srvCert = sslServerBump->serverCert.get()) {
+    if (const Security::CertPointer &srvCert = sslServerBump->serverCert) {
         HttpRequest *request = http->request;
-        if (!Ssl::checkX509ServerValidity(srvCert, request->url.host())) {
+        if (!Ssl::checkX509ServerValidity(srvCert.get(), request->url.host())) {
             debugs(33, 2, "SQUID_X509_V_ERR_DOMAIN_MISMATCH: Certificate " <<
                    "does not match domainname " << request->url.host());
 
             bool allowDomainMismatch = false;
             if (Config.ssl_client.cert_error) {
                 ACLFilledChecklist check(Config.ssl_client.cert_error, request, dash_str);
-                check.sslErrors = new Ssl::CertErrors(Ssl::CertError(SQUID_X509_V_ERR_DOMAIN_MISMATCH, srvCert));
+                check.sslErrors = new Security::CertErrors(Security::CertError(SQUID_X509_V_ERR_DOMAIN_MISMATCH, srvCert));
                 allowDomainMismatch = (check.fastCheck() == ACCESS_ALLOWED);
                 delete check.sslErrors;
                 check.sslErrors = NULL;
@@ -1534,7 +1540,7 @@ bool ConnStateData::serveDelayedError(Http::Stream *context)
                 err->src_addr = clientConnection->remote;
                 Ssl::ErrorDetail *errDetail = new Ssl::ErrorDetail(
                     SQUID_X509_V_ERR_DOMAIN_MISMATCH,
-                    srvCert, NULL);
+                    srvCert.get(), nullptr);
                 err->detail = errDetail;
                 // Save the original request for logging purposes.
                 if (!context->http->al->request) {
@@ -1677,7 +1683,7 @@ clientProcessRequest(ConnStateData *conn, const Http1::RequestParserPointer &hp,
             http->flags.internal = true;
         } else if (Config.onoff.global_internal_static && internalStaticCheck(request->url.path())) {
             debugs(33, 2, "internal URL found: " << request->url.getScheme() << "://" << request->url.authority(true) << " (global_internal_static on)");
-            request->url.setScheme(AnyP::PROTO_HTTP);
+            request->url.setScheme(AnyP::PROTO_HTTP, "http");
             request->url.host(internalHostname());
             request->url.port(getMyPort());
             http->flags.internal = true;
@@ -2141,10 +2147,6 @@ ConnStateData::clientParseRequests()
     // On errors, bodyPipe may become nil, but readMore will be cleared
     while (!inBuf.isEmpty() && !bodyPipe && flags.readMore) {
 
-        /* Don't try to parse if the buffer is empty */
-        if (inBuf.isEmpty())
-            break;
-
         /* Limit the number of concurrent requests */
         if (concurrentRequestQueueFilled())
             break;
@@ -2447,7 +2449,7 @@ ConnStateData::ConnStateData(const MasterXaction::Pointer &xact) :
 
     // register to receive notice of Squid signal events
     // which may affect long persisting client connections
-    RegisterRunner(this);
+    registerRunner();
 }
 
 void
@@ -2570,23 +2572,23 @@ httpAccept(const CommAcceptCbParams &params)
     ++incoming_sockets_accepted;
 
     // Socket is ready, setup the connection manager to start using it
-    ConnStateData *connState = Http::NewServer(xact);
-    AsyncJob::Start(connState); // usually async-calls readSomeData()
+    auto *srv = Http::NewServer(xact);
+    AsyncJob::Start(srv); // usually async-calls readSomeData()
 }
 
 #if USE_OPENSSL
 
 /** Create SSL connection structure and update fd_table */
-static Security::SessionPtr
+static bool
 httpsCreate(const Comm::ConnectionPointer &conn, Security::ContextPtr sslContext)
 {
-    if (auto ssl = Ssl::CreateServer(sslContext, conn->fd, "client https start")) {
+    if (Ssl::CreateServer(sslContext, conn, "client https start")) {
         debugs(33, 5, "will negotate SSL on " << conn);
-        return ssl;
+        return true;
     }
 
     conn->close();
-    return nullptr;
+    return false;
 }
 
 /**
@@ -2657,7 +2659,7 @@ clientNegotiateSSL(int fd, void *data)
         return;
     }
 
-    if (SSL_session_reused(ssl)) {
+    if (Security::SessionIsResumed(fd_table[fd].ssl)) {
         debugs(83, 2, "clientNegotiateSSL: Session " << SSL_get_session(ssl) <<
                " reused on FD " << fd << " (" << fd_table[fd].ipaddr << ":" << (int)fd_table[fd].remote_port << ")");
     } else {
@@ -2732,11 +2734,10 @@ clientNegotiateSSL(int fd, void *data)
 static void
 httpsEstablish(ConnStateData *connState, Security::ContextPtr sslContext)
 {
-    Security::SessionPtr ssl = nullptr;
     assert(connState);
     const Comm::ConnectionPointer &details = connState->clientConnection;
 
-    if (!sslContext || !(ssl = httpsCreate(details, sslContext)))
+    if (!sslContext || !httpsCreate(details, sslContext))
         return;
 
     typedef CommCbMemFunT<ConnStateData, CommTimeoutCbParams> TimeoutDialer;
@@ -2798,8 +2799,8 @@ httpsAccept(const CommAcceptCbParams &params)
     ++incoming_sockets_accepted;
 
     // Socket is ready, setup the connection manager to start using it
-    ConnStateData *connState = Https::NewServer(xact);
-    AsyncJob::Start(connState); // usually async-calls postHttpsAccept()
+    auto *srv = Https::NewServer(xact);
+    AsyncJob::Start(srv); // usually async-calls postHttpsAccept()
 }
 
 void
@@ -2980,10 +2981,14 @@ void ConnStateData::buildSslCertGenerationParams(Ssl::CertificateProperties &cer
 void
 ConnStateData::getSslContextStart()
 {
-    // XXX starting SSL with a pipeline of requests still waiting for non-SSL replies?
-    assert(pipeline.count() < 2); // the CONNECT is okay for now. Anything else is a bug.
-    pipeline.terminateAll(0);
-    /* careful: terminateAll(0) above frees request, host, etc. */
+    // If we are called, then CONNECT has succeeded. Finalize it.
+    if (auto xact = pipeline.front()) {
+        if (xact->http && xact->http->request && xact->http->request->method == Http::METHOD_CONNECT)
+            xact->finished();
+        // cannot proceed with encryption if requests wait for plain responses
+        Must(pipeline.empty());
+    }
+    /* careful: finished() above frees request, host, etc. */
 
     if (port->generateHostCertificates) {
         Ssl::CertificateProperties certProperties;
@@ -3448,7 +3453,7 @@ static void
 clientHttpConnectionsOpen(void)
 {
     for (AnyP::PortCfgPointer s = HttpPortList; s != NULL; s = s->next) {
-        const char *scheme = AnyP::UriScheme(s->transport.protocol).c_str();
+        const SBuf &scheme = AnyP::UriScheme(s->transport.protocol).image();
 
         if (MAXTCPLISTENPORTS == NHttpSockets) {
             debugs(1, DBG_IMPORTANT, "WARNING: You have too many '" << scheme << "_port' lines.");
@@ -4031,3 +4036,36 @@ ConnStateData::unpinConnection(const bool andClose)
      * connection has gone away */
 }
 
+void
+ConnStateData::checkLogging()
+{
+    // if we are parsing request body, its request is responsible for logging
+    if (bodyPipe)
+        return;
+
+    // a request currently using this connection is responsible for logging
+    if (!pipeline.empty() && pipeline.back()->mayUseConnection())
+        return;
+
+    /* Either we are waiting for the very first transaction, or
+     * we are done with the Nth transaction and are waiting for N+1st.
+     * XXX: We assume that if anything was added to inBuf, then it could
+     * only be consumed by actions already covered by the above checks.
+     */
+
+    // do not log connections that closed after a transaction (it is normal)
+    // TODO: access_log needs ACLs to match received-no-bytes connections
+    // XXX: TLS may return here even though we got no transactions yet
+    // XXX: PROXY protocol may return here even though we got no
+    // transactions yet
+    if (receivedFirstByte_ && inBuf.isEmpty())
+        return;
+
+    /* Create a temporary ClientHttpRequest object. Its destructor will log. */
+    ClientHttpRequest http(this);
+    http.req_sz = inBuf.length();
+    char const *uri = "error:transaction-end-before-headers";
+    http.uri = xstrdup(uri);
+    setLogUri(&http, uri);
+}
+