Varnish 丢失并重新获取日志 - 连接断开
Varnish losing and reacquiring log - connection dropped
我遇到 Varnish (6.5) 对特定路由的间歇性空回复或连接重置错误。这是有问题的 VCL（更大的 VCL 集的一部分，但这是路由正在使用的）：
vcl 4.1;
import gcis;
import std;
include "/etc/varnish/conf.d/backend_default.vcl";
include "/etc/varnish/conf.d/acl.vcl";
sub vcl_init {
new idmap = gcis.idmap();
}
sub vcl_recv {
if (!client.ip ~ internal_acl) {
return (synth (
405,
"Client IP " + client.ip +
" is not allowed to access this service."));
}
}
sub vcl_deliver {
// If the request was for reloading the ACL, reload the list here.
if (req.url == "/svc/reload_acl") {
std.log(
idmap.load(std.getenv("GCISWG_ACL_FILE"))
+ " restricted identifiers reloaded from database."
);
ban ("req.url ~ ^/iiif/");
ban ("req.url == /svc/dump_acl");
}
}
如果我重复发送以下请求：
curl -iXPOST varnish/svc/reload_acl
有时我会得到预期的响应；其他时候我得到 curl: (52) Empty reply from server 其他时候 curl: (56) Recv failure: Connection reset by peer.
空回复的 varnishlog 条目如下所示：
varnish_1 | * << BeReq >> 9
varnish_1 | - Begin bereq 8 pass
varnish_1 | - VCL_use svc
varnish_1 | - Timestamp Start: 1623449680.866799 0.000000 0.000000
varnish_1 | - BereqMethod POST
varnish_1 | - BereqURL /svc/reload_acl
varnish_1 | - BereqProtocol HTTP/1.1
varnish_1 | - BereqHeader User-Agent: curl/7.64.0
varnish_1 | - BereqHeader Accept: */*
varnish_1 | - BereqHeader X-Forwarded-For: 172.18.0.5
varnish_1 | - BereqHeader host: varnish
varnish_1 | - BereqHeader X-Varnish: 9
varnish_1 | - VCL_call BACKEND_FETCH
varnish_1 | - VCL_return fetch
varnish_1 | - BackendOpen 32 default 172.18.0.8 8080 172.18.0.9 34554 reuse
varnish_1 | - Timestamp Bereq: 1623449680.866890 0.000091 0.000091
varnish_1 | - Timestamp Beresp: 1623449680.878314 0.011515 0.011424
varnish_1 | - BerespProtocol HTTP/1.1
varnish_1 | - BerespStatus 201
varnish_1 | - BerespReason CREATED
varnish_1 | - BerespHeader Server: nginx/1.18.0
varnish_1 | - BerespHeader Date: Fri, 11 Jun 2021 22:14:40 GMT
varnish_1 | - BerespHeader Content-Type: text/html; charset=utf-8
varnish_1 | - BerespHeader Content-Length: 31
varnish_1 | - BerespHeader Connection: keep-alive
varnish_1 | - VCL_call BACKEND_RESPONSE
varnish_1 | - VCL_return deliver
varnish_1 | - Filters
varnish_1 | - Storage malloc Transient
varnish_1 | - Fetch_Body 3 length stream
varnish_1 | - BackendClose 32 default recycle
varnish_1 | - Timestamp BerespBody: 1623449680.878392 0.011593 0.000078
varnish_1 | - Length 31
varnish_1 | - BereqAcct 129 0 129 167 31 198
varnish_1 | - End
varnish_1 |
varnish_1 | * << Session >> 7
varnish_1 | - Begin sess 0 HTTP/1
varnish_1 | - SessOpen 172.18.0.5 57306 nossl 172.18.0.9 80 1623449680.866658 30
varnish_1 | - Link req 8 rxreq
varnish_1 | - VSL flush
varnish_1 | - End synth
varnish_1 |
varnish_1 | * << Request >> 8
varnish_1 | - Begin req 7 rxreq
varnish_1 | - Timestamp Start: 1623449680.866744 0.000000 0.000000
varnish_1 | - Timestamp Req: 1623449680.866744 0.000000 0.000000
varnish_1 | - VCL_use main
varnish_1 | - ReqStart 172.18.0.5 57306 nossl
varnish_1 | - ReqMethod POST
varnish_1 | - ReqURL /svc/reload_acl
varnish_1 | - ReqProtocol HTTP/1.1
varnish_1 | - ReqHeader Host: varnish
varnish_1 | - ReqHeader User-Agent: curl/7.64.0
varnish_1 | - ReqHeader Accept: */*
varnish_1 | - ReqHeader X-Forwarded-For: 172.18.0.5
varnish_1 | - VCL_call RECV
varnish_1 | - VCL_use svc via svc_vcl
varnish_1 | - VCL_return vcl
varnish_1 | - ReqHeader X-Forwarded-For: 172.18.0.5
varnish_1 | - VCL_call RECV
varnish_1 | - VCL_acl MATCH internal_acl "172.0.0.0/8"
varnish_1 | - ReqUnset Host: varnish
varnish_1 | - ReqHeader host: varnish
varnish_1 | - VCL_return pass
varnish_1 | Log abandoned (vsl)
varnish_1 | Log reacquired
varnish_1 | - VCL_call HASH
varnish_1 | - VCL_return lookup
varnish_1 | - VCL_call PASS
varnish_1 | - VCL_return fetch
varnish_1 | - Link bereq 9 pass
varnish_1 | - Timestamp Fetch: 1623449680.878425 0.011680 0.011680
varnish_1 | - RespProtocol HTTP/1.1
varnish_1 | - RespStatus 201
varnish_1 | - RespReason CREATED
varnish_1 | - RespHeader Server: nginx/1.18.0
varnish_1 | - RespHeader Date: Fri, 11 Jun 2021 22:14:40 GMT
varnish_1 | - RespHeader Content-Type: text/html; charset=utf-8
varnish_1 | - RespHeader Content-Length: 31
varnish_1 | - RespHeader X-Varnish: 8
varnish_1 | - RespHeader Age: 0
varnish_1 | - RespHeader Via: 1.1 varnish (Varnish/6.5)
varnish_1 | - VCL_call DELIVER
varnish_1 | - VSL flush
varnish_1 | - End synth
会发生什么？竞争条件？我在交付子中遗漏了什么吗？顺便说一句，我在没有禁止命令的情况下也注意到了这些问题。
感谢您的帮助。
更新：按照评论者的建议，我检查了恐慌转储：
Panic at: Mon, 14 Jun 2021 17:25:36 GMT
Wrong turn at cache/cache_main.c:287:
Signal 11 (Segmentation fault) received at 0 si_code 128
version = varnish-6.5.1 revision 1dae23376bb5ea7a6b8e9e4b9ed95cdc9469fb64, vrt api = 12.0
ident = Linux,5.12.6-arch1-1,x86_64,-junix,-sdefault,-sfile,-sdefault,-hcritbit,epoll
now = 148500.767810 (mono), 1623691535.535737 (real)
Backtrace:
ip=0x55c79cbc5b19, sp=0x7f941dbf8460 <PAN_already+0x1304>
ip=0x55c79cc1c8de, sp=0x7f941dbf85a0 <VAS_Fail+0x22>
ip=0x55c79cbc1cb2, sp=0x7f941dbf85e0 <THR_GetRequest+0x14a>
ip=0x7f941dd75c4b, sp=0x7f941dbf8ac0 <sigwaitinfo+0x8>
pthread.self = 0x7f9417c63b38
pthread.name = (cache-worker)
pthread.attr = {
guard = 8192,
stack_bottom = 0x7f9417c55000,
stack_top = 0x7f9417c63b08,
stack_size = 60168,
}
thr.req = 0x7f93f736eb20 {
vxid = 32770, transport = HTTP/1 {
state = HTTP1::Proc
}
step = R_STP_DELIVER,
req_body = none,
restarts = 0, esi_level = 0,
sp = 0x7f93f737f030 {
fd = 28, vxid = 32769,
t_open = 1623691535.525822,
t_idle = 1623691535.525822,
ws = 0x7f93f737f070 {
id = \"ses\",
{s, f, r, e} = {0x7f93f737f0c8, +96, 0, +576},
},
transport = HTTP/1 {
state = HTTP1::Proc
}
client = 172.18.0.5 57692 :80,
},
worker = 0x7f9417c63970 {
ws = 0x7f9417c63a18 {
id = \"wrk\",
{s, f, r, e} = {0x7f9417c62f50, +0, 0, +2040},
},
VCL::method = inside DELIVER,
VCL::return = 0x0,
VCL::methods = {RECV, PASS, HASH, DELIVER},
},
ws = 0x7f93f736ec70 {
id = \"req\",
{s, f, r, e} = {0x7f93f7370bd0, +168, 0, +57128},
},
http_conn = 0x7f93f7370b48 {
fd = 28 (@0x7f93f737f054),
doclose = NULL,
ws = 0x7f93f736ec70 {
[Already dumped, see above]
},
{rxbuf_b, rxbuf_e} = {0x7f93f7370bd0, 0x7f93f7370c26},
{pipeline_b, pipeline_e} = {0, 0},
content_length = -1,
body_status = none,
first_byte_timeout = 0.000000,
between_bytes_timeout = 0.000000,
},
http[req] = 0x7f93f736ed10 {
ws = 0x7f93f736ec70 {
[Already dumped, see above]
},
hdrs {
\"POST\",
\"/svc/reload_acl\",
\"HTTP/1.1\",
\"User-Agent: curl/7.64.0\",
\"Accept: */*\",
\"X-Forwarded-For: 172.18.0.5\",
\"host: varnish\",
},
},
http[resp] = 0x7f93f736f600 {
ws = 0x7f93f736ec70 {
[Already dumped, see above]
},
hdrs {
\"HTTP/1.1\",
\"201\",
\"CREATED\",
\"Server: nginx/1.18.0\",
\"Date: Mon, 14 Jun 2021 17:25:35 GMT\",
\"Content-Type: text/html; charset=utf-8\",
\"Content-Length: 31\",
\"X-Varnish: 32770\",
\"Age: 0\",
\"Via: 1.1 varnish (Varnish/6.5)\",
},
},
vdc = 0x7f93f7370b28 {
nxt = 0,
retval = 0,
},
vcl = {
name = \"svc\",
busy = 1,
discard = 0,
state = auto,
temp = warm,
conf = {
syntax = \"41\",
srcname = {
\"/etc/varnish/conf.d/svc.vcl\",
\"Builtin\",
\"/etc/varnish/conf.d/backend_default.vcl\",
\"/etc/varnish/conf.d/acl.vcl\",
instances = {
\"idmap\" = 0x7f93f75fe070,
},
},
},
objcore[REQ] = 0x7f93f75d51f0 {
refcnt = 1,
flags = {hfm, private},
exp_flags = {},
exp = {1623691535.535603, -1.000000, 0.000000, 0.000000},
objhead = 0x7f941dc16890,
stevedore = 0x55c79cc9dee0 (malloc Transient) {
Simple = 0x7f93f75d58d0,
Obj = 0x7f93f771ad98 {priv=0x7f93f771ad90, ptr=0x7f93f75d58d0, len=264, space=264},
LEN = 0x000000000000001f,
VXID = 0x00008003,
FLAGS = 0x00,
GZIPBITS = 0x0...0,
LASTMODIFIED = 0x41d831e443c00000,
VARY = {len=0, ptr=0},
HEADERS = {len=144, ptr=0x7f93f75d5948},
Body = 0x7f93f7593818 {priv=0x7f93f7593810, ptr=0x7f93f75d5c90, len=31, space=31},
},
},
flags = {
},
privs = 0x7f93f736ed00 {
},
top = 0x7f93f7370bb0 {
req = 0x7f93f736eb20 {
[Already dumped, see above]
},
privs = 0x7f93f7370bc8 {
},
vcl0 = {
name = \"main\",
busy = 1,
discard = 0,
state = auto,
temp = warm,
conf = {
syntax = \"41\",
srcname = {
\"/etc/varnish/conf.d/main.vcl\",
\"Builtin\",
\"/etc/varnish/conf.d/backend_default.vcl\",
\"/etc/varnish/conf.d/synth.vcl\",
instances = {
\"idmap\" = 0x7f93f75fe070,
},
},
},
},
},
thr.busyobj = 0 {
},
vmods = {
blob = {0x7f941860edb0, Varnish 6.5.1 1dae23376bb5ea7a6b8e9e4b9ed95cdc9469fb64, 0.0},
blobdigest = {0x7f941860ee20, Varnish 6.5.1 1dae23376bb5ea7a6b8e9e4b9ed95cdc9469fb64, 0.0},
curl = {0x7f941860ef00, Varnish 6.5.1 1dae23376bb5ea7a6b8e9e4b9ed95cdc9469fb64, 12.0},
frozen = {0x7f93f7625020, Varnish 6.5.1 1dae23376bb5ea7a6b8e9e4b9ed95cdc9469fb64, 0.0},
gcis = {0x7f93f7625090, Varnish 6.5.1 1dae23376bb5ea7a6b8e9e4b9ed95cdc9469fb64, 0.0},
std = {0x7f93f7625100, Varnish 6.5.1 1dae23376bb5ea7a6b8e9e4b9ed95cdc9469fb64, 0.0},
},
我注意到如果我在我构建的自定义 VMOD 中删除对函数的调用，则不会发生恐慌。这是有问题的功能：
VCL_INT
vmod_idmap_load (VRT_CTX, IDMap *idmap, VCL_STRING fpath)
{
int i = 0;
char *line = NULL;
FILE *fh = NULL;
idmap_clear (idmap);
LOG ("Opening file %s", fpath);
fh = fopen (fpath, "r");
if (!fh) {
VRT_fail (ctx, "Error opening %s", fpath);
i = -1;
goto finally;
}
size_t size = 0;
int ret;
while (getline (&line, &size, fh) >= 0) {
char *id = strndup (line, UUID_STR_LEN - 1);
//LOG ("UUID: %s", id);
khint_t cur = kh_put (uuid_ht, idmap->ht, id, &ret);
if (cur != kh_end (idmap->ht)) i++;
else LOG ("Duplicate ID: %s", id);
line = NULL;
size = 0;
};
LOG ("%d identifiers loaded.", i);
finally:
free (line);
if (fh) fclose (fh);
idmap->ct = i;
return i;
}
不幸的是，我无法从转储中分辨出段错误的确切位置。我可以用调试符号编译 Varnish 以了解更多信息吗？
我敢打赌，vmod 代码破坏了堆栈，造成恐慌，因为堆栈跟踪毫无意义。
如果您不确定哪里出了问题，最好的办法是撒一些 VSLb(ctx, VCL_Error, "at line %d", __LINE__) 看看您使用 varnishlog.
能走多远
请注意，您没有测试很多输入，returns，我建议 asserting/checking 多做一些。例如：https://github.com/varnish/varnish-modules/blob/master/src/vmod_str.c#L15
另一个例子是 strndup() 不应该失败，所以你应该在它后面有一个 AN(id)。
希望对您有所帮助
我遇到 Varnish (6.5) 对特定路由的间歇性空回复或连接重置错误。这是有问题的 VCL（更大的 VCL 集的一部分，但这是路由正在使用的）：
vcl 4.1;
import gcis;
import std;
include "/etc/varnish/conf.d/backend_default.vcl";
include "/etc/varnish/conf.d/acl.vcl";
sub vcl_init {
new idmap = gcis.idmap();
}
sub vcl_recv {
if (!client.ip ~ internal_acl) {
return (synth (
405,
"Client IP " + client.ip +
" is not allowed to access this service."));
}
}
sub vcl_deliver {
// If the request was for reloading the ACL, reload the list here.
if (req.url == "/svc/reload_acl") {
std.log(
idmap.load(std.getenv("GCISWG_ACL_FILE"))
+ " restricted identifiers reloaded from database."
);
ban ("req.url ~ ^/iiif/");
ban ("req.url == /svc/dump_acl");
}
}
如果我重复发送以下请求：
curl -iXPOST varnish/svc/reload_acl
有时我会得到预期的响应；其他时候我得到 curl: (52) Empty reply from server 其他时候 curl: (56) Recv failure: Connection reset by peer.
空回复的 varnishlog 条目如下所示：
varnish_1 | * << BeReq >> 9
varnish_1 | - Begin bereq 8 pass
varnish_1 | - VCL_use svc
varnish_1 | - Timestamp Start: 1623449680.866799 0.000000 0.000000
varnish_1 | - BereqMethod POST
varnish_1 | - BereqURL /svc/reload_acl
varnish_1 | - BereqProtocol HTTP/1.1
varnish_1 | - BereqHeader User-Agent: curl/7.64.0
varnish_1 | - BereqHeader Accept: */*
varnish_1 | - BereqHeader X-Forwarded-For: 172.18.0.5
varnish_1 | - BereqHeader host: varnish
varnish_1 | - BereqHeader X-Varnish: 9
varnish_1 | - VCL_call BACKEND_FETCH
varnish_1 | - VCL_return fetch
varnish_1 | - BackendOpen 32 default 172.18.0.8 8080 172.18.0.9 34554 reuse
varnish_1 | - Timestamp Bereq: 1623449680.866890 0.000091 0.000091
varnish_1 | - Timestamp Beresp: 1623449680.878314 0.011515 0.011424
varnish_1 | - BerespProtocol HTTP/1.1
varnish_1 | - BerespStatus 201
varnish_1 | - BerespReason CREATED
varnish_1 | - BerespHeader Server: nginx/1.18.0
varnish_1 | - BerespHeader Date: Fri, 11 Jun 2021 22:14:40 GMT
varnish_1 | - BerespHeader Content-Type: text/html; charset=utf-8
varnish_1 | - BerespHeader Content-Length: 31
varnish_1 | - BerespHeader Connection: keep-alive
varnish_1 | - VCL_call BACKEND_RESPONSE
varnish_1 | - VCL_return deliver
varnish_1 | - Filters
varnish_1 | - Storage malloc Transient
varnish_1 | - Fetch_Body 3 length stream
varnish_1 | - BackendClose 32 default recycle
varnish_1 | - Timestamp BerespBody: 1623449680.878392 0.011593 0.000078
varnish_1 | - Length 31
varnish_1 | - BereqAcct 129 0 129 167 31 198
varnish_1 | - End
varnish_1 |
varnish_1 | * << Session >> 7
varnish_1 | - Begin sess 0 HTTP/1
varnish_1 | - SessOpen 172.18.0.5 57306 nossl 172.18.0.9 80 1623449680.866658 30
varnish_1 | - Link req 8 rxreq
varnish_1 | - VSL flush
varnish_1 | - End synth
varnish_1 |
varnish_1 | * << Request >> 8
varnish_1 | - Begin req 7 rxreq
varnish_1 | - Timestamp Start: 1623449680.866744 0.000000 0.000000
varnish_1 | - Timestamp Req: 1623449680.866744 0.000000 0.000000
varnish_1 | - VCL_use main
varnish_1 | - ReqStart 172.18.0.5 57306 nossl
varnish_1 | - ReqMethod POST
varnish_1 | - ReqURL /svc/reload_acl
varnish_1 | - ReqProtocol HTTP/1.1
varnish_1 | - ReqHeader Host: varnish
varnish_1 | - ReqHeader User-Agent: curl/7.64.0
varnish_1 | - ReqHeader Accept: */*
varnish_1 | - ReqHeader X-Forwarded-For: 172.18.0.5
varnish_1 | - VCL_call RECV
varnish_1 | - VCL_use svc via svc_vcl
varnish_1 | - VCL_return vcl
varnish_1 | - ReqHeader X-Forwarded-For: 172.18.0.5
varnish_1 | - VCL_call RECV
varnish_1 | - VCL_acl MATCH internal_acl "172.0.0.0/8"
varnish_1 | - ReqUnset Host: varnish
varnish_1 | - ReqHeader host: varnish
varnish_1 | - VCL_return pass
varnish_1 | Log abandoned (vsl)
varnish_1 | Log reacquired
varnish_1 | - VCL_call HASH
varnish_1 | - VCL_return lookup
varnish_1 | - VCL_call PASS
varnish_1 | - VCL_return fetch
varnish_1 | - Link bereq 9 pass
varnish_1 | - Timestamp Fetch: 1623449680.878425 0.011680 0.011680
varnish_1 | - RespProtocol HTTP/1.1
varnish_1 | - RespStatus 201
varnish_1 | - RespReason CREATED
varnish_1 | - RespHeader Server: nginx/1.18.0
varnish_1 | - RespHeader Date: Fri, 11 Jun 2021 22:14:40 GMT
varnish_1 | - RespHeader Content-Type: text/html; charset=utf-8
varnish_1 | - RespHeader Content-Length: 31
varnish_1 | - RespHeader X-Varnish: 8
varnish_1 | - RespHeader Age: 0
varnish_1 | - RespHeader Via: 1.1 varnish (Varnish/6.5)
varnish_1 | - VCL_call DELIVER
varnish_1 | - VSL flush
varnish_1 | - End synth
会发生什么？竞争条件？我在交付子中遗漏了什么吗？顺便说一句，我在没有禁止命令的情况下也注意到了这些问题。
感谢您的帮助。
更新：按照评论者的建议，我检查了恐慌转储：
Panic at: Mon, 14 Jun 2021 17:25:36 GMT
Wrong turn at cache/cache_main.c:287:
Signal 11 (Segmentation fault) received at 0 si_code 128
version = varnish-6.5.1 revision 1dae23376bb5ea7a6b8e9e4b9ed95cdc9469fb64, vrt api = 12.0
ident = Linux,5.12.6-arch1-1,x86_64,-junix,-sdefault,-sfile,-sdefault,-hcritbit,epoll
now = 148500.767810 (mono), 1623691535.535737 (real)
Backtrace:
ip=0x55c79cbc5b19, sp=0x7f941dbf8460 <PAN_already+0x1304>
ip=0x55c79cc1c8de, sp=0x7f941dbf85a0 <VAS_Fail+0x22>
ip=0x55c79cbc1cb2, sp=0x7f941dbf85e0 <THR_GetRequest+0x14a>
ip=0x7f941dd75c4b, sp=0x7f941dbf8ac0 <sigwaitinfo+0x8>
pthread.self = 0x7f9417c63b38
pthread.name = (cache-worker)
pthread.attr = {
guard = 8192,
stack_bottom = 0x7f9417c55000,
stack_top = 0x7f9417c63b08,
stack_size = 60168,
}
thr.req = 0x7f93f736eb20 {
vxid = 32770, transport = HTTP/1 {
state = HTTP1::Proc
}
step = R_STP_DELIVER,
req_body = none,
restarts = 0, esi_level = 0,
sp = 0x7f93f737f030 {
fd = 28, vxid = 32769,
t_open = 1623691535.525822,
t_idle = 1623691535.525822,
ws = 0x7f93f737f070 {
id = \"ses\",
{s, f, r, e} = {0x7f93f737f0c8, +96, 0, +576},
},
transport = HTTP/1 {
state = HTTP1::Proc
}
client = 172.18.0.5 57692 :80,
},
worker = 0x7f9417c63970 {
ws = 0x7f9417c63a18 {
id = \"wrk\",
{s, f, r, e} = {0x7f9417c62f50, +0, 0, +2040},
},
VCL::method = inside DELIVER,
VCL::return = 0x0,
VCL::methods = {RECV, PASS, HASH, DELIVER},
},
ws = 0x7f93f736ec70 {
id = \"req\",
{s, f, r, e} = {0x7f93f7370bd0, +168, 0, +57128},
},
http_conn = 0x7f93f7370b48 {
fd = 28 (@0x7f93f737f054),
doclose = NULL,
ws = 0x7f93f736ec70 {
[Already dumped, see above]
},
{rxbuf_b, rxbuf_e} = {0x7f93f7370bd0, 0x7f93f7370c26},
{pipeline_b, pipeline_e} = {0, 0},
content_length = -1,
body_status = none,
first_byte_timeout = 0.000000,
between_bytes_timeout = 0.000000,
},
http[req] = 0x7f93f736ed10 {
ws = 0x7f93f736ec70 {
[Already dumped, see above]
},
hdrs {
\"POST\",
\"/svc/reload_acl\",
\"HTTP/1.1\",
\"User-Agent: curl/7.64.0\",
\"Accept: */*\",
\"X-Forwarded-For: 172.18.0.5\",
\"host: varnish\",
},
},
http[resp] = 0x7f93f736f600 {
ws = 0x7f93f736ec70 {
[Already dumped, see above]
},
hdrs {
\"HTTP/1.1\",
\"201\",
\"CREATED\",
\"Server: nginx/1.18.0\",
\"Date: Mon, 14 Jun 2021 17:25:35 GMT\",
\"Content-Type: text/html; charset=utf-8\",
\"Content-Length: 31\",
\"X-Varnish: 32770\",
\"Age: 0\",
\"Via: 1.1 varnish (Varnish/6.5)\",
},
},
vdc = 0x7f93f7370b28 {
nxt = 0,
retval = 0,
},
vcl = {
name = \"svc\",
busy = 1,
discard = 0,
state = auto,
temp = warm,
conf = {
syntax = \"41\",
srcname = {
\"/etc/varnish/conf.d/svc.vcl\",
\"Builtin\",
\"/etc/varnish/conf.d/backend_default.vcl\",
\"/etc/varnish/conf.d/acl.vcl\",
instances = {
\"idmap\" = 0x7f93f75fe070,
},
},
},
objcore[REQ] = 0x7f93f75d51f0 {
refcnt = 1,
flags = {hfm, private},
exp_flags = {},
exp = {1623691535.535603, -1.000000, 0.000000, 0.000000},
objhead = 0x7f941dc16890,
stevedore = 0x55c79cc9dee0 (malloc Transient) {
Simple = 0x7f93f75d58d0,
Obj = 0x7f93f771ad98 {priv=0x7f93f771ad90, ptr=0x7f93f75d58d0, len=264, space=264},
LEN = 0x000000000000001f,
VXID = 0x00008003,
FLAGS = 0x00,
GZIPBITS = 0x0...0,
LASTMODIFIED = 0x41d831e443c00000,
VARY = {len=0, ptr=0},
HEADERS = {len=144, ptr=0x7f93f75d5948},
Body = 0x7f93f7593818 {priv=0x7f93f7593810, ptr=0x7f93f75d5c90, len=31, space=31},
},
},
flags = {
},
privs = 0x7f93f736ed00 {
},
top = 0x7f93f7370bb0 {
req = 0x7f93f736eb20 {
[Already dumped, see above]
},
privs = 0x7f93f7370bc8 {
},
vcl0 = {
name = \"main\",
busy = 1,
discard = 0,
state = auto,
temp = warm,
conf = {
syntax = \"41\",
srcname = {
\"/etc/varnish/conf.d/main.vcl\",
\"Builtin\",
\"/etc/varnish/conf.d/backend_default.vcl\",
\"/etc/varnish/conf.d/synth.vcl\",
instances = {
\"idmap\" = 0x7f93f75fe070,
},
},
},
},
},
thr.busyobj = 0 {
},
vmods = {
blob = {0x7f941860edb0, Varnish 6.5.1 1dae23376bb5ea7a6b8e9e4b9ed95cdc9469fb64, 0.0},
blobdigest = {0x7f941860ee20, Varnish 6.5.1 1dae23376bb5ea7a6b8e9e4b9ed95cdc9469fb64, 0.0},
curl = {0x7f941860ef00, Varnish 6.5.1 1dae23376bb5ea7a6b8e9e4b9ed95cdc9469fb64, 12.0},
frozen = {0x7f93f7625020, Varnish 6.5.1 1dae23376bb5ea7a6b8e9e4b9ed95cdc9469fb64, 0.0},
gcis = {0x7f93f7625090, Varnish 6.5.1 1dae23376bb5ea7a6b8e9e4b9ed95cdc9469fb64, 0.0},
std = {0x7f93f7625100, Varnish 6.5.1 1dae23376bb5ea7a6b8e9e4b9ed95cdc9469fb64, 0.0},
},
我注意到如果我在我构建的自定义 VMOD 中删除对函数的调用，则不会发生恐慌。这是有问题的功能：
VCL_INT
vmod_idmap_load (VRT_CTX, IDMap *idmap, VCL_STRING fpath)
{
int i = 0;
char *line = NULL;
FILE *fh = NULL;
idmap_clear (idmap);
LOG ("Opening file %s", fpath);
fh = fopen (fpath, "r");
if (!fh) {
VRT_fail (ctx, "Error opening %s", fpath);
i = -1;
goto finally;
}
size_t size = 0;
int ret;
while (getline (&line, &size, fh) >= 0) {
char *id = strndup (line, UUID_STR_LEN - 1);
//LOG ("UUID: %s", id);
khint_t cur = kh_put (uuid_ht, idmap->ht, id, &ret);
if (cur != kh_end (idmap->ht)) i++;
else LOG ("Duplicate ID: %s", id);
line = NULL;
size = 0;
};
LOG ("%d identifiers loaded.", i);
finally:
free (line);
if (fh) fclose (fh);
idmap->ct = i;
return i;
}
不幸的是，我无法从转储中分辨出段错误的确切位置。我可以用调试符号编译 Varnish 以了解更多信息吗？
我敢打赌，vmod 代码破坏了堆栈，造成恐慌，因为堆栈跟踪毫无意义。
如果您不确定哪里出了问题，最好的办法是撒一些 VSLb(ctx, VCL_Error, "at line %d", __LINE__) 看看您使用 varnishlog.
请注意，您没有测试很多输入，returns，我建议 asserting/checking 多做一些。例如：https://github.com/varnish/varnish-modules/blob/master/src/vmod_str.c#L15
另一个例子是 strndup() 不应该失败，所以你应该在它后面有一个 AN(id)。
希望对您有所帮助