> On 25. Feb 2021, at 19:08, Andriy Gapon <a...@freebsd.org> wrote:
>
> On 24/02/2021 00:40, Scheffenegger, Richard wrote:
>> Hi Andriy,
>>
>> I guess I am currently the person who has the most recent knowledge about
>> that
>> part of the base stack…
>>
>> Do you happen to have more (preceding) information about this, or a way to
>> reproduce this?
>
> Unfortunately, no. It "just happened".
> There was no unusual activity at the time of the crash.
> At least, from a user / administrator perspective.
So you did not use specific TCP stacks or congestion control modules?
>
>> Are you running any special stack (RACK, BBR) which may have switched back to
>> the base stack in the middle of a loss recovery (I suspected at one point
>> that
>> this may cause issues, potentially)?
>
> I do not have any customizations to the network stack, everything at defaults.
>
>> Or was something done with the ipfw that may have temporarily impacted a tcp
>> session?
>
> I use pf as a firewall. I did not touch it at the time of the crash.
Does pf change the packets?
>
>> The accounting with sack_bytes_rexmit is rather old, and not touched recently
>> (but the sackhint struct was changed recently, and other/additional
>> scoreboard
>> accounting was added).
>>
>> (kgdb) p *cur
>> $1 = {start = 3846347980, end = 3846352300, rxmit = 3846352300, scblink =
>> {tqe_next = 0xfffff8013da5a220, tqe_prev = 0xfffff80754818930}}
>>
>> This indicates, that the current hole in the SACK scoreboard (3 segments of
>> size
>> 1440 bytes) were retransmitted (rxmit == end), before the current
>> acknowledgement came back.
>>
>> Thus the expectation is, that sackhint.sack_bytes_rexmit also has a value of
>> at
>> least that number of bytes (4320). It is increased in tcp_output() for each
>> packet leaving while performing a retransmission.
>>
>> But this is the peculiar part:
>>
>> (kgdb) p tp@entry->sackhint.sack_bytes_rexmit
>> $3 = -1440
>>
>> Indicating negative one packet had been retransmitted before (thus
>> subtracting
>> the hole, which was previously retransmitted violates the invariant). And the
>> only piece of code decrementing it appears to be in tcp_output() during
>> non-permanent error handling…
>>
>> All updates to sackhint should be protected by the INPLOCK, so even if the rx
>> and tx paths are running on different core, the sack_bytes_rexmit should
>> never
>> become negative.
>>
>> The sack blocks returned indicate that (with snd.una as zero baseline, in
>> segments) the client knows about segments 2..34 and 35..47.
>>
>> The first hole has shrunk from the right (unusual; possible when two
>> retransmissions were lost again, or the 3 segment originally sent, delayed by
>> ~50 segments (unlikely).
>>
>> Sorry to not being able to spot something obvious right away…
>
> Thank you very much for the response.
> Unfortunately, I cannot help much in terms of re-creating the issue as for me
> it
> really "just happened" without me touching anything. There were just some
> HTTP(S) and SSH sessions, the usual stuff.
>
> If you need anything else from the crash dump, please let me know.
>
>> *Von:*tue...@freebsd.org <tue...@freebsd.org>
>> *Gesendet:* Dienstag, 23. Februar 2021 22:21
>> *An:* Richard Scheffenegger <rsch...@freebsd.org>
>> *Betreff:* Fwd: panic: sackhint bytes rtx >= 0
>>
>>
>>
>> *NetApp Security WARNING*: This is an external email. Do not click links or
>> open
>> attachments unless you recognize the sender and know the content is safe.
>>
>>
>>
>> FYI
>>
>>
>>
>> Begin forwarded message:
>>
>>
>>
>> *From: *Andriy Gapon <a...@freebsd.org <mailto:a...@freebsd.org>>
>>
>> *Subject: panic: sackhint bytes rtx >= 0*
>>
>> *Date: *23. February 2021 at 22:02:20 CET
>>
>> *To: *FreeBSD Current <curr...@freebsd.org <mailto:curr...@freebsd.org>>,
>> n...@freebsd.org <mailto:n...@freebsd.org>
>>
>>
>>
>>
>> Got this panic on 13.0-STABLE 4b2a20dfde9c using a custom kernel with
>> INVARIANTS
>> enabled.
>> Below is some information from the crash dump.
>> If anyone has any clues, suggestions, etc, please help.
>> I will try to help you to help me the best I can.
>>
>> #0 doadump (textdump=textdump@entry=1)
>> at /usr/devel/git/trant/sys/kern/kern_shutdown.c:399
>> #1 0xffffffff808396b2 in kern_reboot (howto=260)
>> at /usr/devel/git/trant/sys/kern/kern_shutdown.c:486
>> #2 0xffffffff80839d07 in vpanic (
>> fmt=0xffffffff80cbd551 "sackhint bytes rtx >= 0",
>> ap=0xfffffe0120b9e6d0)
>> at /usr/devel/git/trant/sys/kern/kern_shutdown.c:919
>> #3 0xffffffff808398b3 in panic (fmt=<unavailable>)
>> at /usr/devel/git/trant/sys/kern/kern_shutdown.c:843
>> #4 0xffffffff8098a82c in tcp_sack_doack (tp=<optimized out>,
>> tp@entry=0xfffff807548187f0, to=<optimized out>,
>> to@entry=0xfffffe0120b9e780, th_ack=<optimized out>)
>> at /usr/devel/git/trant/sys/netinet/tcp_sack.c:691
>> #5 0xffffffff80983699 in tcp_do_segment (m=0xfffff8029868ca00,
>> m@entry=<error reading variable: value is not available>,
>> th=<optimized out>,
>> th@entry=<error reading variable: value is not available>,
>> so=0xfffff804e7359b10,
>> so@entry=<error reading variable: value is not available>,
>> tp=0xfffff807548187f0,
>> tp@entry=<error reading variable: value is not available>,
>> drop_hdrlen=60,
>> drop_hdrlen@entry=<error reading variable: value is not available>,
>> tlen=<optimized out>,
>> tlen@entry=<error reading variable: value is not available>,
>> iptos=72 'H',
>> iptos@entry=<error reading variable: value is not available>)
>> at /usr/devel/git/trant/sys/netinet/tcp_input.c:2497
>> #6 0xffffffff80980d97 in tcp_input (mp=<optimized out>,
>> mp@entry=<error reading variable: value is not available>,
>> offp=<optimized out>,
>> offp@entry=<error reading variable: value is not available>,
>> proto=<optimized out>)
>> at /usr/devel/git/trant/sys/netinet/tcp_input.c:1381
>> #7 0xffffffff80976eb7 in ip_input (m=0x0)
>> at /usr/devel/git/trant/sys/netinet/ip_input.c:833
>> #8 0xffffffff8094c78f in netisr_dispatch_src (proto=1,
>> source=source@entry=0, m=0xfffff8029868ca00)
>> at /usr/devel/git/trant/sys/net/netisr.c:1143
>> #9 0xffffffff8094cb0e in netisr_dispatch (proto=<unavailable>,
>> m=<unavailable>) at /usr/devel/git/trant/sys/net/netisr.c:1234
>> #10 0xffffffff80943345 in ether_demux (ifp=ifp@entry=0xfffff80008c75000,
>> m=<unavailable>) at /usr/devel/git/trant/sys/net/if_ethersubr.c:923
>> #11 0xffffffff809446c1 in ether_input_internal (ifp=0xfffff80008c75000,
>> m=<unavailable>) at /usr/devel/git/trant/sys/net/if_ethersubr.c:709
>> #12 0xffffffff809443d0 in ether_nh_input (m=<unavailable>)
>> at /usr/devel/git/trant/sys/net/if_ethersubr.c:739
>> #13 0xffffffff8094c78f in netisr_dispatch_src (proto=proto@entry=5,
>> source=source@entry=0, m=m@entry=0xfffff8029868ca00)
>> at /usr/devel/git/trant/sys/net/netisr.c:1143
>> #14 0xffffffff8094cb0e in netisr_dispatch (proto=<unavailable>,
>> proto@entry=5, m=<unavailable>, m@entry=0xfffff8029868ca00)
>> at /usr/devel/git/trant/sys/net/netisr.c:1234
>> #15 0xffffffff8094383d in ether_input (ifp=0xfffff80008c75000,
>> ifp@entry=<error reading variable: value is not available>,
>> m=0xfffff8029868ca00,
>> m@entry=<error reading variable: value is not available>)
>> at /usr/devel/git/trant/sys/net/if_ethersubr.c:830
>> #16 0xffffffff8066da13 in re_rxeof (sc=sc@entry=0xfffffe00391a5000,
>> rx_npktsp=0x0) at /usr/devel/git/trant/sys/dev/re/if_re.c:2388
>> #17 0xffffffff8066b3ab in re_intr_msi (xsc=0xfffffe00391a5000)
>> at /usr/devel/git/trant/sys/dev/re/if_re.c:2684
>> #18 0xffffffff80801bcf in intr_event_execute_handlers (
>> p=p@entry=0xfffff80006a94a50, ie=ie@entry=0xfffff80008c57800)
>> at /usr/devel/git/trant/sys/kern/kern_intr.c:1168
>> #19 0xffffffff80801942 in ithread_execute_handlers (
>> p=p@entry=0xfffff80006a94a50, ie=ie@entry=0xfffff80008c57800)
>> at /usr/devel/git/trant/sys/kern/kern_intr.c:1181
>> #20 0xffffffff80801758 in ithread_loop (arg=arg@entry=0xfffff80008c20c40)
>> at /usr/devel/git/trant/sys/kern/kern_intr.c:1269
>> #21 0xffffffff807fe0a9 in fork_exit (
>> callout=0xffffffff808016c0 <ithread_loop>, arg=0xfffff80008c20c40,
>> frame=0xfffffe0120b9ed40)
>> at /usr/devel/git/trant/sys/kern/kern_fork.c:1069
>>
>>
>> (kgdb) fr 4
>> #4 0xffffffff8098a82c in tcp_sack_doack (tp=<optimized out>,
>> tp@entry=0xfffff807548187f0, to=<optimized out>,
>> to@entry=0xfffffe0120b9e780,
>> th_ack=<optimized out>) at /usr/devel/git/trant/sys/netinet/tcp_sack.c:691
>> 691 KASSERT(tp->sackhint.sack_bytes_rexmit >= 0,
>> (kgdb) i loc
>> sack_blocks = {{start = 3846350860, end = 3846396940}, {start =
>> 3846398380, end
>> = 3846415660}, {start = 0, end = 0}, {start = 1417775088, end =
>> 4294965255},
>> {start = 549054304, end = 4294966785}}
>> left_edge_delta = <optimized out>
>> delivered_data = 0
>> sack_changed = <optimized out>
>> num_sack_blks = <optimized out>
>> i = <optimized out>
>> j = <optimized out>
>> sack = {start = <optimized out>, end = <optimized out>}
>> sblkp = 0xfffffe0120b9e700
>> temp = <optimized out>
>> cur = 0xfffff8013da5a320
>> (kgdb) p *cur
>> $1 = {start = 3846347980, end = 3846352300, rxmit = 3846352300, scblink =
>> {tqe_next = 0xfffff8013da5a220, tqe_prev = 0xfffff80754818930}}
>> (kgdb) p 3846352300 - 3846347980
>> $2 = 4320
>> (kgdb) p tp->sackhint.sack_bytes_rexmit
>> value has been optimized out
>> (kgdb) p tp@entry->sackhint.sack_bytes_rexmit
>> <mailto:tp@entry-%3esackhint.sack_bytes_rexmit>
>> $3 = -1440
>> (kgdb) p 4320 - 1440
>> $4 = 2880
>> (kgdb) p *sblkp
>> $5 = {start = 3846350860, end = 3846396940}
>>
>> (kgdb) p *tp@entry
>> $7 = {t_inpcb = 0xfffff80640ca65b8, t_fb = 0xffffffff80ef4700
>> <tcp_def_funcblk>,
>> t_fb_ptr = 0x0, t_maxseg = 1440, t_logstate = 0, t_port = 0, t_state = 4,
>> t_idle_reduce = 0, t_delayed_ack = 0, t_fin_is_rst = 0,
>> t_log_state_set = 0, bits_spare = 0, t_flags = 1613759072, snd_una =
>> 3846347980, snd_max = 3846417100, snd_nxt = 3846417100, snd_up =
>> 3846347980,
>> snd_wnd = 237568, snd_cwnd = 4320, t_peakrate_thr = 0, ts_offset =
>> 71449215,
>> rfbuf_ts = 162235772, rcv_numsacks = 0, t_tsomax = 0, t_tsomaxsegcount =
>> 0,
>> t_tsomaxsegsize = 0, rcv_nxt = 2281639092, rcv_adv = 2281705332, rcv_wnd =
>> 66240, t_flags2 = 1030, t_srtt = 876, t_rttvar = 33, ts_recent = 0,
>> snd_scale = 8 '\b', rcv_scale = 6 '\006', snd_limited = 2 '\002',
>> request_r_scale = 6 '\006', last_ack_sent = 2281639092, t_rcvtime =
>> 2309118641,
>> rcv_up = 2281639092, t_segqlen = 0, t_segqmbuflen = 0, t_segq = {
>> tqh_first = 0x0, tqh_last = 0xfffff80754818880}, t_in_pkt = 0x0,
>> t_tail_pkt
>> = 0x0, t_timers = 0xfffff80754818a78, t_vnet = 0x0, snd_ssthresh = 31680,
>> snd_wl1 = 2281639092, snd_wl2 = 3846347980, irs = 2281631223,
>> iss = 3840447913, t_acktime = 0, t_sndtime = 2309118613, ts_recent_age =
>> 0,
>> snd_recover = 3846415660, cl4_spare = 0, t_oobflags = 0 '\000', t_iobc = 0
>> '\000', t_rxtcur = 270, t_rxtshift = 1, t_rtttime = 2309118613,
>> t_rtseq = 3846415660, t_starttime = 2309086941, t_fbyte_in = 2309087188,
>> t_fbyte_out = 2309087159, t_pmtud_saved_maxseg = 0, t_blackhole_enter = 0,
>> t_blackhole_exit = 0, t_rttmin = 30, t_rttbest = 845, t_softerror = 0,
>> max_sndwnd = 237568, snd_cwnd_prev = 64800, snd_ssthresh_prev = 8640,
>> snd_recover_prev = 3846347980, t_sndzerowin = 0, t_rttupdated = 368,
>> snd_numholes = 2, t_badrxtwin = 0, snd_holes = {tqh_first =
>> 0xfffff8013da5a320,
>> tqh_last = 0xfffff8013da5a230}, snd_fack = 3846415660, sackblks =
>> {{start =
>> 2281632180, end = 2281632690}, {start = 0, end = 0}, {start = 0, end = 0},
>> {start = 0, end = 0}, {start = 0, end = 0}, {start = 0, end = 0}},
>> sackhint = {nexthole = 0xfffff8013da5a220, sack_bytes_rexmit = -1440,
>> last_sack_ack = 3846415660, delivered_data = 1440, sacked_bytes = 61920,
>> recover_fs = 67680, prr_delivered = 1440, _pad = {0}}, t_rttlow = 25,
>> rfbuf_cnt = 0, tod = 0x0, t_sndrexmitpack = 520, t_rcvoopack = 0, t_toe
>> = 0x0,
>> cc_algo = 0xffffffff80ef2530 <newreno_cc_algo>, ccv = 0xfffff80754818bc0,
>> osd =
>> 0x0, t_bytes_acked = 11520, t_maxunacktime = 0, t_keepinit = 0,
>> t_keepidle = 0, t_keepintvl = 0, t_keepcnt = 0, t_dupacks = 4, t_lognum
>> = 0,
>> t_loglimit = 0, t_pacing_rate = -1, t_logs = {stqh_first = 0x0, stqh_last
>> =
>> 0x0}, t_lin = 0x0, t_lib = 0x0, t_output_caller = 0x0, t_stats = 0x0,
>> t_logsn = 0, gput_ts = 0, gput_seq = 0, gput_ack = 0, t_stats_gput_prev
>> = 0,
>> t_tfo_client_cookie_len = 0 '\000', t_end_info_status = 0, t_tfo_pending
>> = 0x0,
>> t_tfo_cookie = {client = '\000' <repeats 15 times>, server = 0}, {
>> t_end_info_bytes = "\000\000\000\000\000\000\000", t_end_info = 0}}
>>
>> (kgdb) p *tp@entry->sackhint.nexthole
>> <mailto:*tp@entry-%3esackhint.nexthole>
>> $8 = {start = 3846396940, end = 3846398380, rxmit = 3846398380, scblink =
>> {tqe_next = 0x0, tqe_prev = 0xfffff8013da5a330}}
>>
>> --
>> Andriy Gapon
>> _______________________________________________
>> freebsd-curr...@freebsd.org <mailto:freebsd-curr...@freebsd.org> mailing
>> list
>> https://lists.freebsd.org/mailman/listinfo/freebsd-current
>> <https://lists.freebsd.org/mailman/listinfo/freebsd-current>
>> To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org
>> <mailto:freebsd-current-unsubscr...@freebsd.org>"
>>
>>
>>
>
>
> --
> Andriy Gapon
_______________________________________________
freebsd-net@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-net
To unsubscribe, send any mail to "freebsd-net-unsubscr...@freebsd.org"
