sml_ai_lease_boc(): Condition(hdl->returned == 0 || hdl->avail == hdl->returned) not true.

[desdic]

Expected Behavior

not coredumping

Current Behavior

checked out latest version (trunk) and test upgraded one of our servers and shortly after it just coredumps

after about 10s varnish coredumps with

Child (42870) Panic at: Wed, 30 Jul 2025 06:28:36 GMT
Assert error in sml_ai_lease_boc(), storage/storage_simple.c line 492:
  Condition(hdl->returned == 0 || hdl->avail == hdl->returned) not true.
version = varnish-trunk revision 51a117587524cbdd59e43567e6cbd5a76e6a39ff, vrt api = 21.0
ident = Linux,6.8.0-60-generic,x86_64,-jlinux,-smalloc,-sdefault,-hcritbit,epoll
now = 651.995808 (mono), 1753856868.779870 (real)
Backtrace:
  ip=0x60c6eb006ae5 sp=0x755d84138fb0 <VBT_format+0x65>
  ip=0x60c6eaf7c4fd sp=0x755d841390d0 <pan_ic+0x24d>
  ip=0x60c6eb005d69 sp=0x755d84139230 <VAS_Fail+0x19>
  ip=0x60c6eafddf89 sp=0x755d84139240 <sml_ai_lease_boc+0x5c9>
  ip=0x60c6eafdf8cf sp=0x755d841392a0 <sml_iterator+0x13f>
  ip=0x60c6eaf59847 sp=0x755d841395c0 <VDP_DeliverObj+0x77>
  ip=0x60c6eafb1cf7 sp=0x755d841395d0 <V1D_Deliver+0x3a7>
  ip=0x60c6eaf81c2b sp=0x755d841396d0 <cnt_transmit+0x21b>
  ip=0x60c6eaf85918 sp=0x755d84139720 <CNT_Request+0xf8>
  ip=0x60c6eafb409a sp=0x755d84139800 <http1_req+0x6ba>
  ip=0x60c6eafa8202 sp=0x755d84139880 <WRK_Thread+0x3c2>
  ip=0x60c6eafa87ec sp=0x755d8413a420 <pool_thread+0x3c>
  ip=0x755e5dc9caa4 sp=0x755d8413a450 <pthread_condattr_setpshared+0x684>
  ip=0x755e5dd29c3c sp=0x755d8413a500 <__clone+0x24c>

Possible Solution

No response

Steps to Reproduce (for bugs)

No response

Context

once crashed it keeps crashing so it doesn't work. Strace shows events but no response to client

strace: Process 3505700 attached
restart_syscall(<... resuming interrupted read ...>) = 0
poll([{fd=-1}, {fd=-1}, {fd=11, events=POLLIN}, {fd=-1}, {fd=10, events=POLLIN}, {fd=-1}, {fd=-1}, {fd=14, events=POLLIN}], 8, 874) = 0 (Timeout)
write(13, "ping\n", 5)                  = 5
poll([{fd=13, events=POLLIN}], 1, 60000) = 1 ([{fd=13, revents=POLLIN}])
read(13, "200 19      \n", 13)          = 13
poll([{fd=13, events=POLLIN}], 1, 60000) = 1 ([{fd=13, revents=POLLIN}])
read(13, "PONG 1753795692 1.0\n", 20)   = 20
poll([{fd=-1}, {fd=-1}, {fd=11, events=POLLIN}, {fd=-1}, {fd=10, events=POLLIN}, {fd=-1}, {fd=-1}, {fd=14, events=POLLIN}], 8, 111) = 0 (Timeout)
poll([{fd=-1}, {fd=-1}, {fd=11, events=POLLIN}, {fd=-1}, {fd=10, events=POLLIN}, {fd=-1}, {fd=-1}, {fd=14, events=POLLIN}], 8, 1) = 0 (Timeout)
poll([{fd=-1}, {fd=-1}, {fd=11, events=POLLIN}, {fd=-1}, {fd=10, events=POLLIN}, {fd=-1}, {fd=-1}, {fd=14, events=POLLIN}], 8, 999) = 0 (Timeout)
poll([{fd=-1}, {fd=-1}, {fd=11, events=POLLIN}, {fd=-1}, {fd=10, events=POLLIN}, {fd=-1}, {fd=-1}, {fd=14, events=POLLIN}], 8, 1) = 0 (Timeout)
poll([{fd=-1}, {fd=-1}, {fd=11, events=POLLIN}, {fd=-1}, {fd=10, events=POLLIN}, {fd=-1}, {fd=-1}, {fd=14, events=POLLIN}], 8, 999) = 0 (Timeout)
poll([{fd=-1}, {fd=-1}, {fd=11, events=POLLIN}, {fd=-1}, {fd=10, events=POLLIN}, {fd=-1}, {fd=-1}, {fd=14, events=POLLIN}], 8, 803) = 0 (Timeout)

Varnish Cache version

varnishd (varnish-trunk revision 51a1175)

Operating system

Ubuntu24.04

Source of binary packages used (if any)

No response

[nigoroll]

Thank you very much for testing recent code and for reporting.

This one is on me, I will look asap.

[nigoroll]

@desdic which storage are you using please? edit: answered by @simonvik : should be malloc.

