10 webnet线程发送应答数据，过了至少2秒后才到达eth_tx线程处理，导致网页打开很慢

发布于 2024-03-06 18:53:55 浏览：713 订阅该版

[tocm]

webnet线程处理一个请求在14310毫秒处结束，中间多次通过webnet_session_write和webnet_session_printf函数调用send发送了数据。在2490毫秒之后(即16800毫秒处)，线程eth_tx_thread_entry才收邮箱，调用enetif->eth_tx()发数据。

rt-thread版本：V5.0.0
LwIP版本：V2.1.2
WebNet版本：V2.0.3
编译器：gcc version 11.4.0

## 抓包
![webnet_ws1.jpg](https://oss-club.rt-thread.org/uploads/20240307/b226457f8729317b32a5ccde1e5599a3.jpg.webp)

## 线程信息
![webnet_threads.jpg](https://oss-club.rt-thread.org/uploads/20240307/baade794958f275f0655ec0a8ea7d29f.jpg)

## 日志
```
[17650 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 6970
[17660 ethernetif_linkoutput] thread "tcpip" send msg interval 9380
[17660 eth_tx_thread_entry] thread "etx" recv msg
[17670 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 0
[17670 ethernetif_linkoutput] thread "tcpip" send msg interval 10
[17680 eth_tx_thread_entry] thread "etx" recv msg
[17690 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 0
[17740 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 50
[17750 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 0
[17760 ethernetif_linkoutput] thread "tcpip" send msg interval 80
[17770 eth_tx_thread_entry] thread "etx" recv msg
[17770 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 0
[17780 webnet_session_read] read_cout 574

[D/wn.log]   new client: 192.168.5.19:55289
[D/wn.log]       method: GET
[D/wn.log]      request: /net_setting.shtml
[17800 webnet_module_handle_uri] 
[D/wn.log] physical url: /webnet/net_setting.shtml
[D/wn.log]    mime type: text/html
[17810 webnet_module_log] 
[17820 ethernetif_linkoutput] thread "webnet" send msg interval 50
[17820 eth_tx_thread_entry] thread "etx" recv msg
[17830 webnet_session_write] size 85
[17830 ethernetif_linkoutput] thread "webnet" send msg interval 10
[17840 eth_tx_thread_entry] thread "etx" recv msg
[17850 webnet_session_write] size 2514
[17850 webnet_session_printf] size 1
[17850 webnet_session_write] size 174
[17860 webnet_session_printf] size 12
[17860 webnet_session_write] size 190
[17870 webnet_session_printf] size 13
[17870 ethernetif_linkoutput] thread "webnet" send msg interval 30
[17880 eth_tx_thread_entry] thread "etx" recv msg
[17[17880 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 100
880 tcpip_thread] thread "tcpip" TC[17890 webnet_session_printf] size 11
[17900 webnet_session_write] size 340
[17900 webnet_session_printf] size 7
[17900 webnet_session_write] size 65
[17910 webnet_session_printf] size 7
[17910 webnet_session_write] size 2595
[17920 webnet_sessions_handle_fds] closed
[20410 ethernetif_linkoutput] thread "tcpip" send msg interval 2530
[20410 eth_tx_thread_entry] thread "etx" recv msg
[20420 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 2530
[20420 ethernetif_linkoutput] thread "tcpip" send msg interval 10
[20430 eth_tx_thread_entry] thread "etx" recv msg
[20440 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 0
[20440 ethernetif_linkoutput] thread "tcpip" send msg interval 10
[20450 eth_tx_thread_entry] thread "etx" recv msg
[20460 ethernetif_linkoutput] thread "tcpip" send msg interval 10
[20460 eth_tx_thread_entry] thread "etx" recv msg
[20470 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 0
[20470 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 0
[20480 ethernetif_linkoutput] thread "tcpip" send msg interval 20
[20490 eth_tx_thread_entry] thread "etx" recv msg
[20490 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 0
[20500 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 0
[20510 ethernetif_linkoutput] thread "tcpip" send msg interval 20
[20510 eth_tx_thread_entry] thread "etx" recv msg
[20510 eth_tx_threaon_read] read_cout 423

[D/wn.log]   new client: 192.168.5.19:55290
[D/wn.log]       method: GET
[D/wn.log]      request: /css/style.css
[20540 webnet_module_handle_uri] 
[D/wn.log] physical url: /webnet/css/style.css
[D/wn.log]    mime type: text/css
[20550 webnet_module_log] 
[20570 ethernetif_linkoutput] thread "webnet" send msg interval 60
[20570 eth_tx_thread_entry] thread "etx" recv msg
[20580 webnet_session_printf] size 13
[20580 webnet_session_printf] size 2
[20590 webnet_session_printf] size 2
[20590 webnet_session_printf] size 22
[20590 webnet_session_printf] size 24
[20600 webnet_session_printf] size 22
[20600 webnet_session_printf] size 24
[20600 webnet_session_printf] size 31
[20610 webnet_session_printf] size 2
[20610 webnet_session_write] size 1194
[20620 ethernetif_linkoutput] thread "webnet" send msg interval 50
[20620 eth_tx_thread_entry] thread "etx" recv msg
[20630 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 110
[22920 ethernetif_linkoutput] thread "tcpip" send msg interval 2300
[22920 eth_tx_thread_entry] thread "etx" recv msg
[22930 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 2290
[22940 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 10
[22950 ethernetif_linkoutput] thread "tcpip" send msg interval 30
[22950 eth_tx_thread_entry] thread "etx" recv msg

```

1 个回答

出出啊 2024-03-07

恃人不如自恃，人之为己者不如己之自为也

lx1024 2024-03-07

这家伙很懒，什么也没写！

出出啊 2024-03-08

恃人不如自恃，人之为己者不如己之自为也

lx1024 2024-03-08

这家伙很懒，什么也没写！

[@出出啊](https://club.rt-thread.org/u/db779ee1aa856f55)
你好，感谢回复。

打印的tick值是乘以10的.

上传新的日志。发现消耗时间最长之处如下：
1. webnet线程发送应答，关闭会话后，`[17920 webnet_sessions_handle_fds] closed`；
2. tcpip线程执行ethernetif_linkoutput函数发送邮箱消息eth_tx_msg，但与上次执行间隔了2530毫秒，`[20410 ethernetif_linkoutput] thread "tcpip" send msg interval 2530`；
3. etx线程立即收到邮箱消息eth_tx_msg，并调用`enetif->eth_tx()`，`[20410 eth_tx_thread_entry] thread "etx" recv msg`；
4. tcpip线程获取邮箱消息tcpip_msg，消耗了2530毫秒，是在此函数：tcpip_timeouts_mbox_fetch消耗的，`[20420 tcpip_thread] thread "tcpip" TCPIP_MBOX_FETCH msg 2000407c ealp 2530`；

在抓包报文中看到了异常报文，在Lwip发出第57帧`[TCP Previous segment not captured]`和电脑发第58帧`[TCP Dup ACK 45#1]`之后，过后约2.6秒之后Lwip才发第59帧`[TCP Retransmission]`。

```c
static void tcpip_timeouts_mbox_fetch(sys_mbox_t *mbox, void **msg)
{
  u32_t sleeptime, res;

again:
  LWIP_ASSERT_CORE_LOCKED();

sleeptime = sys_timeouts_sleeptime();
  if (sleeptime == SYS_TIMEOUTS_SLEEPTIME_INFINITE) {
    UNLOCK_TCPIP_CORE();
    sys_arch_mbox_fetch(mbox, msg, 0);
    LOCK_TCPIP_CORE();
    return;
  } else if (sleeptime == 0) {
    sys_check_timeouts();
    /* We try again to fetch a message from the mbox. */
    goto again;
  }

UNLOCK_TCPIP_CORE();
  res = sys_arch_mbox_fetch(mbox, msg, sleeptime);
  LOCK_TCPIP_CORE();
  if (res == SYS_ARCH_TIMEOUT) {
    /* If a SYS_ARCH_TIMEOUT value is returned, a timeout occurred
       before a message could be fetched. */
    sys_check_timeouts();
    /* We try again to fetch a message from the mbox. */
    goto again;
  }
}
#endif /* !LWIP_TIMERS */
```

出出啊 2024-03-08

恃人不如自恃，人之为己者不如己之自为也

lx1024 2024-03-08

这家伙很懒，什么也没写！

[@出出啊](https://club.rt-thread.org/u/db779ee1aa856f55)

```
[D/wn.log]   new client: 192.168.5.19:56971
[D/wn.log]       method: GET
[D/wn.log]      request: /net_setting.shtml
[24380 webnet_module_handle_uri] 
[D/wn.log] physical url: /webnet/net_setting.shtml
[D/wn.log]    mime type: text/html
[24400 webnet_module_log] 
[24400 tcp_output] seqno 6511 lastack 6511 len 85 (85 4380)
[24410 ethernetif_linkoutput] thread "webnet" send msg interval 60
[24410 eth_tx_thread_entry] thread "etx" recv msg
[24420 webnet_session_write] size 85
[24420 tcp_output] seqno 6596 lastack 6511 len 1460 (1545 4380)
[24430 ethernetif_linkoutput] thread "webnet" send msg interval 20
[24440 eth_tx_thread_entry] thread "etx" recv msg
[24440 webnet_session_write] size 2514
[24450 tcp_output] seqno 8056 lastack 6511 len 1055 (2600 4380)
[24450 webnet_session_printf] size 1
[24460 tcp_output] seqno 8056 lastack 6511 len 1229 (2774 4380)
[24460 webnet_session_write] size 174
[24470 tcp_output] seqno 8056 lastack 6511 len 1241 (2786 4380)
[24470 webnet_session_printf] size 12
[24480 tcp_output] seqno 8056 lastack 6511 len 1431 (2976 4380)
[24480 webnet_session_write] size 190
[24490 tcp_output] seqno 8056 lastack 6511 len 1444 (2989 4380)
[24490 webnet_session_printf] size 13
[24500 tcp_output] seqno 8056 lastack 6511 len 1460 (3005 4380)
[24500 ethernetif_linkoutput] thread "webnet" send msg interval 60
[24510 eth_tx_thread_entry] thread "etx" recv msg
[24[24520 tcpip_inpkt] thread "erx" trypost tcpip_msg
[24520 tcpip_thread] thread "tcpip" FETCH msg 20004040 ealp 160
[24530 tcp_output] seqno 9516 lastack 6511 len 177 (3182 4380)
530 tcp_output] seqno 9516 lastack [24540 tcp_output] seqno 9516 lastack 6511 len 188 (3193 4380)
[24540 webnet_session_printf] size 11
[24550 tcp_output] seqno 9516 lastack 6511 len 528 (3533 4380)
[24550 webnet_session_write] size 340
[24560 tcp_output] seqno 9516 lastack 6511 len 535 (3540 4380)
[24560 webnet_session_printf] size 7
[24570 tcp_output] seqno 9516 lastack 6511 len 600 (3605 4380)
[24570 webnet_session_write] size 65
[24580 tcp_output] seqno 9516 lastack 6511 len 607 (3612 4380)
[24580 webnet_session_printf] size 7
[24590 tcp_output] seqno 9516 lastack 6511 len 1460 (4465 4380)
[24590 tcp_output] output_done
[24600 webnet_session_write] size 2595
[24600 tcp_output] seqno 9516 lastack 6511 len 1460 (4465 4380)
[24610 tcp_output] output_done
[24610 webnet_sessions_handle_fds] closed
[24980 tcp_slowtmr] thread "tcpip"
[24980 tcp_output] seqno 9516 lastack 6511 len 1460 (4465 4380)
[24980 tcp_output] output_done
[24990 tcp_slowtmr] thread "tcpip"
[25490 tcp_slowtmr] thread "tcpip"
[25490 tcp_output] seqno 9516 lastack 6511 len 1460 (4465 4380)
[25490 tcp_output] output_done
[26000 tcp_slowtmr] thread "tcpip"
[26000 tcp_output] seqno 9516 lastack 6511 len 1460 (4465 4380)
[26000 tcp_output] output_done
[26010 tcp_slowtmr] thread "tcpip"
[26510 tcp_slowtmr] thread "tcpip"
[26510 tcp_output] seqno 9516 lastack 6511 len 1460 (4465 4380)
[26510 tcp_output] output_done
[27020 tcp_output] seqno 6511 lastack 6511 len 85 (85 1460)
[27020 ethernetif_linkoutput] thread "tcpip" send msg interval 2510
[27030 eth_tx_thread_entry] thread "etx" recv msg
[2[27030 tcpip_inpkt] thread "erx" trypost tcpip_msg
7030 tcpip_inpkt] thread "erx" tr[27040 tcp_output] seqno 6596 lastack 6511 len 1460 (1545 1460)
[27050 tcp_output] output_done
[27050 tcp_slowtmr] thread "tcpip"
[27050 tcpip_thread] thread "tcpip" FETCH msg 20004040 ealp 2520
[27060 tcp_output] seqno 6596 lastack 6596 len 1460 (1460 1545)
[27070 ethernetif_linkoutput] thread "tcpip" send msg interval 40
[27070 eth_tx_thread_entry] thread "etx" recv msg
[27080 tcpip_inpkt] thread "erx" trypost tcpip_msg
[27080 tcpip_inpkt] thread "erx" trypost tcpip_msg
[27090 tcpip_thread] thread "tcpip" FETCH msg 20004040 ealp 10
[27090 tcp_output] seqno 9516 lastack 9516 len 1460 (1460 3005)
[27100 ethernetif_linkoutput] thread "tcpip" send msg interval 30
[27110 eth_tx_thread_entry] thread "etx" recv msg
[27110 ethernetif_linkoutput] thread "tcpip" send msg interval 0
[27120 eth_tx_thread_entry] thread "etx" recv msg
[2[27120 tcpip_inpkt] thread "erx" trypost tcpip_msg
7120 tcpip_inpkt] thread "erx" trypost tcpip_msg
7c ealp 0
[27140 tcpip_thread] thread "tcpip" FETCH msg 20004040 ealp 0
[27140 tcp_output] seqno 12436 lastack 12436 len 282 (282 3005)
[27150 ethernetif_linkoutput] thread "tcpip" send msg interval 30
[27150 eth_tx_thread_entry] thread "etx" recv msg
[[27160 tcpip_inpkt] thread "erx" trypost tcpip_msg
[27160 tcpip_inpkt] thread "erx" trypost tcpip_msg
[27170 tcpip_thread] thread "tcpip" FETCH msg 20004040 ealp 10
[27180 tcpip_thread] thread "tcpip" FETCH msg 2000407c ealp 0
[27180 ethernetif_linkoutput] thread "tcpip" send msg interval 30
[27190 eth_tx_thread_entry] thread "etx" recv msg
27190 eth_tx_thread_entry] thread "etx" r
[D/wn.log]   new client: 192.168.5.19:56972
[D/wn.log]       method: GET
[D/wn.log]      request: /css/style.css
[27210 webnet_module_handle_uri] 
[D/wn.log] physical url: /webnet/css/style.css
[D/wn.log]    mime type: text/css
[27230 webnet_module_log] 
[27240 tcp_output] seqno 6511 lastack 6511 len 13 (13 4380)
[27250 ethernetif_linkoutput] thread "webnet" send msg interval 60
[27250 eth_tx_thread_entry] thread "etx" recv msg
[27260 webnet_session_printf] size 13
[27260 tcp_output] seqno 6524 lastack 6511 len 2 (15 4380)
[27270 webnet_session_printf] size 2
[27270 tcp_output] seqno 6524 lastack 6511 len 4 (17 4380)
[27280 webnet_session_printf] size 2
[27280 tcp_output] seqno 6524 lastack 6511 len 26 (39 4380)
[27290 webnet_session_printf] size 22
[27290 tcp_output] seqno 6524 lastack 6511 len 50 (63 4380)
[27300 webnet_session_printf] size 24
[27300 tcp_output] seqno 6524 lastack 6511 len 72 (85 4380)
[27310 webnet_session_pri[27310 tcpip_inpkt] thread "erx" trypost tcpip_msg
[27310 tcpip_thread] thread "tcpip" FETCH msg 2000407c ealp 120
[27320 tcp_output] seqno 6524 lastack 6524 len 72 (72 4393)
[27330 ethernetif_linkoutput] thread "tcpip" send msg interval 80
[27330 eth_tx_thread_entry] thread "etx" recv msg
y] thread "et[27340 tcp_output] seqno 6596 lastack 6524 len 24 (96 4393)
[27350 webnet_session_printf] size 24
[27350 tcp_output] seqno 6596 lastack 6524 len 55 (127 4393)
[27350 webnet_session_printf] size 31
[27360 tcp_output] seqno 6596 lastack 6524 len 57 (129 4393)
[27360 webnet_session_printf] size 2
[27370 tcp_output] seqno 6596 lastack 6524 len 1251 (1323 4393)
[27370 webnet_session_write] size 1194
[27380 tcp_output] seqno 6596 lastack 6524 len 1251 (1323 4393)
[27390 ethernetif_linkoutput] thread "webn[27390 tcpip_inpkt] thread "erx" trypost tcpip_msg
cpip_msg
sg interval 60
[27400 eth_tx_thread_entry] thread "etx" recv msg
[27[27400 tcpip_inpkt] thread "erx" trypost tcpip_msg
[27410 tcpip_inpkt] thread "erx" trypost tcpip_msg
410 tcpip_inpkt] thread "erx" trypost tcpip_msg
7c ealp 60
[27420 tcpip_thread] thread "tcpip" FETCH msg 20004040 ealp 0
[27420 tcpip_thread] thread "tcpip" FETCH msg 20004004 ealp 0
[27430 ethernetif_linkoutput] thread "tcpip" send msg interval 30
[27440 eth_tx_thread_entry] thread "etx" recv msg
```

邮箱消息tcpip_msg是在webnet关闭会话后立即由erx线程发出的，tcpip线程会立即收到了消息进行处理。

在发送eth_tx_msg的`ethernetif_linkoutput`函数与上次间隔约2.5秒时，重复调用`tcp_tmr()->tcp_slowtmr()->tcp_output()`，消耗了2秒，
都会进去：`if (lwip_ntohl(seg->tcphdr->seqno) - pcb->lastack + seg->len > wnd)`，然后就跳转到output_done退出了。

```c
  /* Handle the current segment not fitting within the window */
  if (lwip_ntohl(seg->tcphdr->seqno) - pcb->lastack + seg->len > wnd) {
    /* We need to start the persistent timer when the next unsent segment does not fit
     * within the remaining (could be 0) send window and RTO timer is not running (we
     * have no in-flight data). If window is still too small after persist timer fires,
     * then we split the segment. We don't consider the congestion window since a cwnd
     * smaller than 1 SMSS implies in-flight data
     */
    if (wnd == pcb->snd_wnd && pcb->unacked == NULL && pcb->persist_backoff == 0) {
      pcb->persist_cnt = 0;
      pcb->persist_backoff = 1;
      pcb->persist_probe = 0;
    }
    /* We need an ACK, but can't send data now, so send an empty ACK */
    if (pcb->flags & TF_ACK_NOW) {
      return tcp_send_empty_ack(pcb);
    }
    goto output_done;
  }
  /* Stop persist timer, above conditions are not active */
  pcb->persist_backoff = 0;

/* useg should point to last segment on unacked queue */
  useg = pcb->unacked;
  if (useg != NULL) {
    for (; useg->next != NULL; useg = useg->next);
  }
  /* data available and window allows it to be sent? */
  while (seg != NULL &&
         lwip_ntohl(seg->tcphdr->seqno) - pcb->lastack + seg->len <= wnd) {
    LWIP_ASSERT("RST not expected here!",
                (TCPH_FLAGS(seg->tcphdr) & TCP_RST) == 0);
    /* Stop sending if the nagle algorithm would prevent it
     * Don't stop:
     * - if tcp_write had a memory error before (prevent delayed ACK timeout) or
     * - if FIN was already enqueued for this PCB (SYN is always alone in a segment -
     *   either seg->next != NULL or pcb->unacked == NULL;
     *   RST is no sent using tcp_write/tcp_output.
     */
    if ((tcp_do_output_nagle(pcb) == 0) &&
        ((pcb->flags & (TF_NAGLEMEMERR | TF_FIN)) == 0)) {
      break;
    }
#if TCP_CWND_DEBUG
    LWIP_DEBUGF(TCP_CWND_DEBUG, ("tcp_output: snd_wnd %"TCPWNDSIZE_F", cwnd %"TCPWNDSIZE_F", wnd %"U32_F", effwnd %"U32_F", seq %"U32_F", ack %"U32_F", i %"S16_F"\n",
                                 pcb->snd_wnd, pcb->cwnd, wnd,
                                 lwip_ntohl(seg->tcphdr->seqno) + seg->len -
                                 pcb->lastack,
                                 lwip_ntohl(seg->tcphdr->seqno), pcb->lastack, i));
    ++i;
#endif /* TCP_CWND_DEBUG */

if (pcb->state != SYN_SENT) {
      TCPH_SET_FLAG(seg->tcphdr, TCP_ACK);
    }

err = tcp_output_segment(seg, pcb, netif);
    if (err != ERR_OK) {
      /* segment could not be sent, for whatever reason */
      tcp_set_flags(pcb, TF_NAGLEMEMERR);
      return err;
    }
#if TCP_OVERSIZE_DBGCHECK
    seg->oversize_left = 0;
#endif /* TCP_OVERSIZE_DBGCHECK */
    pcb->unsent = seg->next;
    if (pcb->state != SYN_SENT) {
      tcp_clear_flags(pcb, TF_ACK_DELAY | TF_ACK_NOW);
    }
    snd_nxt = lwip_ntohl(seg->tcphdr->seqno) + TCP_TCPLEN(seg);
    if (TCP_SEQ_LT(pcb->snd_nxt, snd_nxt)) {
      pcb->snd_nxt = snd_nxt;
    }
    /* put segment on unacknowledged list if length > 0 */
    if (TCP_TCPLEN(seg) > 0) {
      seg->next = NULL;
      /* unacked list is empty? */
      if (pcb->unacked == NULL) {
        pcb->unacked = seg;
        useg = seg;
        /* unacked list is not empty? */
      } else {
        /* In the case of fast retransmit, the packet should not go to the tail
         * of the unacked queue, but rather somewhere before it. We need to check for
         * this case. -STJ Jul 27, 2004 */
        if (TCP_SEQ_LT(lwip_ntohl(seg->tcphdr->seqno), lwip_ntohl(useg->tcphdr->seqno))) {
          /* add segment to before tail of unacked list, keeping the list sorted */
          struct tcp_seg **cur_seg = &(pcb->unacked);
          while (*cur_seg &&
                 TCP_SEQ_LT(lwip_ntohl((*cur_seg)->tcphdr->seqno), lwip_ntohl(seg->tcphdr->seqno))) {
            cur_seg = &((*cur_seg)->next );
          }
          seg->next = (*cur_seg);
          (*cur_seg) = seg;
        } else {
          /* add segment to tail of unacked list */
          useg->next = seg;
          useg = useg->next;
        }
      }
      /* do not queue empty segments on the unacked list */
    } else {
      tcp_seg_free(seg);
    }
    seg = pcb->unsent;
  }
#if TCP_OVERSIZE
  if (pcb->unsent == NULL) {
    /* last unsent has been removed, reset unsent_oversize */
    pcb->unsent_oversize = 0;
  }
#endif /* TCP_OVERSIZE */

output_done:
  tcp_clear_flags(pcb, TF_NAGLEMEMERR);
  return ERR_OK;
```

出出啊 2024-03-11

恃人不如自恃，人之为己者不如己之自为也

lx1024 2024-03-11

这家伙很懒，什么也没写！

出出啊 2024-03-11

恃人不如自恃，人之为己者不如己之自为也

lx1024 2024-03-14

这家伙很懒，什么也没写！

[@出出啊](https://club.rt-thread.org/u/db779ee1aa856f55)
把RT_TICK_PER_SECOND设为1000，TCP_TMR_INTERVAL设为1，效果还是一样要等2秒左右。

sys_arch.c文件里时间相关代码处如下，没有看出计算错的。

```c
/*
 * Block the thread while waiting for the semaphore to be signaled
 *
 * @return If the timeout argument is non-zero, it will return the number of milliseconds
 *         spent waiting for the semaphore to be signaled; If the semaphore isn't signaled
 *         within the specified time, it will return SYS_ARCH_TIMEOUT; If the thread doesn't
 *         wait for the semaphore, it will return zero
 */
u32_t sys_arch_sem_wait(sys_sem_t *sem, u32_t timeout)
{
    rt_err_t ret;
    s32_t t;
    u32_t tick;

RT_DEBUG_NOT_IN_INTERRUPT;

/* get the begin tick */
    tick = rt_tick_get();
    if (timeout == 0)
    {
        t = RT_WAITING_FOREVER;
    }
    else
    {
        /* convert msecond to os tick */
        if (timeout < (1000 / RT_TICK_PER_SECOND))
            t = 1;
        else
            t = timeout / (1000 / RT_TICK_PER_SECOND);
    }

ret = rt_sem_take(*sem, t);

if (ret == -RT_ETIMEOUT)
    {
        return SYS_ARCH_TIMEOUT;
    }
    else
    {
        if (ret == RT_EOK)
            ret = 1;
    }

/* get elapse msecond */
    tick = rt_tick_get() - tick;

/* convert tick to msecond */
    tick = tick * (1000 / RT_TICK_PER_SECOND);
    if (tick == 0)
        tick = 1;

return tick;
}

/** Wait for a new message to arrive in the mbox
 * @param mbox mbox to get a message from
 * @param msg pointer where the message is stored
 * @param timeout maximum time (in milliseconds) to wait for a message
 * @return time (in milliseconds) waited for a message, may be 0 if not waited
           or SYS_ARCH_TIMEOUT on timeout
 *         The returned time has to be accurate to prevent timer jitter!
 */
u32_t sys_arch_mbox_fetch(sys_mbox_t *mbox, void **msg, u32_t timeout)
{
    rt_err_t ret;
    s32_t t;
    u32_t tick;

RT_DEBUG_NOT_IN_INTERRUPT;

/* get the begin tick */
    tick = rt_tick_get();

if(timeout == 0)
    {
        t = RT_WAITING_FOREVER;
    }
    else
    {
        /* convirt msecond to os tick */
        if (timeout < (1000 / RT_TICK_PER_SECOND))
            t = 1;
        else
            t = timeout / (1000 / RT_TICK_PER_SECOND);
    }

ret = rt_mb_recv(*mbox, (rt_ubase_t *)msg, t);
    if(ret != RT_EOK)
    {
        return SYS_ARCH_TIMEOUT;
    }

/* get elapse msecond */
    tick = rt_tick_get() - tick;

/* convert tick to msecond */
    tick = tick * (1000 / RT_TICK_PER_SECOND);
    if (tick == 0)
        tick = 1;

return tick;
}

u32_t sys_jiffies(void)
{
    return rt_tick_get();
}

u32_t sys_now(void)
{
    return rt_tick_get_millisecond();
}
```

出出啊 2024-03-15

恃人不如自恃，人之为己者不如己之自为也

lx1024 2024-03-15

这家伙很懒，什么也没写！

[@出出啊](https://club.rt-thread.org/u/db779ee1aa856f55)

把RT_TICK_PER_SECOND设为1000之后，打印间隔不是10ms。

关闭Nagle算法后，打开网页有的时候很快，有时候慢。

第一次请求tcp_setting.shtml页面，在7184955处延时了1733毫秒：

```
[7184955 ethernetif_linkoutput] thread "tcpip" send msg interval 1733
```

第二次请求net_setting.shtml页面，没有延时。

第三次请求mqtt_setting.shtml页面，在7193777处延时了894毫秒和7194160处376毫秒：

```
[7193777 ethernetif_linkoutput] thread "tcpip" send msg interval 894
[7193784 webnet_thread] 4 disable Nagle 0
[7194160 ethernetif_linkoutput] thread "tcpip" send msg interval 376
```

延时是在tcpip线程里，调用`tcp_tmr()->tcp_slowtmr()->tcp_output()`，
每都进去这里：`if (lwip_ntohl(seg->tcphdr->seqno) - pcb->lastack + seg->len > wnd)`，
然后就跳转到`output_done`退出了，消耗了2秒左右才会调用`err = tcp_output_segment(seg, pcb, netif)`发送数据。

```
[7183016 ethernetif_linkoutput] thread "tcpip" send msg interval 53605
[7183023 webnet_thread] 4 disable Nagle 0

[7183111 ethernetif_linkoutput] thread "tcpip" send msg interval 88
[7183117 ethernetif_linkoutput] thread "tcpip" send msg interval 0
[D/wn.log]   new client: 192.168.5.19:60981
[D/wn.log]       method: GET
[D/wn.log]      request: /tcp_setting.shtml
[D/wn.log] physical url: /webnet/tcp_setting.shtml
[D/wn.log]    mime type: text/html
[7183154 ethernetif_linkoutput] thread "webnet" send msg interval 30
[7183162 ethernetif_linkoutput] thread "webnet" send msg interval 1
[7183169 ethernetif_linkoutput] thread "webnet" send msg interval 0
[7183177 webnet_thread] 4 disable Nagle 0
[7183216 ethernetif_linkoutput] thread "tcpip" send msg interval 40
[7184955 ethernetif_linkoutput] thread "tcpip" send msg interval 1733
[7184962 ethernetif_linkoutput] thread "tcpip" send msg interval 1
[7184969 ethernetif_linkoutput] thread "tcpip" send msg interval 0
[7184976 ethernetif_linkoutput] thread "tcpip" send msg interval 1
[7184982 ethernetif_linkoutput] thread "tcpip" send msg interval 0
[7184990 ethernetif_linkoutput] thread "tcpip" send msg interval 1

7186432 ethernetif_linkoutput] thread "tcpip" send msg interval 1436
[7186438 ethernetif_linkoutput] thread "tcpip" send msg interval 0
186438 ethern  new client: 192.168.5.19:60982
[D/wn.log]       method: GET
[D/wn.log]      request: /net_setting.shtml
[D/wn.log] physical url: /webnet/net_setting.shtml
[D/wn.log]    mime type: text/html
[7186475 ethernetif_linkoutput] thread "webnet" send msg interval 30
[7186483 ethernetif_linkoutput] thread "webnet" send msg interval 1
[7186490 ethernetif_linkoutput] thread "webnet" send msg interval 0
[7186497 ethernetif_linkoutput] thread "webnet" send msg interval 0
[7186504 ethernetif_linkoutput] thread "tcpip" send msg interval 1
[7186511 ethernetif_linkoutput] thread "webnet" send msg interval 1
[7186517 ethernetif_linkoutput] thread "webnet" send msg interval 0
[7186524 ethernetif_linkoutput] thread "webnet" send msg interval 0
[7186531 ethernetif_linkoutput] thread "webnet" send msg interval 0
[7186538 ethernetif_linkoutput] thread "webnet" send msg interval 0
[7186545 ethernetif_linkoutput] thread "webnet" send msg interval 0
[7186552 ethernetif_linkoutput] thread "webnet" send msg interval 0
[7186559 ethernetif_linkoutput] thread "webnet" send msg interval 0
[7186566 ethernetif_linkoutput] thread "webnet" send msg interval 0
[7186573 ethernetif_linkoutput] thread "webnet" send msg interval 1
[7186580 ethernetif_linkoutput] thread "webnet" send msg interval 1
[7186587 ethernetif_linkoutput] thread "webnet" send msg interval 1
[7186594 ethernetif_linkoutput] thread "webnet" send msg interval 0
[7186601 ethernetif_linkoutput] thread "webnet" send msg interval 1
[7186608 ethernetif_linkoutput] thread "tcpip" send msg interval 1
[7186614 webnet_thread] 4 disable Nagle 0
[7192776 ethernetif_linkoutput] thread "tcpip" send msg interval 6162

[D/wn.log]   new client: 192.168.5.19:60983
[D/wn.log]       method: GET
[D/wn.log]      request: /mqtt_setting.shtml
[D/wn.log] physical url: /webnet/mqtt_setting.shtml
[D/wn.log]    mime type: text/html
[7192813 ethernetif_linkoutput] thread "webnet" send msg interval 31
[7192821 ethernetif_linkoutput] thread "webnet" send msg interval 2
[7192828 ethernetif_linkoutput] thread "webnet" send msg interval 0
[7192835 ethernetif_linkoutput] thread "webnet" send msg interval 0
[7192842 ethernetif_linkoutput] thread "webnet" send msg interval 1
[7192849 ethernetif_linkoutput] thread "webnet" send msg interval 1
[7192856 ethernetif_linkoutput] thread "webnet" send msg interval 1
[7192863 ethernetif_linkoutput] thread "webnet" send msg interval 1
[7192869 ethernetif_linkoutput] thread "tcpip" send msg interval 0
[7192876 ethernetif_linkoutput] thread "webnet" send msg interval 0
[7193777 ethernetif_linkoutput] thread "tcpip" send msg interval 894
[7193784 webnet_thread] 4 disable Nagle 0
[7194160 ethernetif_linkoutput] thread "tcpip" send msg interval 376
[7194167 ethernetif_linkoutput] thread "tcpip" send msg interval 1
[7194173 ethernetif_linkoutput] thread "tcpip" send msg interval 0
[7194180 ethernetif_linkoutput] thread "tcpip" send msg interval 0
[7194187 ethernetif_linkoutput] thread "tcpip" send msg interval 0
[7194193 ethernetif_linkoutput] thread "tcpip" send msg interval 0
[7194200 ethernetif_linkoutput] thread "tcpip" send msg interval 0
[7194207 ethernetif_linkoutput] thread "tcpip" send msg interval 0
[7194214 ethernetif_linkoutput] thread "tcpip" send msg interval 1
[7194220 ethernetif_linkoutput] thread "tcpip" send msg interval 0
[7194227 ethernetif_linkoutput] thread "tcpip" send msg interval 0
[7194234 ethernetif_linkoutput] thread "tcpip" send msg interval 0
```

出出啊 2024-03-18

恃人不如自恃，人之为己者不如己之自为也

lx1024 2024-03-18

这家伙很懒，什么也没写！

出出啊 2024-03-18

恃人不如自恃，人之为己者不如己之自为也

lx1024 2024-03-19

这家伙很懒，什么也没写！

[@出出啊](https://club.rt-thread.org/u/db779ee1aa856f55)
wnd 变量的值为右边圆括号的第二个数据：[24450 tcp_output] seqno 8056 lastack 6511 len 1055 (2600 4380)
```
[D/wn.log]   new client: 192.168.5.19:56971
[D/wn.log]       method: GET
[D/wn.log]      request: /net_setting.shtml
[24380 webnet_module_handle_uri] 
[D/wn.log] physical url: /webnet/net_setting.shtml
[D/wn.log]    mime type: text/html
[24400 webnet_module_log] 
[24400 tcp_output] seqno 6511 lastack 6511 len 85 (85 4380)
[24410 ethernetif_linkoutput] thread "webnet" send msg interval 60
[24410 eth_tx_thread_entry] thread "etx" recv msg
[24420 webnet_session_write] size 85
[24420 tcp_output] seqno 6596 lastack 6511 len 1460 (1545 4380)
[24430 ethernetif_linkoutput] thread "webnet" send msg interval 20
[24440 eth_tx_thread_entry] thread "etx" recv msg
[24440 webnet_session_write] size 2514
[24450 tcp_output] seqno 8056 lastack 6511 len 1055 (2600 4380)
[24450 webnet_session_printf] size 1
[24460 tcp_output] seqno 8056 lastack 6511 len 1229 (2774 4380)
[24460 webnet_session_write] size 174
[24470 tcp_output] seqno 8056 lastack 6511 len 1241 (2786 4380)
[24470 webnet_session_printf] size 12
[24480 tcp_output] seqno 8056 lastack 6511 len 1431 (2976 4380)
[24480 webnet_session_write] size 190
[24490 tcp_output] seqno 8056 lastack 6511 len 1444 (2989 4380)
[24490 webnet_session_printf] size 13
[24500 tcp_output] seqno 8056 lastack 6511 len 1460 (3005 4380)
[24500 ethernetif_linkoutput] thread "webnet" send msg interval 60
[24510 eth_tx_thread_entry] thread "etx" recv msg
[24[24520 tcpip_inpkt] thread "erx" trypost tcpip_msg
[24520 tcpip_thread] thread "tcpip" FETCH msg 20004040 ealp 160
[24530 tcp_output] seqno 9516 lastack 6511 len 177 (3182 4380)
530 tcp_output] seqno 9516 lastack [24540 tcp_output] seqno 9516 lastack 6511 len 188 (3193 4380)
[24540 webnet_session_printf] size 11
[24550 tcp_output] seqno 9516 lastack 6511 len 528 (3533 4380)
[24550 webnet_session_write] size 340
[24560 tcp_output] seqno 9516 lastack 6511 len 535 (3540 4380)
[24560 webnet_session_printf] size 7
[24570 tcp_output] seqno 9516 lastack 6511 len 600 (3605 4380)
[24570 webnet_session_write] size 65
[24580 tcp_output] seqno 9516 lastack 6511 len 607 (3612 4380)
[24580 webnet_session_printf] size 7
[24590 tcp_output] seqno 9516 lastack 6511 len 1460 (4465 4380)
[24590 tcp_output] output_done
[24600 webnet_session_write] size 2595
[24600 tcp_output] seqno 9516 lastack 6511 len 1460 (4465 4380)
[24610 tcp_output] output_done
[24610 webnet_sessions_handle_fds] closed
[24980 tcp_slowtmr] thread "tcpip"
[24980 tcp_output] seqno 9516 lastack 6511 len 1460 (4465 4380)
[24980 tcp_output] output_done
[24990 tcp_slowtmr] thread "tcpip"
[25490 tcp_slowtmr] thread "tcpip"
[25490 tcp_output] seqno 9516 lastack 6511 len 1460 (4465 4380)
[25490 tcp_output] output_done
[26000 tcp_slowtmr] thread "tcpip"
[26000 tcp_output] seqno 9516 lastack 6511 len 1460 (4465 4380)
[26000 tcp_output] output_done
[26010 tcp_slowtmr] thread "tcpip"
[26510 tcp_slowtmr] thread "tcpip"
[26510 tcp_output] seqno 9516 lastack 6511 len 1460 (4465 4380)
[26510 tcp_output] output_done
[27020 tcp_output] seqno 6511 lastack 6511 len 85 (85 1460)
[27020 ethernetif_linkoutput] thread "tcpip" send msg interval 2510
[27030 eth_tx_thread_entry] thread "etx" recv msg
[2[27030 tcpip_inpkt] thread "erx" trypost tcpip_msg
7030 tcpip_inpkt] thread "erx" tr[27040 tcp_output] seqno 6596 lastack 6511 len 1460 (1545 1460)
[27050 tcp_output] output_done
[27050 tcp_slowtmr] thread "tcpip"
[27050 tcpip_thread] thread "tcpip" FETCH msg 20004040 ealp 2520
[27060 tcp_output] seqno 6596 lastack 6596 len 1460 (1460 1545)
[27070 ethernetif_linkoutput] thread "tcpip" send msg interval 40
[27070 eth_tx_thread_entry] thread "etx" recv msg
[27080 tcpip_inpkt] thread "erx" trypost tcpip_msg
[27080 tcpip_inpkt] thread "erx" trypost tcpip_msg
[27090 tcpip_thread] thread "tcpip" FETCH msg 20004040 ealp 10
[27090 tcp_output] seqno 9516 lastack 9516 len 1460 (1460 3005)
[27100 ethernetif_linkoutput] thread "tcpip" send msg interval 30
[27110 eth_tx_thread_entry] thread "etx" recv msg
[27110 ethernetif_linkoutput] thread "tcpip" send msg interval 0
[27120 eth_tx_thread_entry] thread "etx" recv msg
[2[27120 tcpip_inpkt] thread "erx" trypost tcpip_msg
7120 tcpip_inpkt] thread "erx" trypost tcpip_msg
7c ealp 0
[27140 tcpip_thread] thread "tcpip" FETCH msg 20004040 ealp 0
[27140 tcp_output] seqno 12436 lastack 12436 len 282 (282 3005)
[27150 ethernetif_linkoutput] thread "tcpip" send msg interval 30
[27150 eth_tx_thread_entry] thread "etx" recv msg
[[27160 tcpip_inpkt] thread "erx" trypost tcpip_msg
[27160 tcpip_inpkt] thread "erx" trypost tcpip_msg
[27170 tcpip_thread] thread "tcpip" FETCH msg 20004040 ealp 10
[27180 tcpip_thread] thread "tcpip" FETCH msg 2000407c ealp 0
[27180 ethernetif_linkoutput] thread "tcpip" send msg interval 30
[27190 eth_tx_thread_entry] thread "etx" recv msg
27190 eth_tx_thread_entry] thread "etx" r
[D/wn.log]   new client: 192.168.5.19:56972
[D/wn.log]       method: GET
[D/wn.log]      request: /css/style.css
[27210 webnet_module_handle_uri] 
[D/wn.log] physical url: /webnet/css/style.css
[D/wn.log]    mime type: text/css
[27230 webnet_module_log] 
[27240 tcp_output] seqno 6511 lastack 6511 len 13 (13 4380)
[27250 ethernetif_linkoutput] thread "webnet" send msg interval 60
[27250 eth_tx_thread_entry] thread "etx" recv msg
[27260 webnet_session_printf] size 13
[27260 tcp_output] seqno 6524 lastack 6511 len 2 (15 4380)
[27270 webnet_session_printf] size 2
[27270 tcp_output] seqno 6524 lastack 6511 len 4 (17 4380)
[27280 webnet_session_printf] size 2
[27280 tcp_output] seqno 6524 lastack 6511 len 26 (39 4380)
[27290 webnet_session_printf] size 22
[27290 tcp_output] seqno 6524 lastack 6511 len 50 (63 4380)
[27300 webnet_session_printf] size 24
[27300 tcp_output] seqno 6524 lastack 6511 len 72 (85 4380)
[27310 webnet_session_pri[27310 tcpip_inpkt] thread "erx" trypost tcpip_msg
[27310 tcpip_thread] thread "tcpip" FETCH msg 2000407c ealp 120
[27320 tcp_output] seqno 6524 lastack 6524 len 72 (72 4393)
[27330 ethernetif_linkoutput] thread "tcpip" send msg interval 80
[27330 eth_tx_thread_entry] thread "etx" recv msg
y] thread "et[27340 tcp_output] seqno 6596 lastack 6524 len 24 (96 4393)
[27350 webnet_session_printf] size 24
[27350 tcp_output] seqno 6596 lastack 6524 len 55 (127 4393)
[27350 webnet_session_printf] size 31
[27360 tcp_output] seqno 6596 lastack 6524 len 57 (129 4393)
[27360 webnet_session_printf] size 2
[27370 tcp_output] seqno 6596 lastack 6524 len 1251 (1323 4393)
[27370 webnet_session_write] size 1194
[27380 tcp_output] seqno 6596 lastack 6524 len 1251 (1323 4393)
[27390 ethernetif_linkoutput] thread "webn[27390 tcpip_inpkt] thread "erx" trypost tcpip_msg
cpip_msg
sg interval 60
[27400 eth_tx_thread_entry] thread "etx" recv msg
[27[27400 tcpip_inpkt] thread "erx" trypost tcpip_msg
[27410 tcpip_inpkt] thread "erx" trypost tcpip_msg
410 tcpip_inpkt] thread "erx" trypost tcpip_msg
7c ealp 60
[27420 tcpip_thread] thread "tcpip" FETCH msg 20004040 ealp 0
[27420 tcpip_thread] thread "tcpip" FETCH msg 20004004 ealp 0
[27430 ethernetif_linkoutput] thread "tcpip" send msg interval 30
[27440 eth_tx_thread_entry] thread "etx" recv msg
```
下次调用 tcp_output 还是：tcp_tmr()->tcp_slowtmr()->tcp_output()