[squid-users] Squid 6.4 assertion errors: FATAL: assertion failed: stmem.cc:98: "lowestOffset () <= target_offset" current master transaction: master655 (backtrace)]

Ralf Hildebrandt Ralf.Hildebrandt at charite.de
Mon Oct 23 11:39:52 UTC 2023


I upgraded from 6.3 to 6.4 today and it INSTANTLY began crashing
(frequently!)

The Log messages in cache.log:
...
2023/10/23 09:57:21| Beginning Validation Procedure
2023/10/23 09:57:21| Completed Validation Procedure
    Validated 237163 Entries
    store_swap_size = 29491032.00 KB
2023/10/23 09:57:21| Recv recv: (111) Connection refused
2023/10/23 09:57:21| Closing Pinger socket on FD 25
2023/10/23 09:57:22| storeLateRelease: released 0 objects
2023/10/23 09:57:46| FATAL: assertion failed: stmem.cc:98: "lowestOffset () <= target_offset"
    current master transaction: master655
   
Backtraces (core files mentioned in the bt are available for further debugging):
================================================================================

Reading symbols from /usr/sbin/squid...
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".

Program received signal SIGABRT, Aborted.
__GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#0  __GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
        set = {
          __val = {0, 115, 59597774791904, 8260741391549598720, 1, 
            8260741391549598720, 93825000044944, 140737488346944, 
            93825000045032, 140737488346992, 93824997712448, 93824995977164, 
            93825059434008, 140737344738147, 206158430240, 140737488346848}
        }
        pid = <optimized out>
        tid = <optimized out>
        ret = <optimized out>
#1  0x00007ffff7613859 in __GI_abort () at abort.c:79
        save_stage = 1
        act = {
          __sigaction_handler = {
            sa_handler = 0x55555956ae18,
            sa_sigaction = 0x55555956ae18
          },
          sa_mask = {
            __val = {93824997144201, 47, 1698047866, 972957, 0, 
              93824997779200, 93825059434008, 93825059130880, 
              8260741391549598720, 114, 93825000044944, 93825000113656, 
              93824997147760, 93825000113656, 93824997143224, 93825000113656}
          },
          sa_flags = 1085148160,
          sa_restorer = 0x555555a8e4e0
        }
        sigs = {
          __val = {32, 0 <repeats 15 times>}
        }
#2  0x0000555555a03343 in xassert (
    msg=msg at entry=0x555555a8e4e0 "lowestOffset () <= target_offset", 
    file=file at entry=0x555555a8e240 "stmem.cc", line=line at entry=98)
    at debug.cc:1269
        __FUNCTION__ = <optimized out>
#3  0x000055555582a2ea in mem_hdr::freeDataUpto (
    this=this at entry=0x55555957ca08, target_offset=target_offset at entry=1048576)
    at stmem.cc:83
        __FUNCTION__ = "freeDataUpto"
        theStart = 0x5555595d57e0
#4  0x00005555557477f1 in MemObject::trimUnSwappable (this=0x55555957c9e0)
    at MemObject.cc:400
        new_mem_lo = 1048576
#5  0x0000555555831b69 in StoreEntry::trimMemory (
    this=this at entry=0x5555589d7d80, 
    preserveSwappable=preserveSwappable at entry=false) at store.cc:1816
        __FUNCTION__ = "trimMemory"
#6  0x0000555555a55765 in Store::Controller::memoryOut (this=<optimized out>, 
    e=..., preserveSwappable=<optimized out>) at Controller.cc:600
        keepInLocalMemory = false
        __FUNCTION__ = "memoryOut"
#7  0x00005555558419ff in StoreEntry::swapOut (this=0x5555589d7d80)
    at store_swapout.cc:168
        weAreOrMayBeSwappingOut = false
        __FUNCTION__ = "swapOut"
        lowest_offset = <optimized out>
        swapout_maxsize = <optimized out>
