I turned on mod_dumpio (for a while, it's easy to fill up a disk!), and I captured an example that includes the request for an old style css file.
The source page returned was also captured and there is no mention of the non-existent css, the page response looks as it should be. But the same socket connection used for the page source then goes on to request the css.
In the request for the css from Safari, this header caught my eye (domain changed):
if-modified-since: Tue, 18 Jul 2023 20:48:05 GMT, referer: https://example.com/admin/content
I suspect this is something Safari is doing to speed up at the client; requesting cached CSS. But it does seem odd that it would request resources that aren't on the page source (anymore).
As to what we do about it in Drupal, I would support not logging this as an error and sending a 400 or 404 back to the browser.
I have collected some more information. The exceptions have Agent strings below:
Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/15.6.6 Safari/605.1.15
Mozilla/5.0 (iPhone; CPU iPhone OS 16_0 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.0 Mobile/15E148 Safari/604.1
Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.3 Safari/605.1.15
Mozilla/5.0 (iPhone; CPU iPhone OS 16_0 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.0 Mobile/15E148 Safari/604.1
Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/15.6.1 Safari/605.1.15
Mozilla/5.0 (iPhone; CPU iPhone OS 16_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.2 Mobile/15E148 Safari/604.1
So all from Safari. Has anyone seen any other browser generate these? (I took the time of these errors and tracked them down in /var/log/httpd/access_log).
Hi longwave, there's no CDN but web servers are behind a load balancer and WAF. The WAF doesn't change the requests, it just passes on requests it thinks are okay.
In the last sample, I'm almost 100% certain this is from one client, it's a low traffic site and there's a single burst of activity at that time. The IP is just the load balancer, the actual public IP isn't logged.
It might be useful to log the actual page source returned for a while on that site, and I'll have a look to see if it's always a 403 status that these have in common. Job for tomorrow though.
Just the same, they just miss out the query string. Here's the log for a single request in case you're keen to wade through it. I changed the domain name to protect the innocent!
172.31.46.237 - - [31/Jul/2023:18:42:24 +0000] subdomain.example.com "GET /user/1014 HTTP/1.1" 403 12626 "-" "Mozilla/5.0 (iPhone; CPU iPhone OS 16_5_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.5.2 Mobile/15E148 Safari/604.1"
172.31.46.237 - - [31/Jul/2023:18:42:25 +0000] subdomain.example.com "GET /sites/club0011/files/css/css_36uDh63LXSs76qjstCdFOLgR2cDdda9r1WTbq74NrgY.css?delta=0&language=en&theme=cth&include=eJxtjF0OAiEMhC-Ey5FMwUpwC12Z7kM9vUYSsxrf5u8bOIxbTAQOiYbVNWYhwJc_UWOACiNkHRy7jkZSH59VEU0kJ5hL7SVckX6jN3e77zw8cKMqZ9FSe9xe9yv7dF_NQU9ae-apLmPfSBYYGeMJWJpNaQ HTTP/1.1" 200 2749 "https://subdomain.example.com/user/1014" "Mozilla/5.0 (iPhone; CPU iPhone OS 16_5_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.5.2 Mobile/15E148 Safari/604.1"
172.31.46.237 - - [31/Jul/2023:18:42:25 +0000] subdomain.example.com "GET /sites/club0011/files/css/css_PH43SPObUN9UfC17NeGNJqkiZ-B83AlfyqKYZ7_oWHU.css?delta=1&language=en&theme=cth&include=eJxtjF0OAiEMhC-Ey5FMwUpwC12Z7kM9vUYSsxrf5u8bOIxbTAQOiYbVNWYhwJc_UWOACiNkHRy7jkZSH59VEU0kJ5hL7SVckX6jN3e77zw8cKMqZ9FSe9xe9yv7dF_NQU9ae-apLmPfSBYYGeMJWJpNaQ HTTP/1.1" 200 11155 "https://subdomain.example.com/user/1014" "Mozilla/5.0 (iPhone; CPU iPhone OS 16_5_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.5.2 Mobile/15E148 Safari/604.1"
172.31.46.237 - - [31/Jul/2023:18:42:25 +0000] subdomain.example.com "GET /sites/club0011/files/js/js_XGNd8E2XD6K7ln4v0LLI9waimR0qOsMKNkaN76hul4U.js?scope=footer&delta=0&language=en&theme=cth&include=eJxtjF0OAiEMhC-Ey5FMwUpwC12Z7kM9vUYSsxrf5u8bOIxbTAQOiYbVNWYhwJc_UWOACiNkHRy7jkZSH59VEU0kJ5hL7SVckX6jN3e77zw8cKMqZ9FSe9xe9yv7dF_NQU9ae-apLmPfSBYYGeMJWJpNaQ HTTP/1.1" 200 36044 "https://subdomain.example.com/user/1014" "Mozilla/5.0 (iPhone; CPU iPhone OS 16_5_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.5.2 Mobile/15E148 Safari/604.1"
172.31.46.237 - - [31/Jul/2023:18:42:25 +0000] subdomain.example.com "GET /sites/club0011/files/logo/KFC_Web_Logo.svg HTTP/1.1" 200 13995 "https://subdomain.example.com/user/1014" "Mozilla/5.0 (iPhone; CPU iPhone OS 16_5_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.5.2 Mobile/15E148 Safari/604.1"
172.31.46.237 - - [31/Jul/2023:18:42:24 +0000] subdomain.example.com "GET /sites/club0011/files/css/css_5QIOX67YRJAVVb0EhhnXHbGkIS4M8revWNGPGM1rids.css HTTP/1.1" 400 4997 "https://subdomain.example.com/user/1014" "Mozilla/5.0 (iPhone; CPU iPhone OS 16_5_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.5.2 Mobile/15E148 Safari/604.1"
172.31.46.237 - - [31/Jul/2023:18:42:24 +0000] subdomain.example.com "GET /sites/club0011/files/js/js_C_2va83ewPZSp_sGEiXTLudga5173S7_hKEJtPpqB4Y.js HTTP/1.1" 400 4997 "https://subdomain.example.com/user/1014" "Mozilla/5.0 (iPhone; CPU iPhone OS 16_5_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.5.2 Mobile/15E148 Safari/604.1"
172.31.46.237 - - [31/Jul/2023:18:42:24 +0000] subdomain.example.com "GET /sites/club0011/files/css/css_xvEIUbbpPM0ngBjJCt3buIm8uZzMRpvEAwKAX6SkD2s.css HTTP/1.1" 400 4997 "https://subdomain.example.com/user/1014" "Mozilla/5.0 (iPhone; CPU iPhone OS 16_5_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.5.2 Mobile/15E148 Safari/604.1"
172.31.46.237 - - [31/Jul/2023:18:42:25 +0000] subdomain.example.com "GET /sites/club0011/files/css/css_xdlm4DznKZNjS6A9t3mq3gFwWz3Ip0uxuP4BZerMd9A.css?delta=2&language=en&theme=cth&include=eJxtjF0OAiEMhC-Ey5FMwUpwC12Z7kM9vUYSsxrf5u8bOIxbTAQOiYbVNWYhwJc_UWOACiNkHRy7jkZSH59VEU0kJ5hL7SVckX6jN3e77zw8cKMqZ9FSe9xe9yv7dF_NQU9ae-apLmPfSBYYGeMJWJpNaQ HTTP/1.1" 200 334 "https://subdomain.example.com/user/1014" "Mozilla/5.0 (iPhone; CPU iPhone OS 16_5_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.5.2 Mobile/15E148 Safari/604.1"
I noticed the timestamps are a bit wonky, is this a clue? The first request is for the page source and it results in a 403 Access Denied. At the same time there are three requests to invalid css and js files which all result in the 400 status code. But note there are valid requests as well, a second later (although I only have resolution to the second in the log file). I don't have evidence but I bet the source for the page only contains the valid references with the query strings. But then why would the browser request the invalid ones? It's a bit of a mystery to me.
The same issue applies when inline images are uploaded with maximum dimensions set (eg 100x100). If dimensions are set, the validation function called is "file_validate_image_resolution".
Sorry I'm new to posting suggestions to Drupal, so I don't really know what I'm doing. But hopefully you can reproduce the same problem I'm seeing?
The logged error contains this: "Symfony\Component\HttpKernel\Exception\UnprocessableEntityHttpException: Object(Drupal\Core\Entity\Plugin\DataType\EntityAdapter).uri.0.value: This value should be of the correct primitive type. in Drupal\ckeditor5\Controller\CKEditor5ImageController->upload()"
I was able to fix this in combination with the patch provided by larowlan, but only with the following code added just after $temp_file_path = $upload->getRealPath();:
// Some file validation requires access to the file iteself, which is
// currently in the temporary directory. Initially set the File object
// with the temporary file URI and update it if the file is moved.
$temp_directory_path = $this->fileSystem->getTempDirectory();
if (substr($temp_file_path, 0, strlen($temp_directory_path)) === $temp_directory_path) {
$uri = preg_replace('/^' . preg_quote($temp_directory_path, '/') . '/', '', $temp_file_path);
$temp_file_path = 'temporary://' . ltrim($uri, '/');
}
The code makes sure the URI is in the correct form, and contains the scheme "temporary://" instead of the real file path, which isn't suitable for the URI.
Does this help?
I was (and still am) seeing the same exception here. In the logs I can see the request for the page source, followed by the new style css and js requests but sometimes what looks like an old css/js request. The frequency of these is much less now a few days after the upgrade to 10.1.1 so I can only imagine some browsers are requesting components of a previous cached page while they wait for the main page to be returned to them. It's not something I can repeat, as it only happens in production.