reapply: location-header: tweak location header handling

- Fix potentially sending the location header into PSOL twice.
- Be more thorough when unsetting the location header

Attempts to fix #725

from oschaaf

config

@@ -29,8 +29,8 @@ if [ "$mod_pagespeed_dir" = "unset" ] ; then
     echo "   You need to separately download the pagespeed library:"
     echo ""
     echo "     $ cd /path/to/ngx_pagespeed"
-    echo "     $ wget https://dl.google.com/dl/page-speed/psol/1.9.32.1.tar.gz"
-    echo "     $ tar -xzvf 1.9.32.1.tar.gz # expands to psol/"
+    echo "     $ wget https://dl.google.com/dl/page-speed/psol/1.10.33.3.tar.gz"
+    echo "     $ tar -xzvf 1.10.33.3.tar.gz # expands to psol/"
     echo ""
     echo "   Or see the installation instructions:"
     echo "     https://github.com/pagespeed/ngx_pagespeed#how-to-build"

src/ngx_base_fetch.cc

@@ -118,6 +118,8 @@ const char* BaseFetchTypeToCStr(NgxBaseFetchType type) {
   return "can't get here";
 }
 
+// TODO(oschaaf): replace the ngx_log_error with VLOGS or pass in a
+// MessageHandler and use that.
 void NgxBaseFetch::ReadCallback(const ps_event_data& data) {
   NgxBaseFetch* base_fetch = reinterpret_cast<NgxBaseFetch*>(data.sender);
   ngx_http_request_t* r = base_fetch->request();
@@ -138,19 +140,40 @@ void NgxBaseFetch::ReadCallback(const ps_event_data& data) {
   if (refcount == 0 || detached) {
     return;
   }
+
   ps_request_ctx_t* ctx = ps_get_request_context(r);
 
-  CHECK(data.sender == ctx->base_fetch);
-  CHECK(r->count > 0) << "r->count: " << r->count;
+  // If our request context was zeroed, skip this event.
+  // See https://github.com/pagespeed/ngx_pagespeed/issues/1081
+  if (ctx == NULL) {
+    // Should not happen normally, when it does this message will cause our
+    // system tests to fail.
+    ngx_log_error(NGX_LOG_WARN, ngx_cycle->log, 0,
+        "pagespeed [%p] skipping event: request context gone", r);
+    return;
+  }
+
+  // Normally we expect the sender to equal the active NgxBaseFetch instance.
+  DCHECK(data.sender == ctx->base_fetch);
+
+  // If someone changed our request context or NgxBaseFetch, skip processing.
+  if (data.sender != ctx->base_fetch) {
+      ngx_log_error(NGX_LOG_WARN, ngx_cycle->log, 0,
+          "pagespeed [%p] skipping event: event originating from disassociated"
+          " NgxBaseFetch instance.", r);
+      return;
+  }
 
   int rc;
+  bool run_posted = true;
   // If we are unlucky enough to have our connection finalized mid-ipro-lookup,
   // we must enter a different flow. Also see ps_in_place_check_header_filter().
   if ((ctx->base_fetch->base_fetch_type_ != kIproLookup)
       && r->connection->error) {
     ngx_log_error(NGX_LOG_DEBUG, ngx_cycle->log, 0,
-      "pagespeed [%p] request already finalized", r);
+      "pagespeed [%p] request already finalized %d", r, r->count);
     rc = NGX_ERROR;
+    run_posted = false;
   } else {
     rc = ps_base_fetch::ps_base_fetch_handler(r);
   }
@@ -163,8 +186,11 @@ void NgxBaseFetch::ReadCallback(const ps_event_data& data) {
 
   ngx_connection_t* c = r->connection;
   ngx_http_finalize_request(r, rc);
+
+  if (run_posted) {
     // See http://forum.nginx.org/read.php?2,253006,253061
     ngx_http_run_posted_requests(c);
+  }
 }
 
 void NgxBaseFetch::Lock() {

src/ngx_pagespeed.cc

@@ -284,7 +284,8 @@ ngx_int_t ps_base_fetch_handler(ngx_http_request_t* r) {
     // modules running after us to manipulate those responses.
     if (!status_ok && (ctx->base_fetch->base_fetch_type() != kHtmlTransform
                        && ctx->base_fetch->base_fetch_type() != kIproLookup)) {
-      return status_code;
+      ps_release_base_fetch(ctx);
+      return ngx_http_filter_finalize_request(r, NULL, status_code);
     }
 
     if (ctx->preserve_caching_headers != kDontPreserveHeaders) {
@@ -302,6 +303,12 @@ ngx_int_t ps_base_fetch_handler(ngx_http_request_t* r) {
                 STR_CASE_EQ_LITERAL(header->key, "Last-Modified") ||
                 STR_CASE_EQ_LITERAL(header->key, "Expires"))))) {
           header->hash = 0;
+          if (STR_CASE_EQ_LITERAL(header->key, "Location")) {
+            // There's a possible issue with the location header, where setting
+            // the hash to 0 is not enough. See:
+            // https://github.com/nginx/nginx/blob/master/src/http/ngx_http_header_filter_module.c#L314
+            r->headers_out.location = NULL;
+          }
         }
       }
     } else {
@@ -452,11 +459,6 @@ void copy_response_headers_from_ngx(const ngx_http_request_t* r,
 
   headers->set_status_code(r->headers_out.status);
 
-  if (r->headers_out.location != NULL) {
-    headers->Add(HttpAttributes::kLocation,
-                 str_to_string_piece(r->headers_out.location->value));
-  }
-
   // Manually copy over the content type because it's not included in
   // request_->headers_out.headers.
   headers->Add(HttpAttributes::kContentType,
@@ -986,6 +988,7 @@ void* ps_create_main_conf(ngx_conf_t* cf) {
       "" /* hostname, not used */,
       -1 /* port, not used */);
   active_driver_factory = cfg_m->driver_factory;
+  active_driver_factory->LoggingInit(ngx_cycle->log, false);
   cfg_m->driver_factory->Init();
   ps_set_conf_cleanup_handler(cf, ps_cleanup_main_conf, cfg_m);
   return cfg_m;
@@ -2478,8 +2481,8 @@ ngx_int_t send_out_headers_and_body(
 
   rc = ngx_http_send_header(r);
 
-  if (rc != NGX_OK) {
-    return NGX_ERROR;
+  if (rc == NGX_ERROR || rc > NGX_OK || r->header_only) {
+    return rc;
   }
 
   // Send the body.
@@ -3051,7 +3054,7 @@ ngx_int_t ps_init_module(ngx_cycle_t* cycle) {
       return NGX_ERROR;
     }
 
-    cfg_m->driver_factory->LoggingInit(cycle->log);
+    cfg_m->driver_factory->LoggingInit(cycle->log, true);
     cfg_m->driver_factory->RootInit();
   } else {
     delete cfg_m->driver_factory;
@@ -3083,7 +3086,7 @@ ngx_int_t ps_init_child_process(ngx_cycle_t* cycle) {
 
   // ChildInit() will initialise all ServerContexts, which we need to
   // create ProxyFetchFactories below
-  cfg_m->driver_factory->LoggingInit(cycle->log);
+  cfg_m->driver_factory->LoggingInit(cycle->log, true);
   cfg_m->driver_factory->ChildInit();
 
   ngx_http_core_main_conf_t* cmcf = static_cast<ngx_http_core_main_conf_t*>(

src/ngx_rewrite_driver_factory.cc

@@ -208,10 +208,11 @@ void NgxRewriteDriverFactory::StartThreads() {
   threads_started_ = true;
 }
 
-void NgxRewriteDriverFactory::LoggingInit(ngx_log_t* log) {
+void NgxRewriteDriverFactory::LoggingInit(
+    ngx_log_t* log, bool may_install_crash_handler) {
   log_ = log;
   net_instaweb::log_message_handler::Install(log);
-  if (install_crash_handler()) {
+  if (may_install_crash_handler && install_crash_handler()) {
     NgxMessageHandler::InstallCrashHandler(log);
   }
   ngx_message_handler_->set_log(log);

src/ngx_rewrite_driver_factory.h

@@ -115,7 +115,7 @@ class NgxRewriteDriverFactory : public SystemRewriteDriverFactory {
     return process_script_variables_;
   }
 
-  void LoggingInit(ngx_log_t* log);
+  void LoggingInit(ngx_log_t* log, bool may_install_crash_handler);
 
   virtual void ShutDownMessageHandlers();
 

test/nginx_system_test.sh

@@ -1241,6 +1241,14 @@ check_from "$OUT" fgrep -qi '404'
 MATCHES=$(echo "$OUT" | grep -c "Cache-Control: override") || true
 check [ $MATCHES -eq 1 ]
 
+start_test Custom 404 does not crash.
+URL=http://custom404.example.com/mod_pagespeed_test/
+URL+=A.doesnotexist.css.pagespeed.cf.0.css
+# The 404 response makes wget exit with an error code, which we ignore.
+OUT=$(http_proxy=$SECONDARY_HOSTNAME $WGET_DUMP -O /dev/null -S $URL 2>&1) || true
+# We ignored the exit code, check if we got a 404 response.
+check_from "$OUT" fgrep -qi '404'
+
 start_test Shutting down.
 
 # Fire up some heavy load if ab is available to test a stressed shutdown

test/pagespeed_test.conf.template

@@ -967,6 +967,14 @@ http {
     }
   }
 
+  server {
+    listen @@SECONDARY_PORT@@;
+    listen [::]:@@SECONDARY_PORT@@;
+    server_name custom404.example.com;
+    pagespeed FileCachePath "@@SECONDARY_CACHE@@";
+    error_page 404 /404.html;
+  }
+
   server {
     listen @@SECONDARY_PORT@@;
     listen [::]:@@SECONDARY_PORT@@;