#8  0x000055555583bd2f in StoreEntry::invokeHandlers (
    this=this at entry=0x5555589d7d80) at store_client.cc:834
        __FUNCTION__ = "invokeHandlers"
        i = <optimized out>
        sc = <optimized out>
        nx = <optimized out>
        node = <optimized out>
        savedContext = {
          p_ = 0x5555558e67cc
     <UnitFileNameHashCacher(char const*, FileNameHasher*)>
        }
#9  0x0000555555832aac in StoreEntry::write (this=0x5555589d7d80, 
    writeBuffer=...) at store.cc:784
        __FUNCTION__ = "write"
#10 0x000055555588804c in Client::storeReplyBody (
    this=this at entry=0x555558d1e3d8, 
    data=data at entry=0x555559599540 "7\030\253\\W\027\306\377\273EM\265\326\236b\226\071\343pSv\331\342\022\030\266Y\n\020\066\314\344+\031N\346\367\205\276C#6N\227\254l\016rn@\262\367\017\212\070\367\307\350\223\360yK\236\237\a\002V\201\316\310\372\225\263+\254R\\\t\267\255\327\234\334\375\233\265\322\235\215I\214\355g\243\031\344\afth\262D\210\204\276\b@\363g\251\353\334e\034\240\217`q\022mV\243\063uB\345\332\341\233\256\333V\261;^.\352\027\365k\273\362\341g\220\002\341\237\240o\254z\373\066\211\036\016YgN\311\240\251\070\273\341\023\252\033e\020\365\200\026\316\331\ntT\017\246\217\251\346\203d\372\361\250\371b\335\310\354\062\361J\225\060\223"..., len=len at entry=7140) at ../../src/StoreIOBuffer.h:23
No locals.
#11 0x000055555588808b in Client::addVirginReplyBody (
    this=this at entry=0x555558d1e3d8, 
    data=0x555559599540 "7\030\253\\W\027\306\377\273EM\265\326\236b\226\071\343pSv\331\342\022\030\266Y\n\020\066\314\344+\031N\346\367\205\276C#6N\227\254l\016rn@\262\367\017\212\070\367\307\350\223\360yK\236\237\a\002V\201\316\310\372\225\263+\254R\\\t\267\255\327\234\334\375\233\265\322\235\215I\214\355g\243\031\344\afth\262D\210\204\276\b@\363g\251\353\334e\034\240\217`q\022mV\243\063uB\345\332\341\233\256\333V\261;^.\352\027\365k\273\362\341g\220\002\341\237\240o\254z\373\066\211\036\016YgN\311\240\251\070\273\341\023\252\033e\020\365\200\026\316\331\ntT\017\246\217\251\346\203d\372\361\250\371b\335\310\354\062\361J\225\060\223"..., len=len at entry=7140) at Client.cc:1049
No locals.
#12 0x00005555557e9dd6 in HttpStateData::writeReplyBody (
    this=this at entry=0x555558d1e3d8) at http.cc:1415
        data = <optimized out>
        len = 7140
        clen = 0
        parsedWhole = <optimized out>
#13 0x00005555557ede3a in HttpStateData::processReplyBody (
    this=0x555558d1e3d8) at http.cc:1498
        __FUNCTION__ = "processReplyBody"
#14 0x00005555557f1015 in HttpStateData::processReply (
    this=this at entry=0x555558d1e3d8) at http.cc:1295
        __FUNCTION__ = "processReply"
#15 0x00005555557f208a in HttpStateData::readReply (this=0x555558d1e3d8, 
    io=...) at http.cc:1265
        __FUNCTION__ = "readReply"
        rd = {
          <CommCommonCbParams> = {
            data = 0x555558d1e3d8,
            conn = {
              p_ = 0x555559314a80
            },
            flag = Comm::OK,
            xerrno = 0,
            fd = -1
          }, 
          members of CommIoCbParams:
          buf = 0x0,
          size = 7140
        }
#16 0x00005555557f782c in CommCbMemFunT<HttpStateData, CommIoCbParams>::doDial
    (this=0x555559293c48) at CommCalls.h:190
