[squid-users] Fw: [Bug 4977] stmem.cc:98: "lowestOffset () <= target_offset" assertion when adapting Content-Range value

Mon Nov 4 16:21:21 UTC 2019

>> On 02.10.19 16:22, Matus UHLAR - fantomas wrote:
>>> http://bugs.squid-cache.org/show_bug.cgi?id=4977

>On 10/2/19 10:50 AM, Matus UHLAR - fantomas wrote:
>> OK, now I've got 1.7G pcap,  2.8M access.log (22k requests) and cache.log
>> saying when did the problem appear.
>> Any idea what to search for?

On 02.10.19 13:48, Alex Rousskov wrote:
>cache.log with debug_options set to just "ALL,1" (or default), right?

I have raqised it to ALL,2

>I cannot give you specific instructions, but you can try to find the
>transaction that caused the crash by correlating packet capture with the
>timing of the crash. If you are lucky, the transaction would not be
>encrypted and will have few other transactions nearby. In that case, we
>may be able to learn something from the transaction bytes received and
>sent by Squid.

I have new cache.log with debugging, new pcap file, and core (didn't have
before) backed up (/var/tmp should last for some time):

the last request:

CONNECT www.google.com:443 HTTP/1.1
Host: www.google.com

----------
2019/11/04 16:59:09.721 kid1| 85,2| client_side_request.cc(752) clientAccessCheckDone: The request CONNECT www.google.com:443 is ALLOWED; last ACL checked: work_time1
2019/11/04 16:59:09.721 kid1| 85,2| client_side_request.cc(728) clientAccessCheck2: No adapted_http_access configuration. default: ALLOW
2019/11/04 16:59:09.721 kid1| 85,2| client_side_request.cc(752) clientAccessCheckDone: The request CONNECT www.google.com:443 is ALLOWED; last ACL checked: work_time1
2019/11/04 16:59:09.721 kid1| 44,2| peer_select.cc(281) peerSelectDnsPaths: Find IP destination for: www.google.com:443' via www.google.com
2019/11/04 16:59:09.721 kid1| 44,2| peer_select.cc(302) peerSelectDnsPaths: Found sources for 'www.google.com:443'
2019/11/04 16:59:09.721 kid1| 44,2| peer_select.cc(303) peerSelectDnsPaths:   always_direct = DENIED
2019/11/04 16:59:09.721 kid1| 44,2| peer_select.cc(304) peerSelectDnsPaths:    never_direct = DENIED
2019/11/04 16:59:09.721 kid1| 44,2| peer_select.cc(308) peerSelectDnsPaths:          DIRECT = local=[::] remote=[2a00:1450:4014:801::2004]:443 flags=1
2019/11/04 16:59:09.721 kid1| 44,2| peer_select.cc(308) peerSelectDnsPaths:          DIRECT = local=0.0.0.0 remote=216.58.201.100:443 flags=1
2019/11/04 16:59:09.721 kid1| 44,2| peer_select.cc(317) peerSelectDnsPaths:        timedout = 0
2019/11/04 16:59:09.725 kid1| 20,2| store.cc(980) checkCachable: StoreEntry::checkCachable: NO: not cachable
2019/11/04 16:59:09.727 kid1| 33,2| client_side.cc(582) swanSong: local=192.168.251.230:3128 remote=192.168.169.31:62822 flags=1
2019/11/04 16:59:09.730 kid1| 20,2| store.cc(980) checkCachable: StoreEntry::checkCachable: NO: not cachable
2019/11/04 16:59:09.730 kid1| assertion failed: stmem.cc:98: "lowestOffset () <= target_offset"

and the gdb backtrace:

Core was generated by `(squid-1) --kid squid-1 -YC -f /etc/squid/squid.conf'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50      ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
[Current thread is 1 (Thread 0x7f939ea82e80 (LWP 13179))]
(gdb) backtrace
#0  __GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007f93a15b2535 in __GI_abort () at abort.c:79
#2  0x00005654ebcee5ad in ?? ()
#3  0x00005654ebe6c170 in mem_hdr::freeDataUpto(long) ()
#4  0x00005654ebe27440 in MemObject::trimSwappable() ()
#5  0x00005654ebe74bf5 in StoreEntry::trimMemory(bool) ()
#6  0x00005654ec100a80 in Store::Controller::memoryOut(StoreEntry&, bool) ()
#7  0x00005654ebe84305 in StoreEntry::swapOut() ()
#8  0x00005654ebe7b3fd in StoreEntry::invokeHandlers() ()
#9  0x00005654ebe736ac in StoreEntry::write(StoreIOBuffer) ()
#10 0x00005654ebf0a590 in Client::storeReplyBody(char const*, long) ()
#11 0x00005654ebdeca37 in HttpStateData::writeReplyBody() ()
#12 0x00005654ebdf1bd5 in HttpStateData::processReplyBody() ()
#13 0x00005654ebdf382a in HttpStateData::processReply() ()
#14 0x00005654ebdf4da8 in HttpStateData::readReply(CommIoCbParams const&) ()
#15 0x00005654ebdf8d6b in JobDialer<HttpStateData>::dial(AsyncCall&) ()
#16 0x00005654ebf5be51 in AsyncCall::make() ()
#17 0x00005654ebf5d3a4 in AsyncCallQueue::fireNext() ()
#18 0x00005654ebf5d6e9 in AsyncCallQueue::fire() ()
#19 0x00005654ebdb98ea in EventLoop::runOnce() ()
#20 0x00005654ebdb99d8 in EventLoop::run() ()
#21 0x00005654ebe22ab9 in SquidMain(int, char**) ()
#22 0x00005654ebd13901 in main ()
(gdb)

I don't know where do those raise.c and raise.c belong (libthread? glibc?)

squid is stripped, i could probably compile it without stripping and re-try

Any ideas how to debug further? (disabling multi-cpu?)

-- 
Matus UHLAR - fantomas, uhlar at fantomas.sk ; http://www.fantomas.sk/
Warning: I wish NOT to receive e-mail advertising to this address.
Varovanie: na tuto adresu chcem NEDOSTAVAT akukolvek reklamnu postu.
How does cat play with mouse? cat /dev/mouse