Sharing the full panic string (redacted for PII) would be helpful.

[nigoroll]

@desdic the strace seems to be of the manager process, so it is not relevant for the issue at hand.
I have stared at the code and find it very hard to come up with a hypothesis about what might be wrong here. Can you please help me with at least a panic string?
Ideally, we would have a core dump or an option to attach a debugger to the process before crashing.
The things I would be interested in are (gdb commands)

• local variables of the sml_ai_lease_boc stack frame: info locals
• hdl state: p *hdl

Would you be able to help me with any of these?

[desdic]

@desdic the strace seems to be of the manager process, so it is not relevant for the issue at hand. I have stared at the code and find it very hard to come up with a hypothesis about what might be wrong here. Can you please help me with at least a panic string? Ideally, we would have a core dump or an option to attach a debugger to the process before crashing. The things I would be interested in are (gdb commands)

• local variables of the sml_ai_lease_boc stack frame: info locals
• hdl state: p *hdl

Would you be able to help me with any of these?

ah sorry the strace was missing -f .. sadly I don't have a coredump since coredumps has been disabled (1TB memory) but I do have a full error at

https://pastebin.varnish-software.com/59811c91ca11b5834b46c0f3a13630edc7ebf2398daffd82d8f3f7c66a7074fc

[nigoroll]

@desdic thank you!

I am a bit stuck at the moment, and as in the past I made the experience that right after publicly documenting where I stand, an insight comes along. So let's give it a try:

I now think that the assertion which we hit here

varnish-cache/bin/varnishd/storage/storage_simple.c

Lines 491 to 493 in 4c52938

	if (hdl->st == NULL) {
	assert(hdl->returned == 0 || hdl->avail == hdl->returned);
	hdl->st = VTAILQ_LAST(&hdl->obj->list, storagehead);

is actually wrong, because we should always leave the function with hdl->last set whenever hdl->st == next becomes NULL:

varnish-cache/bin/varnishd/storage/storage_simple.c

Lines 511 to 514 in 4c52938

	if (next == NULL) {
	hdl->last = hdl->st;
	viov->lease = VAI_LEASE_NORET;
	}

Also, the top bit of the function should make sure that hdl->avail > hdl->returned except if state == BOS_FINISHED, so the hdl->avail == hdl->returned disjunct seems to make even less sense.

So it would seem to me that the right assertion was actually assert(hdl->returned == 0).

But all in all I do not see yet how we can hit that assertion.

[nigoroll]

So looks like the trick has worked again. I tried this, and it seems to be clear: At the end, last and st are both NULL:

(gdb) fr 6
#6  0x000056216a5407a2 in sml_ai_lease_boc (wrk=0x7f8b14968340, vhdl=0x7f8b0a611000, scarab=0x7f8b14967340) at storage/storage_simple.c:494
494			assert(hdl->returned == 0);
(gdb) p *hdl
$1 = {preamble = {magic = 937417110, magic2 = 2048250210, vai_lease = 0x56216a540360 <sml_ai_lease_boc>, vai_buffer = 0x56216a53fcc0 <sml_ai_buffer>, 
    vai_return = 0x56216a53ff90 <sml_ai_return_buffers>, reserve = {0, 0, 0, 0}, vai_fini = 0x56216a5401e0 <sml_ai_fini>}, qe = {magic = 1463691243, 
    flags = 0, list = {vsle_next = 0x0}, cb = 0x56216a53f350 <sml_notify>, hdl = 0x7f8b0a611000, priv = 0x7f8b14967228}, task = {list = {vtqe_next = 0x0, 
      vtqe_prev = 0x0}, func = 0x0, priv = 0x0}, ws = 0x0, oc = 0x7f8b0a60c000, obj = 0x7f8b0a207000, stv = 0x7f8b168cd000, boc = 0x7f8b0a60f000, st = 0x0, 
  st_off = 0, avail = 8192, returned = 8192, last = 0x0}
(gdb) p hdl->last
$2 = (struct storage *) 0x0
(gdb) p state
$3 = BOS_FINISHED

So I am back on track

[nigoroll]

I still do not have a reproducer. @desdic just in case: Would it be possible that you gather a varnishlog for a case with 09cd9d4 or later,

varnish-cache/bin/varnishd/storage/storage_simple.c

Line 314 in 09cd9d4

#undef VAI_DBG

changed to #define and SLT_Debug enabled?

varnishadm param.set vsl_mask +Debug

I will continue working on this nevertheless, despite other pressing work, this is my priority 1 at the moment.

(edit: needed a trivial patch on top)

[desdic]

I still do not have a reproducer. @desdic just in case: Would it be possible that you gather a varnishlog for a case with 09cd9d4 or later,

varnish-cache/bin/varnishd/storage/storage_simple.c

Line 314 in 09cd9d4

#undef VAI_DBG
changed to #define and SLT_Debug enabled?

varnishadm param.set vsl_mask +Debug

yes I just need to build again and try it out when least amount of customers are online because I can't make it fail on my test instance

[desdic]

I checked out 09cd9d4

and ran varnishadm param.set vsl_mask +Debug before giving it traffic. Crash (after less than 2s) submitted to

https://pastebin.varnish-software.com/45355aad3ddc53ab409edd6480a85247b33c29917046eac544a147f1629927a3