No locals.
#17 0x00005555557f748f in JobDialer<HttpStateData>::dial (
    this=0x555559293c48, call=...) at base/AsyncJobCalls.h:170
        __FUNCTION__ = "dial"
#18 0x00005555557f773e in AsyncCallT<CommCbMemFunT<HttpStateData, CommIoCbParams> >::fire (this=<optimized out>) at ../src/base/AsyncCall.h:147
No locals.
#19 0x00005555558e4f4e in AsyncCall::make (this=0x555559293c10)
    at AsyncCall.cc:44
        __FUNCTION__ = "make"
#20 0x00005555558e69cc in AsyncCallQueue::fire (this=0x555555d9b410)
    at ../../src/base/RefCount.h:73
        call = {
          p_ = 0x555559293c10
        }
        made = true
        __FUNCTION__ = "fire"
#21 0x0000555555710e93 in EventLoop::dispatchCalls (
    this=this at entry=0x7fffffffe940) at EventLoop.cc:144
        dispatchedSome = <optimized out>
#22 0x0000555555710f86 in EventLoop::runOnce (this=this at entry=0x7fffffffe940)
    at EventLoop.cc:121
        sawActivity = <optimized out>
        waitingEngine = 0x7fffffffe860
        __FUNCTION__ = <optimized out>
#23 0x0000555555710ff1 in EventLoop::run (this=0x7fffffffe940)
    at EventLoop.cc:83
No locals.
#24 0x0000555555805a58 in SquidMain (argc=<optimized out>, 
    argv=<optimized out>) at main.cc:1710
        cmdLine = {
          argv_ = std::vector of length 3, capacity 3 = {
            0x555555cc7870 "/usr/sbin/squid", 0x555555cc7890 "-NsYC", 0x0},
          shortOptions_ = 0x555555cc7820 "CDFNRSYXa:d:f:hk:m::n:sl:u:vz?",
          longOptions_ = std::vector of length 5, capacity 8 = {{
              <option> = {
                name = 0x555555cc7970 "foreground",
                has_arg = 0,
                flag = 0x0,
                val = 2
              }, <No data fields>}, {
              <option> = {
                name = 0x555555cc7b70 "kid",
                has_arg = 1,
                flag = 0x0,
                val = 3
              }, <No data fields>}, {
              <option> = {
                name = 0x555555cc7b90 "help",
                has_arg = 0,
                flag = 0x0,
                val = 104
              }, <No data fields>}, {
              <option> = {
                name = 0x555555cc7bb0 "version",
                has_arg = 0,
                flag = 0x0,
                val = 118
              }, <No data fields>}, {
              <option> = {
                name = 0x0,
                has_arg = 0,
                flag = 0x0,
                val = 0
              }, <No data fields>}}
        }
        WIN32_init_err = 0
        __FUNCTION__ = "SquidMain"
        mainLoop = {
          errcount = 0,
          static Running = 0x7fffffffe940,
          last_loop = false,
          engines = std::vector of length 4, capacity 4 = {0x7fffffffe820, 
            0x555555c13760 <EventScheduler::_instance>, 0x7fffffffe840, 
            0x7fffffffe860},
          timeService = 0x7fffffffe880,
          primaryEngine = 0x7fffffffe860,
          loop_delay = 0,
          error = false,
          runOnceResult = false
        }
        signalEngine = {
          <AsyncEngine> = {
            _vptr.AsyncEngine = 0x555555b75138 <vtable for SignalEngine+16>
          }, <No data fields>}
        store_engine = {
          <AsyncEngine> = {
            _vptr.AsyncEngine = 0x555555b75110 <vtable for StoreRootEngine+16>
          }, <No data fields>}
        comm_engine = {
          <AsyncEngine> = {
            _vptr.AsyncEngine = 0x555555b84c08 <vtable for CommSelectEngine+16>
          }, <No data fields>}
        time_engine = {
          _vptr.Engine = 0x555555b93ac8 <vtable for Time::Engine+16>
        }
#25 0x000055555580603a in SquidMainSafe (argv=0x7fffffffed48, argc=2)
    at main.cc:1353
        __FUNCTION__ = <optimized out>
        _dbg_level = <optimized out>
        _dbo = <optimized out>
