Open kkmuffme opened 1 month ago
I checked with debug http://nginx.org/en/docs/debugging_log.html but that wasn't really useful, since the issue is already obvious (and that's also what I see in the debug log that those headers aren't set yet) (fyi there are some other scripts running that are irrelevant for this, it's included in the output. I highlighted relevant things below though)
[debug] 2268815#2268815: 418 http cl:-1 max:104857600 [debug] 2268815#2268815: 418 rewrite phase: 4 [debug] 2268815#2268815: 418 rewrite phase: 5 [debug] 2268815#2268815: 418 rewrite phase: 6 [debug] 2268815#2268815: 418 lua rewrite handler, uri:"/" c:1 [debug] 2268815#2268815: 418 code cache lookup (key='rewrite_by_lua_nhli_6206f9203148bf74ea0eb32c0c536c67', ref=2) [debug] 2268815#2268815: 418 code cache hit (key='rewrite_by_lua_nhli_6206f9203148bf74ea0eb32c0c536c67', ref=2) [debug] 2268815#2268815: 418 lua creating new thread [debug] 2268815#2268815: 418 lua reusing cached lua thread 00007F2DD9A068F0 (ref 1) [debug] 2268815#2268815: 418 lua reset ctx [debug] 2268815#2268815: 418 http lua finalize threads [debug] 2268815#2268815: 418 lua run thread, top:0 c:1 [debug] 2268815#2268815: 418 add cleanup: 0000000001C29398 [debug] 2268815#2268815: 418 lua resume returned 0 [debug] 2268815#2268815: 418 lua light thread ended normally [debug] 2268815#2268815: 418 lua deleting light thread 00007F2DD9A068F0 (ref 1) [debug] 2268815#2268815: 418 lua caching unused lua thread 00007F2DD9A068F0 (ref 1) [debug] 2268815#2268815: 418 post rewrite phase: 7 [debug] 2268815#2268815: 418 generic phase: 8 [debug] 2268815#2268815: 418 generic phase: 9 [debug] 2268815#2268815: 418 generic phase: 10 [debug] 2268815#2268815: 418 access phase: 11 [debug] 2268815#2268815: 418 access phase: 12 [debug] 2268815#2268815: 418 access phase: 13 [debug] 2268815#2268815: 418 lua access handler, uri:"/" c:1 [debug] 2268815#2268815: 418 code cache lookup (key='nhlf_f26d53dac9d31d2ad545f24404e10fe7', ref=3) [debug] 2268815#2268815: 418 code cache hit (key='nhlf_f26d53dac9d31d2ad545f24404e10fe7', ref=3) [debug] 2268815#2268815: 418 lua creating new thread [debug] 2268815#2268815: 418 lua reusing cached lua thread 00007F2DD9A068F0 (ref 1) [debug] 2268815#2268815: 418 lua reset ctx [debug] 2268815#2268815: 418 http lua finalize threads [debug] 2268815#2268815: 418 lua run thread, top:0 c:1 [debug] 2268815#2268815: 418 lua resume returned 0 [debug] 2268815#2268815: 418 lua light thread ended normally [debug] 2268815#2268815: 418 lua deleting light thread 00007F2DD9A068F0 (ref 1) [debug] 2268815#2268815: 418 lua caching unused lua thread 00007F2DD9A068F0 (ref 1) [debug] 2268815#2268815: 418 post access phase: 14 [debug] 2268815#2268815: 418 generic phase: 15 [debug] 2268815#2268815: 418 generic phase: 16 [debug] 2268815#2268815: 418 lua content handler, uri:"/" c:1 [debug] 2268815#2268815: 418 code cache lookup (key='nhlf_916db558d68aa4dac3b6a064618d1323', ref=4) [debug] 2268815#2268815: 418 code cache hit (key='nhlf_916db558d68aa4dac3b6a064618d1323', ref=4) [debug] 2268815#2268815: 418 lua reset ctx [debug] 2268815#2268815: 418 http lua finalize threads [debug] 2268815#2268815: 418 lua creating new thread [debug] 2268815#2268815: 418 lua reusing cached lua thread 00007F2DD9A068F0 (ref 1) [debug] 2268815#2268815: 418 lua run thread, top:0 c:1 [debug] 2268815#2268815: 418 lua tcp socket pool get keepalive peer [debug] 2268815#2268815: 418 lua tcp socket get keepalive peer: using connection 00007F2DD52838C0, fd:105 [debug] 2268815#2268815: 418 event timer del: 105: 33240101260 [debug] 2268815#2268815: 418 http cleanup add: 0000000001C29440 [debug] 2268815#2268815: 418 lua tcp socket send timeout: 5000 [debug] 2268815#2268815: 418 lua allocate new chainlink and new buf of size 99, cl:0000000001C29458 [debug] 2268815#2268815: 418 lua tcp socket send data [debug] 2268815#2268815: 418 send: fd:105 71 of 71 [debug] 2268815#2268815: 418 lua tcp socket sent all the data [debug] 2268815#2268815: 418 lua tcp socket calling receive() method [debug] 2268815#2268815: 418 lua tcp socket read timeout: 5000 [debug] 2268815#2268815: 418 lua allocate new chainlink and new buf of size 4096, cl:0000000001C29468 [debug] 2268815#2268815: 418 malloc: 0000000002A90620:4096 [debug] 2268815#2268815: 418 lua tcp socket read timeout: 5000 [debug] 2268815#2268815: 418 lua tcp socket read data: wait:0 [debug] 2268815#2268815: 418 event timer add: 105: 5000:33239884283 [debug] 2268815#2268815: 418 lua resume returned 1 [debug] 2268815#2268815: 418 lua thread yielded [debug] 2268815#2268815: 418 http finalize request: -4, "/?" a:1, c:2 [debug] 2268815#2268815: 418 http request count:2 blk:0 [debug] 2268815#2268815: 418 lua tcp socket handler for "/?", wev 1 [debug] 2268815#2268815: 418 lua tcp socket dummy handler [debug] 2268815#2268815: 418 lua tcp socket handler for "/?", wev 0 [debug] 2268815#2268815: 418 lua tcp socket read handler [debug] 2268815#2268815: 418 event timer del: 105: 33239884283 [debug] 2268815#2268815: 418 lua tcp socket read data: wait:1 [debug] 2268815#2268815: 418 lua tcp socket try to recv data 4096: "/?" [debug] 2268815#2268815: 418 recv: eof:0, avail:-1 [debug] 2268815#2268815: 418 recv: fd:105 4096 of 4096 [debug] 2268815#2268815: 418 recv: avail:21541 [debug] 2268815#2268815: 418 lua tcp socket recv returned 4096: "/?" [debug] 2268815#2268815: 418 lua tcp socket read line [debug] 2268815#2268815: 418 lua read the final line part: "2 [debug] 2268815#2268815: 418 lua tcp socket receive done: wait:1, eof:0, uri:"/?" [debug] 2268815#2268815: 418 lua tcp socket waking up the current request (read) [debug] 2268815#2268815: 418 lua tcp operation done, resuming lua thread [debug] 2268815#2268815: 418 lua tcp socket calling prepare retvals handler 0000000000549A00, u:00007F2DD465A870 [debug] 2268815#2268815: 418 lua tcp socket receive return value handler [debug] 2268815#2268815: 418 lua run thread, top:0 c:1 [debug] 2268815#2268815: 418 lua tcp socket calling receive() method [debug] 2268815#2268815: 418 lua tcp socket read timeout: 5000 [debug] 2268815#2268815: 418 lua tcp socket read timeout: 5000 [debug] 2268815#2268815: 418 lua tcp socket read data: wait:0 [debug] 2268815#2268815: 418 lua tcp socket read line [debug] 2268815#2268815: 418 lua read the final line part: "$24557 [debug] 2268815#2268815: 418 lua tcp socket receive done: wait:0, eof:0, uri:"/?" [debug] 2268815#2268815: 418 lua tcp socket receive done in a single run [debug] 2268815#2268815: 418 lua tcp socket receive return value handler [debug] 2268815#2268815: 418 lua tcp socket calling receive() method [debug] 2268815#2268815: 418 lua tcp socket read timeout: 5000 [debug] 2268815#2268815: 418 lua tcp socket read timeout: 5000 [debug] 2268815#2268815: 418 lua tcp socket read data: wait:0 [debug] 2268815#2268815: 418 lua tcp socket read chunk 4084 [debug] 2268815#2268815: 418 lua allocate new chainlink and new buf of size 4096, cl:0000000001C29488 [debug] 2268815#2268815: 418 malloc: 0000000002A9FF40:4096 [debug] 2268815#2268815: 418 lua tcp socket try to recv data 4096: "/?" [debug] 2268815#2268815: 418 recv: eof:0, avail:21541 [debug] 2268815#2268815: 418 recv: fd:105 4096 of 4096 [debug] 2268815#2268815: 418 recv: avail:17445 [debug] 2268815#2268815: 418 lua tcp socket recv returned 4096: "/?" [debug] 2268815#2268815: 418 lua tcp socket read chunk 4096 [debug] 2268815#2268815: 418 lua allocate new chainlink and new buf of size 4096, cl:0000000002A8FC18 [debug] 2268815#2268815: 418 malloc: 0000000002AA0F50:4096 [debug] 2268815#2268815: 418 lua tcp socket try to recv data 4096: "/?" [debug] 2268815#2268815: 418 recv: eof:0, avail:17445 [debug] 2268815#2268815: 418 recv: fd:105 4096 of 4096 [debug] 2268815#2268815: 418 recv: avail:13349 [debug] 2268815#2268815: 418 lua tcp socket recv returned 4096: "/?" [debug] 2268815#2268815: 418 lua tcp socket read chunk 4096 [debug] 2268815#2268815: 418 lua allocate new chainlink and new buf of size 4096, cl:0000000002A8FC88 [debug] 2268815#2268815: 418 malloc: 0000000002AA1F60:4096 [debug] 2268815#2268815: 418 lua tcp socket try to recv data 4096: "/?" [debug] 2268815#2268815: 418 recv: eof:0, avail:13349 [debug] 2268815#2268815: 418 recv: fd:105 4096 of 4096 [debug] 2268815#2268815: 418 recv: avail:9253 [debug] 2268815#2268815: 418 lua tcp socket recv returned 4096: "/?" [debug] 2268815#2268815: 418 lua tcp socket read chunk 4096 [debug] 2268815#2268815: 418 lua allocate new chainlink and new buf of size 4096, cl:0000000002A8FCF8 [debug] 2268815#2268815: 418 malloc: 0000000002AA2F70:4096 [debug] 2268815#2268815: 418 lua tcp socket try to recv data 4096: "/?" [debug] 2268815#2268815: 418 recv: eof:0, avail:9253 [debug] 2268815#2268815: 418 recv: fd:105 4096 of 4096 [debug] 2268815#2268815: 418 recv: avail:5157 [debug] 2268815#2268815: 418 lua tcp socket recv returned 4096: "/?" [debug] 2268815#2268815: 418 lua tcp socket read chunk 4096 [debug] 2268815#2268815: 418 lua allocate new chainlink and new buf of size 4096, cl:0000000002A8FD68 [debug] 2268815#2268815: 418 malloc: 0000000002AA3F80:4096 [debug] 2268815#2268815: 418 lua tcp socket try to recv data 4096: "/?" [debug] 2268815#2268815: 418 recv: eof:0, avail:5157 [debug] 2268815#2268815: 418 recv: fd:105 4096 of 4096 [debug] 2268815#2268815: 418 recv: avail:1061 [debug] 2268815#2268815: 418 lua tcp socket recv returned 4096: "/?" [debug] 2268815#2268815: 418 lua tcp socket read chunk 4096 [debug] 2268815#2268815: 418 lua tcp socket receive done: wait:0, eof:0, uri:"/?" [debug] 2268815#2268815: 418 lua tcp socket receive done in a single run [debug] 2268815#2268815: 418 lua tcp socket receive return value handler [debug] 2268815#2268815: 418 lua tcp socket calling receive() method [debug] 2268815#2268815: 418 lua tcp socket read timeout: 5000 [debug] 2268815#2268815: 418 lua tcp socket read timeout: 5000 [debug] 2268815#2268815: 418 lua tcp socket read data: wait:0 [debug] 2268815#2268815: 418 lua tcp socket read chunk 7 [debug] 2268815#2268815: 418 lua tcp socket receive done: wait:0, eof:0, uri:"/?" [debug] 2268815#2268815: 418 lua tcp socket receive done in a single run [debug] 2268815#2268815: 418 lua tcp socket receive return value handler [debug] 2268815#2268815: 418 lua tcp socket calling receive() method [debug] 2268815#2268815: 418 lua tcp socket read timeout: 5000 [debug] 2268815#2268815: 418 lua tcp socket read timeout: 5000 [debug] 2268815#2268815: 418 lua tcp socket read data: wait:0 [debug] 2268815#2268815: 418 lua tcp socket read line [debug] 2268815#2268815: 418 lua read partial line data: $1057 [debug] 2268815#2268815: 418 lua reuse free buf memory 4096 >= 4096, cl:0000000001C29468, p:0000000002A90620 [debug] 2268815#2268815: 418 lua tcp socket try to recv data 4096: "/?" [debug] 2268815#2268815: 418 recv: eof:0, avail:1061 [debug] 2268815#2268815: 418 recv: fd:105 1061 of 4096 [debug] 2268815#2268815: 418 recv: avail:0 [debug] 2268815#2268815: 418 lua tcp socket recv returned 1061: "/?" [debug] 2268815#2268815: 418 lua tcp socket read line "024/09/09 07:35:47 [debug] 2268815#2268815: 418 lua read the final line part: " [debug] 2268815#2268815: 418 lua tcp socket receive done: wait:0, eof:0, uri:"/?" [debug] 2268815#2268815: 418 lua tcp socket receive done in a single run [debug] 2268815#2268815: 418 lua tcp socket receive return value handler [debug] 2268815#2268815: 418 lua tcp socket calling receive() method [debug] 2268815#2268815: 418 lua tcp socket read timeout: 5000 [debug] 2268815#2268815: 418 lua tcp socket read timeout: 5000 [debug] 2268815#2268815: 418 lua tcp socket read data: wait:0 [debug] 2268815#2268815: 418 lua tcp socket read chunk 1059 [debug] 2268815#2268815: 418 lua tcp socket receive done: wait:0, eof:0, uri:"/?" [debug] 2268815#2268815: 418 lua tcp socket receive done in a single run [debug] 2268815#2268815: 418 lua tcp socket receive return value handler [debug] 2268815#2268815: 418 lua tcp socket calling receive() method [debug] 2268815#2268815: 418 lua tcp socket read timeout: 5000 [debug] 2268815#2268815: 418 lua tcp socket read timeout: 5000 [debug] 2268815#2268815: 418 lua tcp socket read data: wait:0 [debug] 2268815#2268815: 418 lua tcp socket read chunk 2 [debug] 2268815#2268815: 418 lua tcp socket receive done: wait:0, eof:0, uri:"/?" [debug] 2268815#2268815: 418 lua tcp socket receive done in a single run [debug] 2268815#2268815: 418 lua tcp socket receive return value handler [debug] 2268815#2268815: 418 lua tcp socket set keepalive: saving connection 00007F2DD52838C0 [debug] 2268815#2268815: 418 lua tcp socket clear current socket connection [debug] 2268815#2268815: 418 lua tcp socket keepalive timeout: 300000 ms [debug] 2268815#2268815: 418 event timer add: 105: 300000:33240179283 [debug] 2268815#2268815: 418 lua finalize socket [debug] 2268815#2268815: 418 lua http cleanup free: 0000000001C29440 [alert] 2268815#2268815: 418 [lua] my.lua:5: nil ----------------------------------------------------> here ngx.log ngx.header["Expires"] [debug] 2268815#2268815: 418 lua reuse free buf chain, but reallocate memory because 24557 >= 99, cl:0000000001C29458, p:0000000002A8FB00 [debug] 2268815#2268815: 418 malloc: 0000000002AA4F90:24557 [debug] 2268815#2268815: 418 lua print response [debug] 2268815#2268815: 418 headers more header filter, uri "/" ---> only here the headers from http block will get set [debug] 2268815#2268815: 418 lua capture header filter, uri "/" [debug] 2268815#2268815: 418 http map started [debug] 2268815#2268815: 418 http map: "" "private, no-cache, no-store, must-revalidate, max-age=0" [debug] 2268815#2268815: 418 http script var: "private, no-cache, no-store, must-revalidate, max-age=0" [debug] 2268815#2268815: 418 http map started [debug] 2268815#2268815: 418 http map: "" "Wed, 11 Jan 1984 05:00:00 GMT" [debug] 2268815#2268815: 418 http script var: "Wed, 11 Jan 1984 05:00:00 GMT" [debug] 2268815#2268815: 418 http script copy: "1; mode=block; report=https://" [debug] 2268815#2268815: 418 http script var: "example.com" [debug] 2268815#2268815: 418 http script copy: "/some-file.php" [debug] 2268815#2268815: 418 posix_memalign: 0000000002AAAF90:4096 @16 [debug] 2268815#2268815: 418 http script copy: "default-src ..." [debug] 2268815#2268815: 418 http script var: "example.com" [debug] 2268815#2268815: 418 http script copy: "/some-file.php; report-to some-endpoint" [debug] 2268815#2268815: 418 http script copy: "{ ..." [debug] 2268815#2268815: 418 http script var: "example.com" [debug] 2268815#2268815: 418 http script copy: "/some-file.php" }" [debug] 2268815#2268815: 418 http script var: "example.com" [debug] 2268815#2268815: 418 http script copy: "/some-file.php" } ] }" [debug] 2268815#2268815: 418 http2 header filter [debug] 2268815#2268815: 418 posix_memalign: 0000000002AABFA0:4096 @16 [debug] 2268815#2268815: 418 http2 output header: ":status: 200" [debug] 2268815#2268815: 418 http2 output header: "content-type: text/html; charset=UTF-8" [debug] 2268815#2268815: 418 http2 output header: "date: Mon, 09 Sep 2024 07:35:47 GMT" [debug] 2268815#2268815: 418 http2 output header: "expires: Mon, 09 Sep 2024 08:35:47 GMT" [debug] 2268815#2268815: 418 http2 output header: "cache-control: private, no-cache, no-store, must-revalidate, max-age=0" [debug] 2268815#2268815: 418 http2 output header: "expires: Wed, 11 Jan 1984 05:00:00 GMT" ... [debug] 2268815#2268815: 418 http2:1 create HEADERS frame 0000000002A904C0: len:2576 fin:0 [debug] 2268815#2268815: 418 http cleanup add: 0000000002A905C8 [debug] 2268815#2268815: 418 http output filter "/?" [debug] 2268815#2268815: 418 http copy filter: "/?" [debug] 2268815#2268815: 418 lua capture body filter, uri "/" [debug] 2268815#2268815: 418 http postpone filter "/?" 0000000001C29458 [debug] 2268815#2268815: 418 http brotli filter [debug] 2268815#2268815: 418 write new buf t:1 f:0 0000000002AA4F90, pos 0000000002AA4F90, size: 24557 file: 0, size: 0 [debug] 2268815#2268815: 418 http write filter: l:0 f:0 s:24557 [debug] 2268815#2268815: 418 http write filter limit 5242880 [debug] 2268815#2268815: 418 http2 send chain: 0000000002A905E0 [debug] 2268815#2268815: 418 http2:1 create DATA frame 0000000002A904C0: len:8192 flags:0 [debug] 2268815#2268815: 418 http2:1 create DATA frame 0000000002AABB50: len:8192 flags:0 [debug] 2268815#2268815: 418 http2:1 create DATA frame 0000000002AABC48: len:8173 flags:0 [debug] 2268815#2268815: 418 http write filter 0000000000000000 [debug] 2268815#2268815: 418 http copy filter: 0 "/?" [debug] 2268815#2268815: 418 lua print response has no busy bufs [debug] 2268815#2268815: 418 lua exit with code 200 [debug] 2268815#2268815: 418 lua resume returned 1 [debug] 2268815#2268815: 418 lua thread yielded [debug] 2268815#2268815: 418 lua thread aborting request with status 200 [debug] 2268815#2268815: 418 lua request cleanup: forcible=0 [debug] 2268815#2268815: 418 http lua finalize threads [debug] 2268815#2268815: 418 lua deleting light thread 00007F2DD9A068F0 (ref 1) [debug] 2268815#2268815: 418 lua caching unused lua thread 00007F2DD9A068F0 (ref 1) [debug] 2268815#2268815: 418 lua sending last buf of the response body [debug] 2268815#2268815: 418 http output filter "/?" [debug] 2268815#2268815: 418 http copy filter: "/?" [debug] 2268815#2268815: 418 lua capture body filter, uri "/" [debug] 2268815#2268815: 418 http postpone filter "/?" 00007FFED8658440 [debug] 2268815#2268815: 418 http brotli filter [debug] 2268815#2268815: 418 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0 [debug] 2268815#2268815: 418 http write filter: l:1 f:0 s:0 [debug] 2268815#2268815: 418 http write filter limit 5242880 [debug] 2268815#2268815: 418 http2 send chain: 0000000002A905E0 [debug] 2268815#2268815: 418 http2:1 create DATA frame 0000000002AABC48: len:0 flags:1 [debug] 2268815#2268815: 418 http write filter 0000000000000000 [debug] 2268815#2268815: 418 http copy filter: 0 "/?" [debug] 2268815#2268815: 418 lua run thread returned 0 [debug] 2268815#2268815: 418 http finalize request: 0, "/?" a:1, c:1 [debug] 2268815#2268815: 418 http request count:1 blk:0 [debug] 2268815#2268815: 418 http close request [debug] 2268815#2268815: 418 http log handler [debug] 2268815#2268815: 418 run cleanup: 0000000001C29398 [debug] 2268815#2268815: 418 run cleanup: 0000000000D467D0 [debug] 2268815#2268815: 418 free: 0000000002AA4F90 [debug] 2268815#2268815: 418 free: 0000000002AA3F80 [debug] 2268815#2268815: 418 free: 0000000002AA2F70 [debug] 2268815#2268815: 418 free: 0000000002AA1F60 [debug] 2268815#2268815: 418 free: 0000000002AA0F50 [debug] 2268815#2268815: 418 free: 0000000002A9FF40 [debug] 2268815#2268815: 418 free: 0000000002A90620 [debug] 2268815#2268815: 418 free: 0000000001C294B0 [debug] 2268815#2268815: 418 free: 0000000000D45930, unused: 0 [debug] 2268815#2268815: 418 free: 0000000001C284A0, unused: 0 [debug] 2268815#2268815: 418 free: 0000000002A8F610, unused: 0 [debug] 2268815#2268815: 418 free: 0000000002AAAF90, unused: 576 [debug] 2268815#2268815: *418 free: 0000000002AABFA0, unused: 510
The add_header directive takes effect after the headers_more and lua content and lua header_filter phase. If you want to use lua code or headers_more directive, please consider the following configuration
http {
map $upstream_http_cache_control $custom_cache_control {
"" "private, no-cache, no-store, must-revalidate, max-age=0";
default "";
}
# I think -a should not be used for Cache-Control header, it is just to restore the functionality of add_header
more_set_headers -a "Cache-Control: $custom_cache_control";
server {
...
location / {
// **
# You created variables in http based on $upstream_http_cache_control through map, but proxy_pass and content_by_lua_block cannot be used at the same time, so I believe $upstream_http_cache_control will never exist. You may need to show your specific use case again.
content_by_lua_file '/my.lua';
# When you need to modify the response header, you should use header_filter_by_lua_file instead of content_by_lua_file
header_filter_by_lua_file '/header_filter.lua';
}
}
}
According to the execution phase, it is probably as follows, you can verify it again:
Finally, there is a question: do you want to operate on the Cache-Control or Expires header, or both?
openresty/1.25.3.2
my.lua
At the place marked with
// **
I also tried:=> this doesn't work either - it will only remove the new Expires header I set with the .lua but not the one from http block
What works is using this at
// **
:Then I will only get my Expires header I expected (however all other headers set with add_header are lost/I need to include/set them all there too, which I'd rather avoid)
EDIT: adding
ngx.log( ngx.ALERT, ngx.header["Expires"] )
BEFOREngx.header["Expires"] = nil
results in nil, which means the header isn't set yet, so obviously I can't remove it there. Which goes against what the docs for both ngx.header andmore_clear_headers
say though?