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

classic Classic list List threaded Threaded
9 messages Options
Reply | Threaded
Open this post in threaded view
|

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

Matus UHLAR - fantomas
Hello,

related to http://bugs.squid-cache.org/show_bug.cgi?id=4977

    (In reply to Matus UHLAR - fantomas from comment #12)
    > We notice the same problem after few minutes running squid 4.6 (debian 10,
    > x86_64):
    >
    > 2019/10/02 05:00:53 kid1| assertion failed: stmem.cc:98: "lowestOffset () <=
    > target_offset"

    (In reply to Matus UHLAR - fantomas from comment #14)
    > I would like to note that we have no SSL support and no header modification
    > besides "forwarded_for delete"

    This bug report was about adaptation (or, more precisely, new adapted message
    creation) triggering the above assertion. It sounds like your environment is
    very different -- no new messages are created. The bug may or may not be the
    same, of course.

    Can you reproduce the bug with specific message(s), on demand?

I could try to reproduce by using newer squid, hoping the customer won't get
very angry.  I would need some hints on what more to watch for and what more
to log. (debug options probably)

--
Matus UHLAR - fantomas, [hidden email] ; 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.
- Holmes, what kind of school did you study to be a detective?
- Elementary, Watkins.  -- Daffy Duck & Porky Pig
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

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

Matus UHLAR - fantomas
On 02.10.19 16:22, Matus UHLAR - fantomas wrote:

>related to http://bugs.squid-cache.org/show_bug.cgi?id=4977
>
>   (In reply to Matus UHLAR - fantomas from comment #12)
>   > We notice the same problem after few minutes running squid 4.6 (debian 10,
>   > x86_64):
>   >
>   > 2019/10/02 05:00:53 kid1| assertion failed: stmem.cc:98: "lowestOffset () <=
>   > target_offset"
>
>   (In reply to Matus UHLAR - fantomas from comment #14)
>   > I would like to note that we have no SSL support and no header modification
>   > besides "forwarded_for delete"
>
>   This bug report was about adaptation (or, more precisely, new adapted message
>   creation) triggering the above assertion. It sounds like your environment is
>   very different -- no new messages are created. The bug may or may not be the
>   same, of course.
>
>   Can you reproduce the bug with specific message(s), on demand?
>
>I could try to reproduce by using newer squid, hoping the customer won't get
>very angry.  I would need some hints on what more to watch for and what more
>to log. (debug options probably)

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?

--
Matus UHLAR - fantomas, [hidden email] ; 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.
Windows found: (R)emove, (E)rase, (D)elete
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

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

Alex Rousskov
On 10/2/19 10:50 AM, Matus UHLAR - fantomas wrote:
> On 02.10.19 16:22, Matus UHLAR - fantomas wrote:
>> http://bugs.squid-cache.org/show_bug.cgi?id=4977

> 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?

cache.log with debug_options set to just "ALL,1" (or default), right?

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.

Alex.
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

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

Matus UHLAR - fantomas
>> 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@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@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, [hidden email] ; 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
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

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

Alex Rousskov
On 11/4/19 11:21 AM, Matus UHLAR - fantomas wrote:
> the last request:
>
> CONNECT www.google.com:443 HTTP/1.1
> Host: www.google.com


That request does not seem to match the stack trace: The stack trace
points to a non-CONNECT transaction AFAICT. Perhaps you are bumping that
tunnel? Please note that you are not looking for the last request, but
for the request that triggered the assertion. It is very difficult to do
that with just ALL,2 and stripped executable, especially when you have
lots of concurrent transactions flying by.


Alex.



> ----------
> 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@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@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?)
>

_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

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

Matus UHLAR - fantomas
>On 11/4/19 11:21 AM, Matus UHLAR - fantomas wrote:
>> the last request:
>>
>> CONNECT www.google.com:443 HTTP/1.1
>> Host: www.google.com

On 04.11.19 12:13, Alex Rousskov wrote:
>That request does not seem to match the stack trace: The stack trace
>points to a non-CONNECT transaction AFAICT.

Oh, yes, may be caused by other GET request fetching from cache or storing
to cache (doesn't happen wich cache disabled).

> Perhaps you are bumping that
>tunnel? Please note that you are not looking for the last request, but
>for the request that triggered the assertion. It is very difficult to do
>that with just ALL,2 and stripped executable, especially when you have
>lots of concurrent transactions flying by.

No bumping. I can create unstripped executable (great if it works with
current core, but I may create new one).


>> ----------
>> 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@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@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, [hidden email] ; 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.
"Where do you want to go to die?" [Microsoft]
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

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

Matus UHLAR - fantomas
>On 04.11.19 12:13, Alex Rousskov wrote:
>>That request does not seem to match the stack trace: The stack trace
>>points to a non-CONNECT transaction AFAICT.
>
>Oh, yes, may be caused by other GET request fetching from cache or storing
>to cache (doesn't happen wich cache disabled).
>
>>Perhaps you are bumping that
>>tunnel? Please note that you are not looking for the last request, but
>>for the request that triggered the assertion. It is very difficult to do
>>that with just ALL,2 and stripped executable, especially when you have
>>lots of concurrent transactions flying by.

On 04.11.19 18:59, Matus UHLAR - fantomas wrote:
>No bumping. I can create unstripped executable (great if it works with
>current core, but I may create new one).

I didn't know about debian archive for debug symbols. Now I have full
backtrace, hopefully:

(gdb) backtrace
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007f93a15b2535 in __GI_abort () at abort.c:79
#2  0x00005654ebcee5ad in xassert (msg=msg@entry=0x5654ec133290 "lowestOffset () <= target_offset", file=file@entry=0x5654ec133043 "stmem.cc", line=line@entry=98) at debug.cc:618
#3  0x00005654ebe6c170 in mem_hdr::freeDataUpto (this=this@entry=0x5654f6c11988, target_offset=target_offset@entry=0) at stmem.cc:39
#4  0x00005654ebe27440 in MemObject::trimSwappable (this=0x5654f6c11950) at MemObject.cc:400
#5  0x00005654ebe74bf5 in StoreEntry::trimMemory (this=0x5654edd697b0, preserveSwappable=<optimized out>) at store.cc:1902
#6  0x00005654ec100a80 in Store::Controller::memoryOut (this=<optimized out>, e=..., preserveSwappable=<optimized out>) at Controller.cc:557
#7  0x00005654ebe84305 in StoreEntry::swapOut (this=0x5654edd697b0) at store_swapout.cc:185
#8  0x00005654ebe7b3fd in StoreEntry::invokeHandlers (this=this@entry=0x5654edd697b0) at store_client.cc:719
#9  0x00005654ebe736ac in StoreEntry::write (this=0x5654edd697b0, writeBuffer=...) at store.cc:836
#10 0x00005654ebf0a590 in Client::storeReplyBody (this=this@entry=0x5654f15e4d88,
    data=0x5654f5a21f70 "A\336{\t,8K\246\353\257=\"r\r\210\375u\254\061\016\301\001\t\255\265\206\030h\350`a\300Kd\002\222k\354\247\016@3m\211v\204\227rdL\030\006\026j\024\002XXM\240R)\343kƔ\017\222\261\367X\033\234:\204\242\315\032\205\020\032*Zm鲜\273\272\361\060\310j\276\217o\364m\377O\375\006&Ԏ", len=len@entry=1400) at ../../src/StoreIOBuffer.h:23
#11 0x00005654ebf0a5d3 in Client::addVirginReplyBody (this=this@entry=0x5654f15e4d88, data=<optimized out>, len=len@entry=1400) at Client.cc:1005
#12 0x00005654ebdeca37 in HttpStateData::writeReplyBody (this=0x5654f15e4d88) at http.cc:1359
#13 0x00005654ebdf1bd5 in HttpStateData::processReplyBody (this=0x5654f15e4d88) at http.cc:1424
#14 0x00005654ebdf382a in HttpStateData::processReply (this=0x5654f15e4d88) at http.cc:1251
#15 0x00005654ebdf4da8 in HttpStateData::readReply (this=0x5654f15e4d88, io=...) at http.cc:1223
#16 0x00005654ebdf8d6b in JobDialer<HttpStateData>::dial (this=0x5654f281c0f0, call=...) at base/AsyncJobCalls.h:169
#17 0x00005654ebf5be51 in AsyncCall::make (this=this@entry=0x5654f281c0c0) at AsyncCall.cc:40
#18 0x00005654ebf5d3a4 in AsyncCallQueue::fireNext (this=<optimized out>) at AsyncCallQueue.cc:56
#19 0x00005654ebf5d6e9 in AsyncCallQueue::fire (this=0x5654ed4cdc40) at AsyncCallQueue.cc:42
#20 0x00005654ebdb98ea in EventLoop::dispatchCalls (this=0x7ffcde3afba0) at EventLoop.cc:144
#21 EventLoop::runOnce (this=this@entry=0x7ffcde3afba0) at EventLoop.cc:121
#22 0x00005654ebdb99d8 in EventLoop::run (this=this@entry=0x7ffcde3afba0) at EventLoop.cc:83
#23 0x00005654ebe22ab9 in SquidMain (argc=<optimized out>, argv=<optimized out>) at main.cc:1707
#24 0x00005654ebd13901 in SquidMainSafe (argv=0x7ffcde3b0008, argc=6) at main.cc:1415
#25 main (argc=6, argv=0x7ffcde3b0008) at main.cc:1403

--
Matus UHLAR - fantomas, [hidden email] ; 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.
You have the right to remain silent. Anything you say will be misquoted,
then used against you.
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

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

Alex Rousskov
On 11/5/19 4:34 AM, Matus UHLAR - fantomas wrote:

> Now I have full backtrace, hopefully:

You are making progress, but the backtrace itself is not sufficient. One
has to examine the core dump to find out transaction details (e.g., the
URL) _and_ log enough of those details into cache.log (usually at levels
much higher than ALL,2) to restore Squid state and figure out what is
going on or build a reliable reproducer. Sorry if I was not clear about
that from the start.

It does take time and some expertise to figure out what is going on.
Unfortunately, I cannot personally guide you through this painful
process right now.

Alex.


> (gdb) backtrace
> #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
> #1  0x00007f93a15b2535 in __GI_abort () at abort.c:79
> #2  0x00005654ebcee5ad in xassert (msg=msg@entry=0x5654ec133290
> "lowestOffset () <= target_offset", file=file@entry=0x5654ec133043
> "stmem.cc", line=line@entry=98) at debug.cc:618
> #3  0x00005654ebe6c170 in mem_hdr::freeDataUpto
> (this=this@entry=0x5654f6c11988, target_offset=target_offset@entry=0) at
> stmem.cc:39
> #4  0x00005654ebe27440 in MemObject::trimSwappable (this=0x5654f6c11950)
> at MemObject.cc:400
> #5  0x00005654ebe74bf5 in StoreEntry::trimMemory (this=0x5654edd697b0,
> preserveSwappable=<optimized out>) at store.cc:1902
> #6  0x00005654ec100a80 in Store::Controller::memoryOut (this=<optimized
> out>, e=..., preserveSwappable=<optimized out>) at Controller.cc:557
> #7  0x00005654ebe84305 in StoreEntry::swapOut (this=0x5654edd697b0) at
> store_swapout.cc:185
> #8  0x00005654ebe7b3fd in StoreEntry::invokeHandlers
> (this=this@entry=0x5654edd697b0) at store_client.cc:719
> #9  0x00005654ebe736ac in StoreEntry::write (this=0x5654edd697b0,
> writeBuffer=...) at store.cc:836
> #10 0x00005654ebf0a590 in Client::storeReplyBody
> (this=this@entry=0x5654f15e4d88,
>    data=0x5654f5a21f70 "A\336{\t,8K\246\353\257=\"r\r\210\375u\254\061
> \016\301\001\t\255\265\206\030h\350`a\300Kd\002\222k\354\247\016@3m\211v
> \204\227rdL\030\006\026j\024\002XXM\240R)\343kƔ\017\222\261\367X\033
> \234:\204\242\315\032\205\020\032*Zm鲜\273\272\361\060\310j\276\217o
> \364m\377O\375\006&Ԏ", len=len@entry=1400) at ../../src/StoreIOBuffer.h:23
> #11 0x00005654ebf0a5d3 in Client::addVirginReplyBody
> (this=this@entry=0x5654f15e4d88, data=<optimized out>,
> len=len@entry=1400) at Client.cc:1005
> #12 0x00005654ebdeca37 in HttpStateData::writeReplyBody
> (this=0x5654f15e4d88) at http.cc:1359
> #13 0x00005654ebdf1bd5 in HttpStateData::processReplyBody
> (this=0x5654f15e4d88) at http.cc:1424
> #14 0x00005654ebdf382a in HttpStateData::processReply
> (this=0x5654f15e4d88) at http.cc:1251
> #15 0x00005654ebdf4da8 in HttpStateData::readReply (this=0x5654f15e4d88,
> io=...) at http.cc:1223
> #16 0x00005654ebdf8d6b in JobDialer<HttpStateData>::dial
> (this=0x5654f281c0f0, call=...) at base/AsyncJobCalls.h:169
> #17 0x00005654ebf5be51 in AsyncCall::make
> (this=this@entry=0x5654f281c0c0) at AsyncCall.cc:40
> #18 0x00005654ebf5d3a4 in AsyncCallQueue::fireNext (this=<optimized
> out>) at AsyncCallQueue.cc:56
> #19 0x00005654ebf5d6e9 in AsyncCallQueue::fire (this=0x5654ed4cdc40) at
> AsyncCallQueue.cc:42
> #20 0x00005654ebdb98ea in EventLoop::dispatchCalls (this=0x7ffcde3afba0)
> at EventLoop.cc:144
> #21 EventLoop::runOnce (this=this@entry=0x7ffcde3afba0) at EventLoop.cc:121
> #22 0x00005654ebdb99d8 in EventLoop::run
> (this=this@entry=0x7ffcde3afba0) at EventLoop.cc:83
> #23 0x00005654ebe22ab9 in SquidMain (argc=<optimized out>,
> argv=<optimized out>) at main.cc:1707
> #24 0x00005654ebd13901 in SquidMainSafe (argv=0x7ffcde3b0008, argc=6) at
> main.cc:1415
> #25 main (argc=6, argv=0x7ffcde3b0008) at main.cc:1403
>

_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

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

Matus UHLAR - fantomas
>On 11/5/19 4:34 AM, Matus UHLAR - fantomas wrote:
>> Now I have full backtrace, hopefully:

On 05.11.19 09:10, Alex Rousskov wrote:

>You are making progress, but the backtrace itself is not sufficient. One
>has to examine the core dump to find out transaction details (e.g., the
>URL) _and_ log enough of those details into cache.log (usually at levels
>much higher than ALL,2) to restore Squid state and figure out what is
>going on or build a reliable reproducer. Sorry if I was not clear about
>that from the start.
>
>It does take time and some expertise to figure out what is going on.
>Unfortunately, I cannot personally guide you through this painful
>process right now.

I understand.

Luckily, the problem turned out to be because of squid bug #4823 reported in
debian bug #943692 (when searching month ago, debian bug didn't exist and I
haven't found squid bug that time).

hopefully the mentioed patch is safe in squid 4.6 (I have applied it and it
seems so).

hopefully we can close this thread now.
--
Matus UHLAR - fantomas, [hidden email] ; 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.
I wonder how much deeper the ocean would be without sponges.
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users