#26 main (argc=2, argv=0x7fffffffed48) at main.cc:1341
No locals.
Saved corefile core.4053617
A debugging session is active.

	Inferior 1 [process 4053617] will be killed.

Quit anyway? (y or n) [answered Y; input not from terminal]


and yet another crash:
======================

Reading symbols from /usr/sbin/squid...
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".

Program received signal SIGABRT, Aborted.
__GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#0  __GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
        set = {
          __val = {0, 115, 60701581386976, 3007948225109730816, 1, 
            3007948225109730816, 93825000044944, 140737488346944, 
            93825000045032, 140737488346992, 93824997712448, 93824995977164, 
            93825145171800, 140737344738147, 206158430240, 140737488346848}
        }
        pid = <optimized out>
        tid = <optimized out>
        ret = <optimized out>
#1  0x00007ffff7613859 in __GI_abort () at abort.c:79
        save_stage = 1
        act = {
          __sigaction_handler = {
            sa_handler = 0x55555e72ef58,
            sa_sigaction = 0x55555e72ef58
          },
          sa_mask = {
            __val = {93824997144201, 47, 1698047947, 163403, 0, 
              93824997779200, 93825145171800, 93825150253856, 
              3007948225109730816, 115, 93825000044944, 93825000113656, 
              93824997147760, 93825000113656, 93824997143224, 93825000113656}
          },
          sa_flags = 1416537600,
          sa_restorer = 0x555555a8e4e0
        }
        sigs = {
          __val = {32, 0 <repeats 15 times>}
        }
#2  0x0000555555a03343 in xassert (
    msg=msg at entry=0x555555a8e4e0 "lowestOffset () <= target_offset", 
    file=file at entry=0x555555a8e240 "stmem.cc", line=line at entry=98)
    at debug.cc:1269
        __FUNCTION__ = <optimized out>
#3  0x000055555582a2ea in mem_hdr::freeDataUpto (
    this=this at entry=0x55555eb698e8, target_offset=target_offset at entry=2097152)
    at stmem.cc:83
        __FUNCTION__ = "freeDataUpto"
        theStart = 0x55555ec07a70
#4  0x00005555557477f1 in MemObject::trimUnSwappable (this=0x55555eb698c0)
    at MemObject.cc:400
        new_mem_lo = 2097152
#5  0x0000555555831b69 in StoreEntry::trimMemory (
    this=this at entry=0x555558989360, 
    preserveSwappable=preserveSwappable at entry=false) at store.cc:1816
        __FUNCTION__ = "trimMemory"
#6  0x0000555555a55765 in Store::Controller::memoryOut (this=<optimized out>, 
    e=..., preserveSwappable=<optimized out>) at Controller.cc:600
        keepInLocalMemory = false
        __FUNCTION__ = "memoryOut"
#7  0x00005555558419ff in StoreEntry::swapOut (this=0x555558989360)
    at store_swapout.cc:168
        weAreOrMayBeSwappingOut = false
        __FUNCTION__ = "swapOut"
        lowest_offset = <optimized out>
        swapout_maxsize = <optimized out>
#8  0x000055555583bd2f in StoreEntry::invokeHandlers (
    this=this at entry=0x555558989360) at store_client.cc:834
        __FUNCTION__ = "invokeHandlers"
        i = <optimized out>
        sc = <optimized out>
        nx = <optimized out>
        node = <optimized out>
        savedContext = {
          p_ = 0x5555558e67cc
     <UnitFileNameHashCacher(char const*, FileNameHasher*)>
        }
#9  0x0000555555832aac in StoreEntry::write (this=0x555558989360, 
    writeBuffer=...) at store.cc:784
        __FUNCTION__ = "write"
#10 0x000055555588804c in Client::storeReplyBody (
    this=this at entry=0x555558aee1f8, 
    data=data at entry=0x55555ec07ba0 "\245N\313\343Q\334M8t\365\356\341\f\177O\257\242\376\240\031\341\317\022Gh\243\324\034\211\273\317\037\f\353XQN\034\325\312\355\330\337\251y\021\335L\266N\342\071<7\215\230\234\300\225\343\316\320\221\271\316\020IT\335f\"I\302}\236\301\206}\325\r\243\232\336\247\v\277\360H\352\026@\005\356\227\204\267\206\036\361\245\357y?k\310T\324\023h\325\304#t\vB\352\273\005\253\331a\027`+\217!i\331=\374\356V\310\224\327\336\336A\035>\322\377\250q\350\207\v\030:\341\n\f]\311'?w^$\vg\024\067\374\263'\352\347)p\230\024\217\036\270b\023\320\025\066\021Z7\230\217\006n\300\314a,\304.w\337\367\332\304\333o"..., len=len at entry=12080) at ../../src/StoreIOBuffer.h:23
No locals.
#11 0x000055555588808b in Client::addVirginReplyBody (
    this=this at entry=0x555558aee1f8, 
    data=0x55555ec07ba0 "\245N\313\343Q\334M8t\365\356\341\f\177O\257\242\376\240\031\341\317\022Gh\243\324\034\211\273\317\037\f\353XQN\034\325\312\355\330\337\251y\021\335L\266N\342\071<7\215\230\234\300\225\343\316\320\221\271\316\020IT\335f\"I\302}\236\301\206}\325\r\243\232\336\247\v\277\360H\352\026@\005\356\227\204\267\206\036\361\245\357y?k\310T\324\023h\325\304#t\vB\352\273\005\253\331a\027`+\217!i\331=\374\356V\310\224\327\336\336A\035>\322\377\250q\350\207\v\030:\341\n\f]\311'?w^$\vg\024\067\374\263'\352\347)p\230\024\217\036\270b\023\320\025\066\021Z7\230\217\006n\300\314a,\304.w\337\367\332\304\333o"..., 
    len=len at entry=12080) at Client.cc:1049
No locals.
#12 0x00005555557e9dd6 in HttpStateData::writeReplyBody (
    this=this at entry=0x555558aee1f8) at http.cc:1415
        data = <optimized out>
        len = 12080
        clen = 93825148988456
        parsedWhole = <optimized out>
#13 0x00005555557ede3a in HttpStateData::processReplyBody (
    this=0x555558aee1f8) at http.cc:1498
        __FUNCTION__ = "processReplyBody"
#14 0x00005555557f1015 in HttpStateData::processReply (
    this=this at entry=0x555558aee1f8) at http.cc:1295
        __FUNCTION__ = "processReply"
#15 0x00005555557f208a in HttpStateData::readReply (this=0x555558aee1f8, 
    io=...) at http.cc:1265
        __FUNCTION__ = "readReply"
        rd = {
          <CommCommonCbParams> = {
            data = 0x555558aee1f8,
            conn = {
              p_ = 0x55555eb588d0
            },
            flag = Comm::OK,
            xerrno = 0,
            fd = -1
          }, 
          members of CommIoCbParams:
          buf = 0x0,
          size = 12080
        }
#16 0x00005555557f782c in CommCbMemFunT<HttpStateData, CommIoCbParams>::doDial
    (this=0x55555eadc0a8) at CommCalls.h:190
No locals.
#17 0x00005555557f748f in JobDialer<HttpStateData>::dial (
    this=0x55555eadc0a8, call=...) at base/AsyncJobCalls.h:170
        __FUNCTION__ = "dial"
#18 0x00005555557f773e in AsyncCallT<CommCbMemFunT<HttpStateData, CommIoCbParams> >::fire (this=<optimized out>) at ../src/base/AsyncCall.h:147
No locals.
#19 0x00005555558e4f4e in AsyncCall::make (this=0x55555eadc070)
    at AsyncCall.cc:44
        __FUNCTION__ = "make"
#20 0x00005555558e69cc in AsyncCallQueue::fire (this=0x555555d9b410)
    at ../../src/base/RefCount.h:73
        call = {
          p_ = 0x55555eadc070
        }
        made = true
        __FUNCTION__ = "fire"
#21 0x0000555555710e93 in EventLoop::dispatchCalls (
    this=this at entry=0x7fffffffe940) at EventLoop.cc:144
        dispatchedSome = <optimized out>
#22 0x0000555555710f86 in EventLoop::runOnce (this=this at entry=0x7fffffffe940)
    at EventLoop.cc:121
        sawActivity = <optimized out>
        waitingEngine = 0x7fffffffe860
        __FUNCTION__ = <optimized out>
#23 0x0000555555710ff1 in EventLoop::run (this=0x7fffffffe940)
    at EventLoop.cc:83
No locals.
#24 0x0000555555805a58 in SquidMain (argc=<optimized out>, 
    argv=<optimized out>) at main.cc:1710
        cmdLine = {
          argv_ = std::vector of length 3, capacity 3 = {
            0x555555cc7870 "/usr/sbin/squid", 0x555555cc7890 "-NsYC", 0x0},
          shortOptions_ = 0x555555cc7820 "CDFNRSYXa:d:f:hk:m::n:sl:u:vz?",
          longOptions_ = std::vector of length 5, capacity 8 = {{
              <option> = {
                name = 0x555555cc7970 "foreground",
                has_arg = 0,
                flag = 0x0,
                val = 2
              }, <No data fields>}, {
              <option> = {
                name = 0x555555cc7b70 "kid",
                has_arg = 1,
                flag = 0x0,
                val = 3
              }, <No data fields>}, {
              <option> = {
                name = 0x555555cc7b90 "help",
                has_arg = 0,
                flag = 0x0,
                val = 104
              }, <No data fields>}, {
              <option> = {
                name = 0x555555cc7bb0 "version",
                has_arg = 0,
                flag = 0x0,
                val = 118
              }, <No data fields>}, {
              <option> = {
                name = 0x0,
                has_arg = 0,
                flag = 0x0,
                val = 0
              }, <No data fields>}}
        }
        WIN32_init_err = 0
        __FUNCTION__ = "SquidMain"
        mainLoop = {
          errcount = 0,
          static Running = 0x7fffffffe940,
          last_loop = false,
          engines = std::vector of length 4, capacity 4 = {0x7fffffffe820, 
            0x555555c13760 <EventScheduler::_instance>, 0x7fffffffe840, 
            0x7fffffffe860},
          timeService = 0x7fffffffe880,
          primaryEngine = 0x7fffffffe860,
          loop_delay = 0,
          error = false,
          runOnceResult = false
        }
        signalEngine = {
          <AsyncEngine> = {
            _vptr.AsyncEngine = 0x555555b75138 <vtable for SignalEngine+16>
          }, <No data fields>}
        store_engine = {
          <AsyncEngine> = {
            _vptr.AsyncEngine = 0x555555b75110 <vtable for StoreRootEngine+16>
          }, <No data fields>}
        comm_engine = {
          <AsyncEngine> = {
            _vptr.AsyncEngine = 0x555555b84c08 <vtable for CommSelectEngine+16>
          }, <No data fields>}
        time_engine = {
          _vptr.Engine = 0x555555b93ac8 <vtable for Time::Engine+16>
        }
#25 0x000055555580603a in SquidMainSafe (argv=0x7fffffffed48, argc=2)
    at main.cc:1353
        __FUNCTION__ = <optimized out>
        _dbg_level = <optimized out>
        _dbo = <optimized out>
#26 main (argc=2, argv=0x7fffffffed48) at main.cc:1341
No locals.
Saved corefile core.4053842
A debugging session is active.

	Inferior 1 [process 4053842] will be killed.

Quit anyway? (y or n) [answered Y; input not from terminal]

-- 
Ralf Hildebrandt
Charité - Universitätsmedizin Berlin
Geschäftsbereich IT | Abteilung Netz | Netzwerk-Administration
Invalidenstraße 120/121 | D-10115 Berlin

Tel. +49 30 450 570 155
ralf.hildebrandt at charite.de
https://www.charite.de


More information about the squid-users mailing list